From 57ce60402abb98cfcdf099ab1c54b862c747763d Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky Date: Wed, 17 Apr 2024 16:29:02 -0400 Subject: [PATCH 1/7] emit enhanced error metric and create span when an exception is raised outside of the handler function --- datadog_lambda/handler.py | 34 ++++++++++++++++- datadog_lambda/metric.py | 6 +-- datadog_lambda/tracing.py | 36 ++++++++++++++++++ tests/test_handler.py | 80 +++++++++++++++++++++++++++++++++++++++ tests/test_tracing.py | 47 +++++++++++++++++++++++ 5 files changed, 198 insertions(+), 5 deletions(-) create mode 100644 tests/test_handler.py diff --git a/datadog_lambda/handler.py b/datadog_lambda/handler.py index 777dc492..9e7da0bf 100644 --- a/datadog_lambda/handler.py +++ b/datadog_lambda/handler.py @@ -7,6 +7,9 @@ from importlib import import_module import os +import time + +from datadog_lambda.tracing import emit_telemetry_on_exception_outside_of_handler from datadog_lambda.wrapper import datadog_lambda_wrapper from datadog_lambda.module_name import modify_module_name @@ -15,6 +18,27 @@ class HandlerError(Exception): pass +class _ErrorOutsideHandlerDecorator(object): + """ + Decorator for when an exception occurs outside of the handler function. + Emits telemetry and re-raises the exception. + """ + + def __init__(self, exception, modified_mod_name, start_time_ns): + self.exception = exception + self.modified_mod_name = modified_mod_name + self.start_time_ns = start_time_ns + + def __call__(self, event, context, **kwargs): + emit_telemetry_on_exception_outside_of_handler( + context, + self.exception, + self.modified_mod_name, + self.start_time_ns, + ) + raise self.exception + + path = os.environ.get("DD_LAMBDA_HANDLER", None) if path is None: raise HandlerError( @@ -27,5 +51,11 @@ class HandlerError(Exception): (mod_name, handler_name) = parts modified_mod_name = modify_module_name(mod_name) -handler_module = import_module(modified_mod_name) -handler = datadog_lambda_wrapper(getattr(handler_module, handler_name)) + +try: + start_time_ns = time.time_ns() + handler_module = import_module(modified_mod_name) + handler_func = getattr(handler_module, handler_name) + handler = datadog_lambda_wrapper(handler_func) +except Exception as e: + handler = _ErrorOutsideHandlerDecorator(e, modified_mod_name, start_time_ns) diff --git a/datadog_lambda/metric.py b/datadog_lambda/metric.py index e3b01a90..bc7391a6 100644 --- a/datadog_lambda/metric.py +++ b/datadog_lambda/metric.py @@ -100,7 +100,7 @@ def submit_enhanced_metric(metric_name, lambda_context): Args: metric_name (str): metric name w/o enhanced prefix i.e. "invocations" or "errors" - lambda_context (dict): Lambda context dict passed to the function by AWS + lambda_context (object): Lambda context dict passed to the function by AWS """ if not enhanced_metrics_enabled: logger.debug( @@ -118,7 +118,7 @@ def submit_invocations_metric(lambda_context): """Increment aws.lambda.enhanced.invocations by 1, applying runtime, layer, and cold_start tags Args: - lambda_context (dict): Lambda context dict passed to the function by AWS + lambda_context (object): Lambda context dict passed to the function by AWS """ submit_enhanced_metric("invocations", lambda_context) @@ -127,6 +127,6 @@ def submit_errors_metric(lambda_context): """Increment aws.lambda.enhanced.errors by 1, applying runtime, layer, and cold_start tags Args: - lambda_context (dict): Lambda context dict passed to the function by AWS + lambda_context (object): Lambda context dict passed to the function by AWS """ submit_enhanced_metric("errors", lambda_context) diff --git a/datadog_lambda/tracing.py b/datadog_lambda/tracing.py index 1d73de3e..0e074395 100644 --- a/datadog_lambda/tracing.py +++ b/datadog_lambda/tracing.py @@ -6,6 +6,7 @@ import logging import os import base64 +import traceback import ujson as json from datetime import datetime, timezone from typing import Optional, Dict @@ -1320,3 +1321,38 @@ def is_async(span: Span) -> bool: e, ) return False + + +def emit_telemetry_on_exception_outside_of_handler( + context, exception, resource_name, start_time_ns +): + """ + Emit an enhanced error metric and create a span for exceptions occuring outside of the handler + """ + submit_errors_metric(context) + + span = tracer.trace( + "aws.lambda", + service="aws.lambda", + resource=resource_name, + span_type="serverless", + ) + span.start_ns = start_time_ns + tags = { + "error.status": 500, + "error.type": type(exception).__name__, + "error.message": exception, + "error.stack": "".join( + traceback.format_exception( + type(exception), exception, exception.__traceback__ + ) + ), + "resource_names": resource_name, + "resource.name": resource_name, + "operation_name": "aws.lambda", + "status": "error", + "request_id": context.aws_request_id, + } + span.set_tags(tags) + span.error = 1 + span.finish() diff --git a/tests/test_handler.py b/tests/test_handler.py new file mode 100644 index 00000000..e8496c28 --- /dev/null +++ b/tests/test_handler.py @@ -0,0 +1,80 @@ +import os +import sys +import unittest +from unittest.mock import patch + +from tests.utils import get_mock_context + + +class TestHandler(unittest.TestCase): + def tearDown(self): + for mod in sys.modules.copy(): + if mod.startswith("datadog_lambda.handler"): + del sys.modules[mod] + + def test_dd_lambda_handler_env_var_none(self): + with self.assertRaises(Exception) as context: + import datadog_lambda.handler as handler + + assert context.exception == handler.HandlerError( + "DD_LAMBDA_HANDLER is not defined. Can't use prebuilt datadog handler" + ) + + @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "malformed"}, clear=True) + def test_dd_lambda_handler_env_var_malformed(self): + with self.assertRaises(Exception) as context: + import datadog_lambda.handler as handler + + assert context.exception == handler.HandlerError( + "Value malformed for DD_LAMBDA_HANDLER has invalid format." + ) + + @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) + @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") + @patch("time.time_ns", return_value=42) + def test_exception_importing_module(self, mock_time, mock_emit_telemetry): + with self.assertRaises(ModuleNotFoundError) as test_context: + import datadog_lambda.handler + + lambda_context = get_mock_context() + datadog_lambda.handler.handler.__call__(None, lambda_context) + mock_emit_telemetry.assert_called_once_with( + lambda_context, test_context.exception, "nonsense", 42 + ) + + @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) + @patch("importlib.import_module", return_value=None) + @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") + @patch("time.time_ns", return_value=42) + def test_exception_getting_handler_func( + self, mock_time, mock_emit_telemetry, mock_import + ): + with self.assertRaises(AttributeError) as test_context: + import datadog_lambda.handler + + lambda_context = get_mock_context() + datadog_lambda.handler.handler.__call__(None, lambda_context) + mock_emit_telemetry.assert_called_once_with( + lambda_context, test_context.exception, "nonsense", 42 + ) + + @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) + @patch("importlib.import_module") + @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") + @patch("time.time_ns", return_value=42) + @patch("datadog_lambda.wrapper.datadog_lambda_wrapper") + def test_handler_success( + self, mock_lambda_wrapper, mock_time, mock_emit_telemetry, mock_import + ): + def nonsense(): + pass + + mock_import.nonsense.return_value = nonsense + + import datadog_lambda.handler + + lambda_context = get_mock_context() + datadog_lambda.handler.handler.__call__(None, lambda_context) + + mock_emit_telemetry.assert_not_called() + mock_lambda_wrapper.assert_called_once_with(mock_import().nonsense) diff --git a/tests/test_tracing.py b/tests/test_tracing.py index 296bd0dc..f81e4941 100644 --- a/tests/test_tracing.py +++ b/tests/test_tracing.py @@ -1,6 +1,7 @@ import copy import functools import json +import traceback import pytest import os import unittest @@ -36,6 +37,7 @@ determine_service_name, service_mapping as global_service_mapping, propagator, + emit_telemetry_on_exception_outside_of_handler, ) from datadog_lambda.trigger import EventTypes @@ -1999,3 +2001,48 @@ def test_deterministic_m5_hash__always_leading_with_zero(self): # Leading zeros will be omitted, so only test for full 64 bits present if len(result_in_binary) == 66: # "0b" + 64 bits. self.assertTrue(result_in_binary.startswith("0b0")) + + +class TestExceptionOutsideHandler(unittest.TestCase): + @patch("datadog_lambda.tracing.submit_errors_metric") + def test_exception_outside_handler(self, mock_submit_errors_metric): + fake_error = ValueError("Some error message") + resource_name = "my_handler" + span_type = "aws.lambda" + mock_span = Mock() + context = get_mock_context() + with patch( + "datadog_lambda.tracing.tracer.trace", return_value=mock_span + ) as mock_trace: + emit_telemetry_on_exception_outside_of_handler( + context, fake_error, resource_name, 42 + ) + + mock_submit_errors_metric.assert_called_once_with(context) + + mock_trace.assert_called_once_with( + span_type, + service="aws.lambda", + resource=resource_name, + span_type="serverless", + ) + mock_span.set_tags.assert_called_once_with( + { + "error.status": 500, + "error.type": "ValueError", + "error.message": fake_error, + "error.stack": "".join( + traceback.format_exception( + type(fake_error), fake_error, fake_error.__traceback__ + ) + ), + "resource_names": resource_name, + "resource.name": resource_name, + "operation_name": span_type, + "status": "error", + "request_id": context.aws_request_id, + } + ) + mock_span.finish.assert_called_once() + assert mock_span.error == 1 + assert mock_span.start_ns == 42 From 885adfed900226d2cc9b23c85c5b294fb813b641 Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky Date: Tue, 23 Apr 2024 14:22:05 -0400 Subject: [PATCH 2/7] rename handler --- datadog_lambda/handler.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/datadog_lambda/handler.py b/datadog_lambda/handler.py index 9e7da0bf..f37c8572 100644 --- a/datadog_lambda/handler.py +++ b/datadog_lambda/handler.py @@ -18,7 +18,7 @@ class HandlerError(Exception): pass -class _ErrorOutsideHandlerDecorator(object): +class _ErrorFallbackHandler(object): """ Decorator for when an exception occurs outside of the handler function. Emits telemetry and re-raises the exception. @@ -58,4 +58,4 @@ def __call__(self, event, context, **kwargs): handler_func = getattr(handler_module, handler_name) handler = datadog_lambda_wrapper(handler_func) except Exception as e: - handler = _ErrorOutsideHandlerDecorator(e, modified_mod_name, start_time_ns) + handler = _ErrorFallbackHandler(e, modified_mod_name, start_time_ns) From fb6e60cb4ea632d8862b52009738df03084d8ab3 Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky Date: Tue, 23 Apr 2024 14:40:29 -0400 Subject: [PATCH 3/7] move fallback handler to wrapper.py --- datadog_lambda/handler.py | 26 ++------------------------ datadog_lambda/wrapper.py | 23 +++++++++++++++++++++++ tests/test_handler.py | 6 +++--- 3 files changed, 28 insertions(+), 27 deletions(-) diff --git a/datadog_lambda/handler.py b/datadog_lambda/handler.py index f37c8572..c0cbeafd 100644 --- a/datadog_lambda/handler.py +++ b/datadog_lambda/handler.py @@ -9,8 +9,7 @@ import os import time -from datadog_lambda.tracing import emit_telemetry_on_exception_outside_of_handler -from datadog_lambda.wrapper import datadog_lambda_wrapper +from datadog_lambda.wrapper import datadog_lambda_wrapper, error_fallback_handler from datadog_lambda.module_name import modify_module_name @@ -18,27 +17,6 @@ class HandlerError(Exception): pass -class _ErrorFallbackHandler(object): - """ - Decorator for when an exception occurs outside of the handler function. - Emits telemetry and re-raises the exception. - """ - - def __init__(self, exception, modified_mod_name, start_time_ns): - self.exception = exception - self.modified_mod_name = modified_mod_name - self.start_time_ns = start_time_ns - - def __call__(self, event, context, **kwargs): - emit_telemetry_on_exception_outside_of_handler( - context, - self.exception, - self.modified_mod_name, - self.start_time_ns, - ) - raise self.exception - - path = os.environ.get("DD_LAMBDA_HANDLER", None) if path is None: raise HandlerError( @@ -58,4 +36,4 @@ def __call__(self, event, context, **kwargs): handler_func = getattr(handler_module, handler_name) handler = datadog_lambda_wrapper(handler_func) except Exception as e: - handler = _ErrorFallbackHandler(e, modified_mod_name, start_time_ns) + handler = error_fallback_handler(e, modified_mod_name, start_time_ns) diff --git a/datadog_lambda/wrapper.py b/datadog_lambda/wrapper.py index ba31f2be..54685918 100644 --- a/datadog_lambda/wrapper.py +++ b/datadog_lambda/wrapper.py @@ -44,6 +44,7 @@ is_authorizer_response, tracer, propagator, + emit_telemetry_on_exception_outside_of_handler, ) from datadog_lambda.trigger import ( extract_trigger_tags, @@ -382,9 +383,31 @@ def _after(self, event, context): logger.error(format_err_with_traceback(e)) +class _ErrorFallbackHandler(object): + """ + Fallback handler for when an exception occurs outside of the handler function. + Emits telemetry and re-raises the exception. + """ + + def __init__(self, exception, modified_mod_name, start_time_ns): + self.exception = exception + self.modified_mod_name = modified_mod_name + self.start_time_ns = start_time_ns + + def __call__(self, event, context, **kwargs): + emit_telemetry_on_exception_outside_of_handler( + context, + self.exception, + self.modified_mod_name, + self.start_time_ns, + ) + raise self.exception + + def format_err_with_traceback(e): tb = traceback.format_exc().replace("\n", "\r") return f"Error {e}. Traceback: {tb}" datadog_lambda_wrapper = _LambdaDecorator +error_fallback_handler = _ErrorFallbackHandler diff --git a/tests/test_handler.py b/tests/test_handler.py index e8496c28..d8c7b06a 100644 --- a/tests/test_handler.py +++ b/tests/test_handler.py @@ -30,7 +30,7 @@ def test_dd_lambda_handler_env_var_malformed(self): ) @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) - @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") + @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") @patch("time.time_ns", return_value=42) def test_exception_importing_module(self, mock_time, mock_emit_telemetry): with self.assertRaises(ModuleNotFoundError) as test_context: @@ -44,7 +44,7 @@ def test_exception_importing_module(self, mock_time, mock_emit_telemetry): @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) @patch("importlib.import_module", return_value=None) - @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") + @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") @patch("time.time_ns", return_value=42) def test_exception_getting_handler_func( self, mock_time, mock_emit_telemetry, mock_import @@ -60,7 +60,7 @@ def test_exception_getting_handler_func( @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) @patch("importlib.import_module") - @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") + @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") @patch("time.time_ns", return_value=42) @patch("datadog_lambda.wrapper.datadog_lambda_wrapper") def test_handler_success( From 101cfb98693f7ace911fee2023ad7b02a4aff273 Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky Date: Wed, 24 Apr 2024 09:25:13 -0400 Subject: [PATCH 4/7] fix duration --- datadog_lambda/handler.py | 8 +++++--- datadog_lambda/tracing.py | 6 ++++-- datadog_lambda/wrapper.py | 6 +++--- tests/test_handler.py | 7 +++---- tests/test_tracing.py | 5 +++-- 5 files changed, 18 insertions(+), 14 deletions(-) diff --git a/datadog_lambda/handler.py b/datadog_lambda/handler.py index c0cbeafd..cf2af5a0 100644 --- a/datadog_lambda/handler.py +++ b/datadog_lambda/handler.py @@ -7,7 +7,7 @@ from importlib import import_module import os -import time +from time import time_ns from datadog_lambda.wrapper import datadog_lambda_wrapper, error_fallback_handler from datadog_lambda.module_name import modify_module_name @@ -31,9 +31,11 @@ class HandlerError(Exception): modified_mod_name = modify_module_name(mod_name) try: - start_time_ns = time.time_ns() + handler_load_start_time_ns = time_ns() handler_module = import_module(modified_mod_name) handler_func = getattr(handler_module, handler_name) handler = datadog_lambda_wrapper(handler_func) except Exception as e: - handler = error_fallback_handler(e, modified_mod_name, start_time_ns) + handler = error_fallback_handler( + e, modified_mod_name, time_ns() - handler_load_start_time_ns + ) diff --git a/datadog_lambda/tracing.py b/datadog_lambda/tracing.py index 0e074395..883dede2 100644 --- a/datadog_lambda/tracing.py +++ b/datadog_lambda/tracing.py @@ -9,6 +9,7 @@ import traceback import ujson as json from datetime import datetime, timezone +from time import time_ns from typing import Optional, Dict from datadog_lambda.metric import submit_errors_metric @@ -1324,7 +1325,7 @@ def is_async(span: Span) -> bool: def emit_telemetry_on_exception_outside_of_handler( - context, exception, resource_name, start_time_ns + context, exception, resource_name, handler_load_duration ): """ Emit an enhanced error metric and create a span for exceptions occuring outside of the handler @@ -1337,7 +1338,8 @@ def emit_telemetry_on_exception_outside_of_handler( resource=resource_name, span_type="serverless", ) - span.start_ns = start_time_ns + span.start_ns = time_ns() - handler_load_duration + tags = { "error.status": 500, "error.type": type(exception).__name__, diff --git a/datadog_lambda/wrapper.py b/datadog_lambda/wrapper.py index 54685918..da5263a1 100644 --- a/datadog_lambda/wrapper.py +++ b/datadog_lambda/wrapper.py @@ -389,17 +389,17 @@ class _ErrorFallbackHandler(object): Emits telemetry and re-raises the exception. """ - def __init__(self, exception, modified_mod_name, start_time_ns): + def __init__(self, exception, modified_mod_name, handler_load_duration_ns): self.exception = exception self.modified_mod_name = modified_mod_name - self.start_time_ns = start_time_ns + self.handler_load_duration_ns = handler_load_duration_ns def __call__(self, event, context, **kwargs): emit_telemetry_on_exception_outside_of_handler( context, self.exception, self.modified_mod_name, - self.start_time_ns, + self.handler_load_duration_ns, ) raise self.exception diff --git a/tests/test_handler.py b/tests/test_handler.py index d8c7b06a..7066dd06 100644 --- a/tests/test_handler.py +++ b/tests/test_handler.py @@ -39,7 +39,7 @@ def test_exception_importing_module(self, mock_time, mock_emit_telemetry): lambda_context = get_mock_context() datadog_lambda.handler.handler.__call__(None, lambda_context) mock_emit_telemetry.assert_called_once_with( - lambda_context, test_context.exception, "nonsense", 42 + lambda_context, test_context.exception, "nonsense", 0 ) @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) @@ -55,16 +55,15 @@ def test_exception_getting_handler_func( lambda_context = get_mock_context() datadog_lambda.handler.handler.__call__(None, lambda_context) mock_emit_telemetry.assert_called_once_with( - lambda_context, test_context.exception, "nonsense", 42 + lambda_context, test_context.exception, "nonsense", 0 ) @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) @patch("importlib.import_module") @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") - @patch("time.time_ns", return_value=42) @patch("datadog_lambda.wrapper.datadog_lambda_wrapper") def test_handler_success( - self, mock_lambda_wrapper, mock_time, mock_emit_telemetry, mock_import + self, mock_lambda_wrapper, mock_emit_telemetry, mock_import ): def nonsense(): pass diff --git a/tests/test_tracing.py b/tests/test_tracing.py index f81e4941..8f40ed72 100644 --- a/tests/test_tracing.py +++ b/tests/test_tracing.py @@ -2005,7 +2005,8 @@ def test_deterministic_m5_hash__always_leading_with_zero(self): class TestExceptionOutsideHandler(unittest.TestCase): @patch("datadog_lambda.tracing.submit_errors_metric") - def test_exception_outside_handler(self, mock_submit_errors_metric): + @patch("datadog_lambda.tracing.time_ns", return_value=100) + def test_exception_outside_handler(self, mock_time, mock_submit_errors_metric): fake_error = ValueError("Some error message") resource_name = "my_handler" span_type = "aws.lambda" @@ -2045,4 +2046,4 @@ def test_exception_outside_handler(self, mock_submit_errors_metric): ) mock_span.finish.assert_called_once() assert mock_span.error == 1 - assert mock_span.start_ns == 42 + assert mock_span.start_ns == 58 From 63f6812505ba03fc5efbe01efc20ae082f08837b Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky Date: Wed, 24 Apr 2024 13:34:02 -0400 Subject: [PATCH 5/7] respect DD_TRACE_ENABLED --- datadog_lambda/tracing.py | 52 +++++++++++++++++++-------------------- tests/test_tracing.py | 22 ++++++++++++++++- 2 files changed, 47 insertions(+), 27 deletions(-) diff --git a/datadog_lambda/tracing.py b/datadog_lambda/tracing.py index 883dede2..659e3541 100644 --- a/datadog_lambda/tracing.py +++ b/datadog_lambda/tracing.py @@ -1331,30 +1331,30 @@ def emit_telemetry_on_exception_outside_of_handler( Emit an enhanced error metric and create a span for exceptions occuring outside of the handler """ submit_errors_metric(context) + if dd_tracing_enabled: + span = tracer.trace( + "aws.lambda", + service="aws.lambda", + resource=resource_name, + span_type="serverless", + ) + span.start_ns = time_ns() - handler_load_duration - span = tracer.trace( - "aws.lambda", - service="aws.lambda", - resource=resource_name, - span_type="serverless", - ) - span.start_ns = time_ns() - handler_load_duration - - tags = { - "error.status": 500, - "error.type": type(exception).__name__, - "error.message": exception, - "error.stack": "".join( - traceback.format_exception( - type(exception), exception, exception.__traceback__ - ) - ), - "resource_names": resource_name, - "resource.name": resource_name, - "operation_name": "aws.lambda", - "status": "error", - "request_id": context.aws_request_id, - } - span.set_tags(tags) - span.error = 1 - span.finish() + tags = { + "error.status": 500, + "error.type": type(exception).__name__, + "error.message": exception, + "error.stack": "".join( + traceback.format_exception( + type(exception), exception, exception.__traceback__ + ) + ), + "resource_names": resource_name, + "resource.name": resource_name, + "operation_name": "aws.lambda", + "status": "error", + "request_id": context.aws_request_id, + } + span.set_tags(tags) + span.error = 1 + span.finish() diff --git a/tests/test_tracing.py b/tests/test_tracing.py index 8f40ed72..02563a53 100644 --- a/tests/test_tracing.py +++ b/tests/test_tracing.py @@ -2004,9 +2004,12 @@ def test_deterministic_m5_hash__always_leading_with_zero(self): class TestExceptionOutsideHandler(unittest.TestCase): + @patch("datadog_lambda.tracing.dd_tracing_enabled", True) @patch("datadog_lambda.tracing.submit_errors_metric") @patch("datadog_lambda.tracing.time_ns", return_value=100) - def test_exception_outside_handler(self, mock_time, mock_submit_errors_metric): + def test_exception_outside_handler_tracing_enabled( + self, mock_time, mock_submit_errors_metric + ): fake_error = ValueError("Some error message") resource_name = "my_handler" span_type = "aws.lambda" @@ -2047,3 +2050,20 @@ def test_exception_outside_handler(self, mock_time, mock_submit_errors_metric): mock_span.finish.assert_called_once() assert mock_span.error == 1 assert mock_span.start_ns == 58 + + @patch("datadog_lambda.tracing.dd_tracing_enabled", False) + @patch("datadog_lambda.tracing.submit_errors_metric") + @patch("datadog_lambda.tracing.time_ns", return_value=100) + def test_exception_outside_handler_tracing_disabled( + self, mock_time, mock_submit_errors_metric + ): + fake_error = ValueError("Some error message") + resource_name = "my_handler" + context = get_mock_context() + with patch("datadog_lambda.tracing.tracer.trace") as mock_trace: + emit_telemetry_on_exception_outside_of_handler( + context, fake_error, resource_name, 42 + ) + + mock_submit_errors_metric.assert_called_once_with(context) + mock_trace.assert_not_called() From a4e3f09daf2f8678cf4b87a8559f156ca5593d21 Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky Date: Fri, 26 Apr 2024 10:15:52 -0400 Subject: [PATCH 6/7] emit telemetry and raise during init --- datadog_lambda/handler.py | 13 +++++++++---- datadog_lambda/tags.py | 7 +++++-- datadog_lambda/tracing.py | 16 +++++----------- datadog_lambda/wrapper.py | 23 ----------------------- tests/test_handler.py | 17 +++++------------ tests/test_tracing.py | 23 ++++++++--------------- tests/test_wrapper.py | 18 +++++++++--------- 7 files changed, 41 insertions(+), 76 deletions(-) diff --git a/datadog_lambda/handler.py b/datadog_lambda/handler.py index cf2af5a0..433d9b92 100644 --- a/datadog_lambda/handler.py +++ b/datadog_lambda/handler.py @@ -9,7 +9,8 @@ import os from time import time_ns -from datadog_lambda.wrapper import datadog_lambda_wrapper, error_fallback_handler +from datadog_lambda.tracing import emit_telemetry_on_exception_outside_of_handler +from datadog_lambda.wrapper import datadog_lambda_wrapper from datadog_lambda.module_name import modify_module_name @@ -34,8 +35,12 @@ class HandlerError(Exception): handler_load_start_time_ns = time_ns() handler_module = import_module(modified_mod_name) handler_func = getattr(handler_module, handler_name) - handler = datadog_lambda_wrapper(handler_func) except Exception as e: - handler = error_fallback_handler( - e, modified_mod_name, time_ns() - handler_load_start_time_ns + emit_telemetry_on_exception_outside_of_handler( + e, + modified_mod_name, + handler_load_start_time_ns, ) + raise + +handler = datadog_lambda_wrapper(handler_func) diff --git a/datadog_lambda/tags.py b/datadog_lambda/tags.py index 695d1a48..ed4a66be 100644 --- a/datadog_lambda/tags.py +++ b/datadog_lambda/tags.py @@ -55,9 +55,12 @@ def parse_lambda_tags_from_arn(lambda_context): def get_enhanced_metrics_tags(lambda_context): """Get the list of tags to apply to enhanced metrics""" - tags = parse_lambda_tags_from_arn(lambda_context) + if lambda_context: + tags = parse_lambda_tags_from_arn(lambda_context) + tags.append(f"memorysize:{lambda_context.memory_limit_in_mb}") + else: + tags = [] tags.append(get_cold_start_tag()) - tags.append(f"memorysize:{lambda_context.memory_limit_in_mb}") tags.append(runtime_tag) tags.append(library_version_tag) return tags diff --git a/datadog_lambda/tracing.py b/datadog_lambda/tracing.py index 659e3541..60b9e726 100644 --- a/datadog_lambda/tracing.py +++ b/datadog_lambda/tracing.py @@ -9,7 +9,6 @@ import traceback import ujson as json from datetime import datetime, timezone -from time import time_ns from typing import Optional, Dict from datadog_lambda.metric import submit_errors_metric @@ -1325,12 +1324,12 @@ def is_async(span: Span) -> bool: def emit_telemetry_on_exception_outside_of_handler( - context, exception, resource_name, handler_load_duration + exception, resource_name, handler_load_start_time_ns ): """ - Emit an enhanced error metric and create a span for exceptions occuring outside of the handler + Emit an enhanced error metric and create a span for exceptions occurring outside the handler """ - submit_errors_metric(context) + submit_errors_metric(None) if dd_tracing_enabled: span = tracer.trace( "aws.lambda", @@ -1338,22 +1337,17 @@ def emit_telemetry_on_exception_outside_of_handler( resource=resource_name, span_type="serverless", ) - span.start_ns = time_ns() - handler_load_duration + span.start_ns = handler_load_start_time_ns tags = { "error.status": 500, "error.type": type(exception).__name__, "error.message": exception, - "error.stack": "".join( - traceback.format_exception( - type(exception), exception, exception.__traceback__ - ) - ), + "error.stack": traceback.format_exc(), "resource_names": resource_name, "resource.name": resource_name, "operation_name": "aws.lambda", "status": "error", - "request_id": context.aws_request_id, } span.set_tags(tags) span.error = 1 diff --git a/datadog_lambda/wrapper.py b/datadog_lambda/wrapper.py index da5263a1..ba31f2be 100644 --- a/datadog_lambda/wrapper.py +++ b/datadog_lambda/wrapper.py @@ -44,7 +44,6 @@ is_authorizer_response, tracer, propagator, - emit_telemetry_on_exception_outside_of_handler, ) from datadog_lambda.trigger import ( extract_trigger_tags, @@ -383,31 +382,9 @@ def _after(self, event, context): logger.error(format_err_with_traceback(e)) -class _ErrorFallbackHandler(object): - """ - Fallback handler for when an exception occurs outside of the handler function. - Emits telemetry and re-raises the exception. - """ - - def __init__(self, exception, modified_mod_name, handler_load_duration_ns): - self.exception = exception - self.modified_mod_name = modified_mod_name - self.handler_load_duration_ns = handler_load_duration_ns - - def __call__(self, event, context, **kwargs): - emit_telemetry_on_exception_outside_of_handler( - context, - self.exception, - self.modified_mod_name, - self.handler_load_duration_ns, - ) - raise self.exception - - def format_err_with_traceback(e): tb = traceback.format_exc().replace("\n", "\r") return f"Error {e}. Traceback: {tb}" datadog_lambda_wrapper = _LambdaDecorator -error_fallback_handler = _ErrorFallbackHandler diff --git a/tests/test_handler.py b/tests/test_handler.py index 7066dd06..50f426dc 100644 --- a/tests/test_handler.py +++ b/tests/test_handler.py @@ -30,21 +30,19 @@ def test_dd_lambda_handler_env_var_malformed(self): ) @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) - @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") + @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") @patch("time.time_ns", return_value=42) def test_exception_importing_module(self, mock_time, mock_emit_telemetry): with self.assertRaises(ModuleNotFoundError) as test_context: import datadog_lambda.handler - lambda_context = get_mock_context() - datadog_lambda.handler.handler.__call__(None, lambda_context) mock_emit_telemetry.assert_called_once_with( - lambda_context, test_context.exception, "nonsense", 0 + test_context.exception, "nonsense", 42 ) @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) @patch("importlib.import_module", return_value=None) - @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") + @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") @patch("time.time_ns", return_value=42) def test_exception_getting_handler_func( self, mock_time, mock_emit_telemetry, mock_import @@ -52,15 +50,13 @@ def test_exception_getting_handler_func( with self.assertRaises(AttributeError) as test_context: import datadog_lambda.handler - lambda_context = get_mock_context() - datadog_lambda.handler.handler.__call__(None, lambda_context) mock_emit_telemetry.assert_called_once_with( - lambda_context, test_context.exception, "nonsense", 0 + test_context.exception, "nonsense", 42 ) @patch.dict(os.environ, {"DD_LAMBDA_HANDLER": "nonsense.nonsense"}, clear=True) @patch("importlib.import_module") - @patch("datadog_lambda.wrapper.emit_telemetry_on_exception_outside_of_handler") + @patch("datadog_lambda.tracing.emit_telemetry_on_exception_outside_of_handler") @patch("datadog_lambda.wrapper.datadog_lambda_wrapper") def test_handler_success( self, mock_lambda_wrapper, mock_emit_telemetry, mock_import @@ -72,8 +68,5 @@ def nonsense(): import datadog_lambda.handler - lambda_context = get_mock_context() - datadog_lambda.handler.handler.__call__(None, lambda_context) - mock_emit_telemetry.assert_not_called() mock_lambda_wrapper.assert_called_once_with(mock_import().nonsense) diff --git a/tests/test_tracing.py b/tests/test_tracing.py index 02563a53..9629dcab 100644 --- a/tests/test_tracing.py +++ b/tests/test_tracing.py @@ -2006,7 +2006,7 @@ def test_deterministic_m5_hash__always_leading_with_zero(self): class TestExceptionOutsideHandler(unittest.TestCase): @patch("datadog_lambda.tracing.dd_tracing_enabled", True) @patch("datadog_lambda.tracing.submit_errors_metric") - @patch("datadog_lambda.tracing.time_ns", return_value=100) + @patch("time.time_ns", return_value=42) def test_exception_outside_handler_tracing_enabled( self, mock_time, mock_submit_errors_metric ): @@ -2014,15 +2014,14 @@ def test_exception_outside_handler_tracing_enabled( resource_name = "my_handler" span_type = "aws.lambda" mock_span = Mock() - context = get_mock_context() with patch( "datadog_lambda.tracing.tracer.trace", return_value=mock_span ) as mock_trace: emit_telemetry_on_exception_outside_of_handler( - context, fake_error, resource_name, 42 + fake_error, resource_name, 42 ) - mock_submit_errors_metric.assert_called_once_with(context) + mock_submit_errors_metric.assert_called_once_with(None) mock_trace.assert_called_once_with( span_type, @@ -2035,35 +2034,29 @@ def test_exception_outside_handler_tracing_enabled( "error.status": 500, "error.type": "ValueError", "error.message": fake_error, - "error.stack": "".join( - traceback.format_exception( - type(fake_error), fake_error, fake_error.__traceback__ - ) - ), + "error.stack": traceback.format_exc(), "resource_names": resource_name, "resource.name": resource_name, "operation_name": span_type, "status": "error", - "request_id": context.aws_request_id, } ) mock_span.finish.assert_called_once() assert mock_span.error == 1 - assert mock_span.start_ns == 58 + assert mock_span.start_ns == 42 @patch("datadog_lambda.tracing.dd_tracing_enabled", False) @patch("datadog_lambda.tracing.submit_errors_metric") - @patch("datadog_lambda.tracing.time_ns", return_value=100) + @patch("time.time_ns", return_value=42) def test_exception_outside_handler_tracing_disabled( self, mock_time, mock_submit_errors_metric ): fake_error = ValueError("Some error message") resource_name = "my_handler" - context = get_mock_context() with patch("datadog_lambda.tracing.tracer.trace") as mock_trace: emit_telemetry_on_exception_outside_of_handler( - context, fake_error, resource_name, 42 + fake_error, resource_name, 42 ) - mock_submit_errors_metric.assert_called_once_with(context) + mock_submit_errors_metric.assert_called_once_with(None) mock_trace.assert_not_called() diff --git a/tests/test_wrapper.py b/tests/test_wrapper.py index 13fef2b6..db9f0f9e 100644 --- a/tests/test_wrapper.py +++ b/tests/test_wrapper.py @@ -220,8 +220,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -251,8 +251,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -267,8 +267,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -306,8 +306,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -322,8 +322,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -358,8 +358,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -374,8 +374,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test", - "cold_start:false", "memorysize:256", + "cold_start:false", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -408,8 +408,8 @@ def lambda_handler(event, context): "account_id:123457598159", "functionname:python-layer-test", "resource:python-layer-test:Latest", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", @@ -442,8 +442,8 @@ def lambda_handler(event, context): "functionname:python-layer-test", "executedversion:1", "resource:python-layer-test:My_alias-1", - "cold_start:true", "memorysize:256", + "cold_start:true", "runtime:python3.9", "datadog_lambda:v6.6.6", "dd_lambda_layer:datadog-python39_X.X.X", From 7c5aa58108b7815957264554ba8de2c4e41634c4 Mon Sep 17 00:00:00 2001 From: Tal Usvyatsky <18072279+TalUsvyatsky@users.noreply.github.com> Date: Mon, 29 Apr 2024 14:10:23 -0400 Subject: [PATCH 7/7] Update datadog_lambda/tags.py MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: jordan gonzález <30836115+duncanista@users.noreply.github.com> --- datadog_lambda/tags.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/datadog_lambda/tags.py b/datadog_lambda/tags.py index ed4a66be..5b3fe43e 100644 --- a/datadog_lambda/tags.py +++ b/datadog_lambda/tags.py @@ -55,11 +55,10 @@ def parse_lambda_tags_from_arn(lambda_context): def get_enhanced_metrics_tags(lambda_context): """Get the list of tags to apply to enhanced metrics""" + tags = [] if lambda_context: tags = parse_lambda_tags_from_arn(lambda_context) tags.append(f"memorysize:{lambda_context.memory_limit_in_mb}") - else: - tags = [] tags.append(get_cold_start_tag()) tags.append(runtime_tag) tags.append(library_version_tag)