From 0b1e80b02928f1b79e01cbef3aebfb58a5002f45 Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Wed, 16 Apr 2025 20:45:41 -0300 Subject: [PATCH 1/8] fix(logger): warn customers when the ALC log level is less verbose than log buffer --- aws_lambda_powertools/logging/logger.py | 28 ++++++++++++++++++ .../test_powertools_logger_buffer.py | 29 +++++++++++++++++++ 2 files changed, 57 insertions(+) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index 3dae687e7e6..455907a763b 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -1047,6 +1047,20 @@ def _determine_log_level(self, level: str | int | None) -> str | int: stacklevel=2, ) + # Check if buffer level is less verbose than ALC + if ( + hasattr(self, "_buffer_config") + and self._buffer_config + and logging.getLevelName(lambda_log_level) + > logging.getLevelName(self._buffer_config.buffer_at_verbosity) + ): + warnings.warn( + "Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level. " + "Buffered logs will be filtered by ALC", + UserWarning, + stacklevel=2, + ) + # AWS Lambda Advanced Logging Controls takes precedence over Powertools log level and we use this if lambda_log_level: return lambda_log_level @@ -1191,6 +1205,20 @@ def flush_buffer(self) -> None: if not buffer: return + # Check ALC level before flushing + alc_level = self._get_aws_lambda_log_level() + if ( + alc_level is not None + and self._buffer_config + and logging.getLevelName(alc_level) > logging.getLevelName(self._buffer_config.buffer_at_verbosity) + ): + warnings.warn( + message="Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level." + "Some logs might be missing.", + category=UserWarning, + stacklevel=2, + ) + # Process log records for log_line in buffer: self._create_and_flush_log_record(log_line) diff --git a/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py b/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py index 3c149d6dfed..aaa9ca72dd5 100644 --- a/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py +++ b/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py @@ -525,3 +525,32 @@ def handler(event, context): # THEN Verify buffer for the original trace ID is cleared assert not logger._buffer_cache.get("1-67c39786-5908a82a246fb67f3089263f") + + +def test_warning_when_alc_less_verbose_than_buffer(monkeypatch): + # GIVEN Lambda ALC set to INFO + monkeypatch.setenv("AWS_LAMBDA_LOG_LEVEL", "INFO") + + # WHEN creating a logger with DEBUG buffer level AND logging a debug message + # THEN a warning should be emitted + with pytest.warns(UserWarning, match="Advanced Logging Controls .* Buffered logs will be filtered by ALC"): + logger = Logger(service="test", level="DEBUG", buffer_config=LoggerBufferConfig(buffer_at_verbosity="DEBUG")) + logger.debug("This is a debug") + + +def test_warning_on_buffer_flush_when_alc_less_verbose(monkeypatch): + # GIVEN Lambda ALC set to INFO + monkeypatch.setenv("AWS_LAMBDA_LOG_LEVEL", "INFO") + + # WHEN creating a logger with DEBUG buffer level + with pytest.warns(UserWarning) as warning_info: + logger = Logger(service="test", level="DEBUG", buffer_config=LoggerBufferConfig(buffer_at_verbosity="DEBUG")) + + # AND logging a debug message and flushing buffer + logger.debug("This is a debug") + logger.flush_buffer() + + # THEN appropriate warnings should be emitted + assert len(warning_info) == 2 + assert "Buffered logs will be filtered by ALC" in str(warning_info[0].message) + assert "Some logs might be missing" in str(warning_info[1].message) From d6b9038768bf76830c1ff0a5dc489185b92aaca7 Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 09:38:52 -0300 Subject: [PATCH 2/8] change flush buffer warning --- aws_lambda_powertools/logging/logger.py | 35 +++++++++++-------- .../test_powertools_logger_buffer.py | 23 ++++++++---- 2 files changed, 36 insertions(+), 22 deletions(-) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index 455907a763b..332427f10ca 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -242,6 +242,8 @@ def __init__( buffer_config: LoggerBufferConfig | None = None, **kwargs, ) -> None: + self._buffer_config = buffer_config + self._buffer_cache = LoggerBufferCache(max_size_bytes=self._buffer_config.max_bytes) if buffer_config else None # Used in case of sampling self.initial_log_level = self._determine_log_level(level) @@ -1057,7 +1059,7 @@ def _determine_log_level(self, level: str | int | None) -> str | int: warnings.warn( "Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level. " "Buffered logs will be filtered by ALC", - UserWarning, + PowertoolsUserWarning, stacklevel=2, ) @@ -1196,6 +1198,23 @@ def flush_buffer(self) -> None: """ tracer_id = get_tracer_id() + # Check ALC level against buffer level + lambda_log_level = self._get_aws_lambda_log_level() + if lambda_log_level: + # Check if buffer level is less verbose than ALC + if ( + hasattr(self, "_buffer_config") + and self._buffer_config + and logging.getLevelName(lambda_log_level) + > logging.getLevelName(self._buffer_config.buffer_at_verbosity) + ): + warnings.warn( + "Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level. " + "Some logs might be missing", + PowertoolsUserWarning, + stacklevel=2, + ) + # Flushing log without a tracer id? Return if not tracer_id: return @@ -1205,20 +1224,6 @@ def flush_buffer(self) -> None: if not buffer: return - # Check ALC level before flushing - alc_level = self._get_aws_lambda_log_level() - if ( - alc_level is not None - and self._buffer_config - and logging.getLevelName(alc_level) > logging.getLevelName(self._buffer_config.buffer_at_verbosity) - ): - warnings.warn( - message="Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level." - "Some logs might be missing.", - category=UserWarning, - stacklevel=2, - ) - # Process log records for log_line in buffer: self._create_and_flush_log_record(log_line) diff --git a/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py b/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py index aaa9ca72dd5..5811b47142d 100644 --- a/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py +++ b/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py @@ -527,15 +527,22 @@ def handler(event, context): assert not logger._buffer_cache.get("1-67c39786-5908a82a246fb67f3089263f") -def test_warning_when_alc_less_verbose_than_buffer(monkeypatch): +def test_warning_when_alc_less_verbose_than_buffer(stdout, monkeypatch): # GIVEN Lambda ALC set to INFO monkeypatch.setenv("AWS_LAMBDA_LOG_LEVEL", "INFO") - # WHEN creating a logger with DEBUG buffer level AND logging a debug message + # WHEN creating a logger with DEBUG buffer level # THEN a warning should be emitted - with pytest.warns(UserWarning, match="Advanced Logging Controls .* Buffered logs will be filtered by ALC"): + with pytest.warns(PowertoolsUserWarning, match="Advanced Logging Controls*"): logger = Logger(service="test", level="DEBUG", buffer_config=LoggerBufferConfig(buffer_at_verbosity="DEBUG")) - logger.debug("This is a debug") + + # AND logging a debug message + logger.debug("This is a debug") + + # AND flushing buffer + # THEN another warning should be emitted about ALC and buffer level mismatch + with pytest.warns(PowertoolsUserWarning, match="Advanced Logging Controls*"): + logger.flush_buffer() def test_warning_on_buffer_flush_when_alc_less_verbose(monkeypatch): @@ -551,6 +558,8 @@ def test_warning_on_buffer_flush_when_alc_less_verbose(monkeypatch): logger.flush_buffer() # THEN appropriate warnings should be emitted - assert len(warning_info) == 2 - assert "Buffered logs will be filtered by ALC" in str(warning_info[0].message) - assert "Some logs might be missing" in str(warning_info[1].message) + assert any("Some logs might be missing" in str(w.message) for w in warning_info) + assert any( + "Current log level (DEBUG) does not match AWS Lambda Advanced Logging Controls" in str(w.message) + for w in warning_info + ) From 60c6eba341c965aac69a5fac614954a4b8df3891 Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 09:48:58 -0300 Subject: [PATCH 3/8] mypy --- aws_lambda_powertools/logging/logger.py | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index 332427f10ca..4fb23ad6756 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -243,7 +243,7 @@ def __init__( **kwargs, ) -> None: self._buffer_config = buffer_config - self._buffer_cache = LoggerBufferCache(max_size_bytes=self._buffer_config.max_bytes) if buffer_config else None + self._buffer_cache = LoggerBufferCache(max_size_bytes=buffer_config.max_bytes) if buffer_config else None # Used in case of sampling self.initial_log_level = self._determine_log_level(level) @@ -1196,7 +1196,8 @@ def flush_buffer(self) -> None: Any exceptions from underlying logging or buffer mechanisms will be propagated to caller """ - tracer_id = get_tracer_id() + if not self._buffer_config or not self._buffer_cache: + return # Check ALC level against buffer level lambda_log_level = self._get_aws_lambda_log_level() @@ -1215,6 +1216,8 @@ def flush_buffer(self) -> None: stacklevel=2, ) + tracer_id = get_tracer_id() + # Flushing log without a tracer id? Return if not tracer_id: return From dd38009dc3560c2be7e2fcc9f03f3d7eb0e6f6b8 Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 09:50:23 -0300 Subject: [PATCH 4/8] mypy --- aws_lambda_powertools/logging/logger.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index 4fb23ad6756..bc40c8a91e8 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -1149,6 +1149,9 @@ def _add_log_record_to_buffer( Handles special first invocation buffering and migration of log records between different tracer contexts. """ + if not self._buffer_cache or not self._buffer_config: + return + # Determine tracer ID, defaulting to first invoke marker tracer_id = get_tracer_id() From 5f802579a2b9b97ad97b219e5d76f7ea1239a234 Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 09:53:38 -0300 Subject: [PATCH 5/8] mypy --- aws_lambda_powertools/logging/logger.py | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index bc40c8a91e8..e8438deb76a 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -1151,7 +1151,7 @@ def _add_log_record_to_buffer( """ if not self._buffer_cache or not self._buffer_config: return - + # Determine tracer ID, defaulting to first invoke marker tracer_id = get_tracer_id() @@ -1256,9 +1256,10 @@ def clear_buffer(self) -> None: ------- None """ - if self._buffer_config: - self._buffer_cache.clear() - + if not self._buffer_config or not self._buffer_cache: + return + + self._buffer_cache.clear() def set_package_logger( level: str | int = logging.DEBUG, From aad91da488e216ecb68c95187204274ba697bb11 Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 11:22:51 -0300 Subject: [PATCH 6/8] fix logger --- aws_lambda_powertools/logging/logger.py | 21 ++++++--------------- 1 file changed, 6 insertions(+), 15 deletions(-) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index e8438deb76a..56e68840cd2 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -242,12 +242,6 @@ def __init__( buffer_config: LoggerBufferConfig | None = None, **kwargs, ) -> None: - self._buffer_config = buffer_config - self._buffer_cache = LoggerBufferCache(max_size_bytes=buffer_config.max_bytes) if buffer_config else None - - # Used in case of sampling - self.initial_log_level = self._determine_log_level(level) - self.service = resolve_env_var_choice( choice=service, env=os.getenv(constants.SERVICE_NAME_ENV, "service_undefined"), @@ -287,6 +281,9 @@ def __init__( if self._buffer_config: self._buffer_cache = LoggerBufferCache(max_size_bytes=self._buffer_config.max_bytes) + # Used in case of sampling + self.initial_log_level = self._determine_log_level(level) + self._init_logger( formatter_options=formatter_options, log_level=level, @@ -1149,8 +1146,6 @@ def _add_log_record_to_buffer( Handles special first invocation buffering and migration of log records between different tracer contexts. """ - if not self._buffer_cache or not self._buffer_config: - return # Determine tracer ID, defaulting to first invoke marker tracer_id = get_tracer_id() @@ -1199,9 +1194,6 @@ def flush_buffer(self) -> None: Any exceptions from underlying logging or buffer mechanisms will be propagated to caller """ - if not self._buffer_config or not self._buffer_cache: - return - # Check ALC level against buffer level lambda_log_level = self._get_aws_lambda_log_level() if lambda_log_level: @@ -1256,10 +1248,9 @@ def clear_buffer(self) -> None: ------- None """ - if not self._buffer_config or not self._buffer_cache: - return - - self._buffer_cache.clear() + if self._buffer_config: + self._buffer_cache.clear() + def set_package_logger( level: str | int = logging.DEBUG, From ef33a779ee07157c59022de113b93068b4e938ac Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 11:36:48 -0300 Subject: [PATCH 7/8] change flush buffer warn --- aws_lambda_powertools/logging/logger.py | 28 ++++++++----------- .../test_powertools_logger_buffer.py | 20 ++----------- 2 files changed, 14 insertions(+), 34 deletions(-) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index 56e68840cd2..e06bd197686 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -1194,22 +1194,6 @@ def flush_buffer(self) -> None: Any exceptions from underlying logging or buffer mechanisms will be propagated to caller """ - # Check ALC level against buffer level - lambda_log_level = self._get_aws_lambda_log_level() - if lambda_log_level: - # Check if buffer level is less verbose than ALC - if ( - hasattr(self, "_buffer_config") - and self._buffer_config - and logging.getLevelName(lambda_log_level) - > logging.getLevelName(self._buffer_config.buffer_at_verbosity) - ): - warnings.warn( - "Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level. " - "Some logs might be missing", - PowertoolsUserWarning, - stacklevel=2, - ) tracer_id = get_tracer_id() @@ -1221,6 +1205,18 @@ def flush_buffer(self) -> None: buffer = self._buffer_cache.get(tracer_id) if not buffer: return + + # Check ALC level against buffer level + lambda_log_level = self._get_aws_lambda_log_level() + if lambda_log_level: + # Check if buffer level is less verbose than ALC + if (logging.getLevelName(lambda_log_level) > logging.getLevelName(self._buffer_config.buffer_at_verbosity)): + warnings.warn( + "Advanced Logging Controls (ALC) Log Level is less verbose than Log Buffering Log Level. " + "Some logs might be missing", + PowertoolsUserWarning, + stacklevel=2, + ) # Process log records for log_line in buffer: diff --git a/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py b/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py index 5811b47142d..7b02a35551d 100644 --- a/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py +++ b/tests/functional/logger/required_dependencies/test_powertools_logger_buffer.py @@ -530,6 +530,8 @@ def handler(event, context): def test_warning_when_alc_less_verbose_than_buffer(stdout, monkeypatch): # GIVEN Lambda ALC set to INFO monkeypatch.setenv("AWS_LAMBDA_LOG_LEVEL", "INFO") + # Set initial trace ID for first Lambda invocation + monkeypatch.setenv(constants.XRAY_TRACE_ID_ENV, "1-67c39786-5908a82a246fb67f3089263f") # WHEN creating a logger with DEBUG buffer level # THEN a warning should be emitted @@ -545,21 +547,3 @@ def test_warning_when_alc_less_verbose_than_buffer(stdout, monkeypatch): logger.flush_buffer() -def test_warning_on_buffer_flush_when_alc_less_verbose(monkeypatch): - # GIVEN Lambda ALC set to INFO - monkeypatch.setenv("AWS_LAMBDA_LOG_LEVEL", "INFO") - - # WHEN creating a logger with DEBUG buffer level - with pytest.warns(UserWarning) as warning_info: - logger = Logger(service="test", level="DEBUG", buffer_config=LoggerBufferConfig(buffer_at_verbosity="DEBUG")) - - # AND logging a debug message and flushing buffer - logger.debug("This is a debug") - logger.flush_buffer() - - # THEN appropriate warnings should be emitted - assert any("Some logs might be missing" in str(w.message) for w in warning_info) - assert any( - "Current log level (DEBUG) does not match AWS Lambda Advanced Logging Controls" in str(w.message) - for w in warning_info - ) From 60d6984db34dc406f984b71a67364a8b76a0b4cc Mon Sep 17 00:00:00 2001 From: Ana Falcao Date: Thu, 17 Apr 2025 11:53:16 -0300 Subject: [PATCH 8/8] check buffer config --- aws_lambda_powertools/logging/logger.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py index e06bd197686..e8340dd2b13 100644 --- a/aws_lambda_powertools/logging/logger.py +++ b/aws_lambda_powertools/logging/logger.py @@ -1206,6 +1206,9 @@ def flush_buffer(self) -> None: if not buffer: return + if not self._buffer_config: + return + # Check ALC level against buffer level lambda_log_level = self._get_aws_lambda_log_level() if lambda_log_level: