From ec8db2c04ba220bef8b5b43c7005c111368d844f Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 17:06:44 +0800 Subject: [PATCH 1/9] Add function _get_format_for_logger --- .../promptflow/_utils/logger_utils.py | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index 4c170ab2b96..143f80c16d5 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -437,3 +437,22 @@ def get_cli_sdk_logger(): # to avoid circular import error, use plain string here instead of importing from _constants # because this function is also called in _prepare_home_dir which is in _constants return LoggerFactory.get_logger("promptflow", verbosity=logging.WARNING) + + +def _get_format_for_logger(): + """ + Get the logging format and date format for logger. + + This function attempts to find the handler of the root logger with a configured formatter. + If such a handler is found, it returns the format and date format used by this handler. + This can be configured through logging.basicConfig. If no configured formatter is found, + it defaults to LOG_FORMAT and DATETIME_FORMAT. + """ + # Get the root logger + logger = logging.getLogger() + # Return the format and date format from the default handler + for handler in logger.handlers: + if handler.formatter: + return handler.formatter._fmt, handler.formatter.datefmt + # Return default format and date format if no formatter is found + return LOG_FORMAT, DATETIME_FORMAT From 8005d8142f39dbcff13d00443ee0624ada4fc327 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 17:22:19 +0800 Subject: [PATCH 2/9] Support custom format --- .../promptflow/_utils/logger_utils.py | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index 143f80c16d5..00df7e18a65 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -106,7 +106,8 @@ def __init__(self, file_path: str, formatter: Optional[logging.Formatter] = None self._stream_handler = self._get_stream_handler(file_path) if formatter is None: # Default formatter to scrub credentials in log message, exception and stack trace. - self._formatter = CredentialScrubberFormatter(fmt=LOG_FORMAT, datefmt=DATETIME_FORMAT) + fmt, datefmt = _get_format_for_logger() + self._formatter = CredentialScrubberFormatter(fmt=fmt, datefmt=datefmt) else: self._formatter = formatter self._stream_handler.setFormatter(self._formatter) @@ -186,7 +187,8 @@ def get_logger(name: str) -> logging.Logger: logger.setLevel(get_pf_logging_level()) logger.addHandler(FileHandlerConcurrentWrapper()) stdout_handler = logging.StreamHandler(sys.stdout) - stdout_handler.setFormatter(CredentialScrubberFormatter(fmt=LOG_FORMAT, datefmt=DATETIME_FORMAT)) + fmt, datefmt = _get_format_for_logger() + stdout_handler.setFormatter(CredentialScrubberFormatter(fmt=fmt, datefmt=datefmt)) logger.addHandler(stdout_handler) return logger @@ -406,7 +408,8 @@ def _add_handler(logger: logging.Logger, verbosity: int, target_stdout: bool = F # set target_stdout=True can log data into sys.stdout instead of default sys.stderr, in this way # logger info and python print result can be synchronized handler = logging.StreamHandler(stream=sys.stdout) if target_stdout else logging.StreamHandler() - formatter = logging.Formatter("[%(asctime)s][%(name)s][%(levelname)s] - %(message)s") + fmt, datefmt = _get_format_for_logger(default_log_format="[%(asctime)s][%(name)s][%(levelname)s] - %(message)s") + formatter = logging.Formatter(fmt=fmt, datefmt=datefmt) handler.setFormatter(formatter) handler.setLevel(verbosity) logger.addHandler(handler) @@ -439,7 +442,7 @@ def get_cli_sdk_logger(): return LoggerFactory.get_logger("promptflow", verbosity=logging.WARNING) -def _get_format_for_logger(): +def _get_format_for_logger(default_log_format: str = None, default_date_format: str = None) -> str: """ Get the logging format and date format for logger. @@ -455,4 +458,6 @@ def _get_format_for_logger(): if handler.formatter: return handler.formatter._fmt, handler.formatter.datefmt # Return default format and date format if no formatter is found + if default_log_format: + return default_log_format, default_date_format return LOG_FORMAT, DATETIME_FORMAT From b274b8b8eb2daccac7d47baa9802fc5294658791 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 17:51:45 +0800 Subject: [PATCH 3/9] Update location --- .../promptflow/_utils/logger_utils.py | 42 +++++++++---------- 1 file changed, 21 insertions(+), 21 deletions(-) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index 00df7e18a65..9e40424281b 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -29,6 +29,27 @@ DATETIME_FORMAT = "%Y-%m-%d %H:%M:%S %z" +def _get_format_for_logger(default_log_format: str = None, default_date_format: str = None) -> str: + """ + Get the logging format and date format for logger. + + This function attempts to find the handler of the root logger with a configured formatter. + If such a handler is found, it returns the format and date format used by this handler. + This can be configured through logging.basicConfig. If no configured formatter is found, + it defaults to LOG_FORMAT and DATETIME_FORMAT. + """ + # Get the root logger + logger = logging.getLogger() + # Return the format and date format from the default handler + for handler in logger.handlers: + if handler.formatter: + return handler.formatter._fmt, handler.formatter.datefmt + # Return default format and date format if no formatter is found + if default_log_format: + return default_log_format, default_date_format + return LOG_FORMAT, DATETIME_FORMAT + + class CredentialScrubberFormatter(logging.Formatter): """Formatter that scrubs credentials in logs.""" @@ -440,24 +461,3 @@ def get_cli_sdk_logger(): # to avoid circular import error, use plain string here instead of importing from _constants # because this function is also called in _prepare_home_dir which is in _constants return LoggerFactory.get_logger("promptflow", verbosity=logging.WARNING) - - -def _get_format_for_logger(default_log_format: str = None, default_date_format: str = None) -> str: - """ - Get the logging format and date format for logger. - - This function attempts to find the handler of the root logger with a configured formatter. - If such a handler is found, it returns the format and date format used by this handler. - This can be configured through logging.basicConfig. If no configured formatter is found, - it defaults to LOG_FORMAT and DATETIME_FORMAT. - """ - # Get the root logger - logger = logging.getLogger() - # Return the format and date format from the default handler - for handler in logger.handlers: - if handler.formatter: - return handler.formatter._fmt, handler.formatter.datefmt - # Return default format and date format if no formatter is found - if default_log_format: - return default_log_format, default_date_format - return LOG_FORMAT, DATETIME_FORMAT From dd5c3471db66f8c4f3a45baae1435dfbbe48f419 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 18:32:18 +0800 Subject: [PATCH 4/9] Add a new test case --- .../tests/executor/e2etests/test_logs.py | 27 +++++++++++++++++++ 1 file changed, 27 insertions(+) diff --git a/src/promptflow/tests/executor/e2etests/test_logs.py b/src/promptflow/tests/executor/e2etests/test_logs.py index 21c2c00c915..8cbe5d1d78a 100644 --- a/src/promptflow/tests/executor/e2etests/test_logs.py +++ b/src/promptflow/tests/executor/e2etests/test_logs.py @@ -1,3 +1,4 @@ +import logging import os from pathlib import Path from tempfile import mkdtemp @@ -277,3 +278,29 @@ def test_async_log_in_worker_thread(self): logs_list = ["INFO monitor_long_running_coroutine started"] assert all(log in log_content for log in logs_list) os.environ.pop("PF_LONG_RUNNING_LOGGING_INTERVAL") + + def test_change_log_format(self): + # Save original log level and handlers + self.original_log_level = logging.root.manager.disable + self.original_handlers = logging.root.handlers[:] + + # Change log format + date_format = "%Y/%m/%d %H:%M:%S" + log_format = "[%(asctime)s][%(name)s][%(levelname)s] - %(message)s" + logging.basicConfig(format=log_format, datefmt=date_format) + + logs_directory = Path(mkdtemp()) + log_path = str(logs_directory / "flow.log") + with LogContext(log_path): + executor = FlowExecutor.create(get_yaml_file("print_input_flow"), {}) + executor.exec_line(inputs={"text": "line_text"}) + log_content = load_content(log_path) + logs_list = ["INFO - execution - Start executing nodes in thread pool mode."] + assert all(log in log_content for log in logs_list), f"Log content is {log_content}" + + # Restore original log level and handlers + logging.root.manager.disable = self.original_log_level + logging.root.handlers = self.original_handlers[:] + for handler in logging.root.handlers: + logging.root.removeHandler(handler) + logging.basicConfig(handlers=self.original_handlers) From b7be75a3e491c5ccbb6dcaaacca5d911f9ec0699 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 18:32:55 +0800 Subject: [PATCH 5/9] Update test cases --- src/promptflow/tests/executor/e2etests/test_logs.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/promptflow/tests/executor/e2etests/test_logs.py b/src/promptflow/tests/executor/e2etests/test_logs.py index 8cbe5d1d78a..dbff373282c 100644 --- a/src/promptflow/tests/executor/e2etests/test_logs.py +++ b/src/promptflow/tests/executor/e2etests/test_logs.py @@ -295,7 +295,7 @@ def test_change_log_format(self): executor = FlowExecutor.create(get_yaml_file("print_input_flow"), {}) executor.exec_line(inputs={"text": "line_text"}) log_content = load_content(log_path) - logs_list = ["INFO - execution - Start executing nodes in thread pool mode."] + logs_list = ["[execution][INFO] - Start executing nodes in thread pool mode."] assert all(log in log_content for log in logs_list), f"Log content is {log_content}" # Restore original log level and handlers From 3e2664647689dc7f898cdacefc433fdc864fbfd5 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 23:01:27 +0800 Subject: [PATCH 6/9] Add env to set log format --- .../promptflow/_utils/logger_utils.py | 15 +++++---------- 1 file changed, 5 insertions(+), 10 deletions(-) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index 9e40424281b..29aa8042f33 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -38,16 +38,11 @@ def _get_format_for_logger(default_log_format: str = None, default_date_format: This can be configured through logging.basicConfig. If no configured formatter is found, it defaults to LOG_FORMAT and DATETIME_FORMAT. """ - # Get the root logger - logger = logging.getLogger() - # Return the format and date format from the default handler - for handler in logger.handlers: - if handler.formatter: - return handler.formatter._fmt, handler.formatter.datefmt - # Return default format and date format if no formatter is found - if default_log_format: - return default_log_format, default_date_format - return LOG_FORMAT, DATETIME_FORMAT + default_log_format = default_log_format or LOG_FORMAT + default_date_format = default_date_format or DATETIME_FORMAT + log_format = os.environ.get("PF_LOG_FORMAT") or default_log_format + datetime_format = os.environ.get("PF_DATETIME_FORMAT") or default_date_format + return log_format, datetime_format class CredentialScrubberFormatter(logging.Formatter): From 3d74904ebfe073c9d77a6a5254a12dab8f79add4 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 23:03:21 +0800 Subject: [PATCH 7/9] Use env to update log format --- src/promptflow-core/promptflow/_utils/logger_utils.py | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index 29aa8042f33..e0e9c18ffc7 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -38,10 +38,8 @@ def _get_format_for_logger(default_log_format: str = None, default_date_format: This can be configured through logging.basicConfig. If no configured formatter is found, it defaults to LOG_FORMAT and DATETIME_FORMAT. """ - default_log_format = default_log_format or LOG_FORMAT - default_date_format = default_date_format or DATETIME_FORMAT - log_format = os.environ.get("PF_LOG_FORMAT") or default_log_format - datetime_format = os.environ.get("PF_DATETIME_FORMAT") or default_date_format + log_format = os.environ.get("PF_LOG_FORMAT") or default_log_format or LOG_FORMAT + datetime_format = os.environ.get("PF_DATETIME_FORMAT") or default_date_format or DATETIME_FORMAT return log_format, datetime_format From a0638f4c42d5f61c68e7bee7872c0837494182a5 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 23 Apr 2024 23:20:45 +0800 Subject: [PATCH 8/9] Add ut to assert log format change --- .../promptflow/_utils/logger_utils.py | 2 +- .../tests/executor/e2etests/test_logs.py | 31 +++++++++---------- 2 files changed, 16 insertions(+), 17 deletions(-) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index e0e9c18ffc7..2b911c7ef7c 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -39,7 +39,7 @@ def _get_format_for_logger(default_log_format: str = None, default_date_format: it defaults to LOG_FORMAT and DATETIME_FORMAT. """ log_format = os.environ.get("PF_LOG_FORMAT") or default_log_format or LOG_FORMAT - datetime_format = os.environ.get("PF_DATETIME_FORMAT") or default_date_format or DATETIME_FORMAT + datetime_format = os.environ.get("PF_LOG_DATETIME_FORMAT") or default_date_format or DATETIME_FORMAT return log_format, datetime_format diff --git a/src/promptflow/tests/executor/e2etests/test_logs.py b/src/promptflow/tests/executor/e2etests/test_logs.py index dbff373282c..64811ed48be 100644 --- a/src/promptflow/tests/executor/e2etests/test_logs.py +++ b/src/promptflow/tests/executor/e2etests/test_logs.py @@ -1,5 +1,5 @@ -import logging import os +from datetime import datetime from pathlib import Path from tempfile import mkdtemp @@ -279,15 +279,12 @@ def test_async_log_in_worker_thread(self): assert all(log in log_content for log in logs_list) os.environ.pop("PF_LONG_RUNNING_LOGGING_INTERVAL") - def test_change_log_format(self): - # Save original log level and handlers - self.original_log_level = logging.root.manager.disable - self.original_handlers = logging.root.handlers[:] - + def test_change_log_format(self, monkeypatch): # Change log format date_format = "%Y/%m/%d %H:%M:%S" log_format = "[%(asctime)s][%(name)s][%(levelname)s] - %(message)s" - logging.basicConfig(format=log_format, datefmt=date_format) + monkeypatch.setenv("PF_LOG_FORMAT", log_format) + monkeypatch.setenv("PF_LOG_DATETIME_FORMAT", date_format) logs_directory = Path(mkdtemp()) log_path = str(logs_directory / "flow.log") @@ -295,12 +292,14 @@ def test_change_log_format(self): executor = FlowExecutor.create(get_yaml_file("print_input_flow"), {}) executor.exec_line(inputs={"text": "line_text"}) log_content = load_content(log_path) - logs_list = ["[execution][INFO] - Start executing nodes in thread pool mode."] - assert all(log in log_content for log in logs_list), f"Log content is {log_content}" - - # Restore original log level and handlers - logging.root.manager.disable = self.original_log_level - logging.root.handlers = self.original_handlers[:] - for handler in logging.root.handlers: - logging.root.removeHandler(handler) - logging.basicConfig(handlers=self.original_handlers) + current_date = datetime.now().strftime("%Y/%m/%d") + logs_list = [ + f"[{current_date}", + "[execution.flow][INFO] - Start executing nodes in thread pool mode.", + "[execution.flow][INFO] - Executing node print_input.", + "[execution.flow][INFO] - Node print_input completes.", + "stderr> STDERR: line_text", + ] + assert all( + log in log_content for log in logs_list + ), f"Missing logs are [{[log for log in logs_list if log not in log_content]}]" From 848320348d6f04bab6340bf84fbf234b1fe47634 Mon Sep 17 00:00:00 2001 From: Peiwen Gao Date: Tue, 14 May 2024 15:02:28 +0800 Subject: [PATCH 9/9] Update annotation --- src/promptflow-core/promptflow/_utils/logger_utils.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/promptflow-core/promptflow/_utils/logger_utils.py b/src/promptflow-core/promptflow/_utils/logger_utils.py index 2b911c7ef7c..b97d0646813 100644 --- a/src/promptflow-core/promptflow/_utils/logger_utils.py +++ b/src/promptflow-core/promptflow/_utils/logger_utils.py @@ -14,7 +14,7 @@ from dataclasses import dataclass from functools import partial from pathlib import Path -from typing import List, Optional +from typing import List, Optional, Tuple from promptflow._constants import LINE_NUMBER_WIDTH, PF_LOGGING_LEVEL from promptflow._utils.credential_scrubber import CredentialScrubber @@ -29,7 +29,7 @@ DATETIME_FORMAT = "%Y-%m-%d %H:%M:%S %z" -def _get_format_for_logger(default_log_format: str = None, default_date_format: str = None) -> str: +def _get_format_for_logger(default_log_format: str = None, default_date_format: str = None) -> Tuple[str, str]: """ Get the logging format and date format for logger.