diff --git a/awslambdaric/lambda_runtime_log_utils.py b/awslambdaric/lambda_runtime_log_utils.py index 9ddbcfb..b684da2 100644 --- a/awslambdaric/lambda_runtime_log_utils.py +++ b/awslambdaric/lambda_runtime_log_utils.py @@ -1,13 +1,15 @@ """ -Copyright 2023 Amazon.com, Inc. or its affiliates. All Rights Reserved. +Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. +SPDX-License-Identifier: Apache-2.0 """ import json import logging import traceback +from datetime import datetime, timezone from enum import IntEnum -_DATETIME_FORMAT = "%Y-%m-%dT%H:%M:%SZ" +_DATETIME_FORMAT = "%Y-%m-%dT%H:%M:%S" _RESERVED_FIELDS = { "name", "msg", @@ -80,6 +82,10 @@ class JsonFormatter(logging.Formatter): def __init__(self): super().__init__(datefmt=_DATETIME_FORMAT) + def formatTime(self, record, datefmt=None): + dt = datetime.fromtimestamp(record.created, tz=timezone.utc) + return dt.strftime(_DATETIME_FORMAT + ".%f")[:-3] + "Z" + @staticmethod def __format_stacktrace(exc_info): if not exc_info: diff --git a/tests/test_bootstrap.py b/tests/test_bootstrap.py index 1eb2bb0..4420300 100644 --- a/tests/test_bootstrap.py +++ b/tests/test_bootstrap.py @@ -1,5 +1,6 @@ """ -Copyright 2019 Amazon.com, Inc. or its affiliates. All Rights Reserved. +Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. +SPDX-License-Identifier: Apache-2.0 """ import importlib @@ -1250,7 +1251,7 @@ def tearDownClass(cls): def test_handler_setup(self, *_): test_cases = [ (62, 0xA55A0003, 46, {}), - (133, 0xA55A001A, 117, {"AWS_LAMBDA_LOG_FORMAT": "JSON"}), + (137, 0xA55A001A, 121, {"AWS_LAMBDA_LOG_FORMAT": "JSON"}), (62, 0xA55A001B, 46, {"AWS_LAMBDA_LOG_LEVEL": "INFO"}), ] diff --git a/tests/test_lambda_runtime_log_utils.py b/tests/test_lambda_runtime_log_utils.py new file mode 100644 index 0000000..90b880b --- /dev/null +++ b/tests/test_lambda_runtime_log_utils.py @@ -0,0 +1,102 @@ +""" +Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. +SPDX-License-Identifier: Apache-2.0 +""" + +import logging +import json +import re +import time +import unittest + +from awslambdaric.lambda_runtime_log_utils import JsonFormatter + + +class TestJsonFormatterTimestamp(unittest.TestCase): + def setUp(self): + self.formatter = JsonFormatter() + self.logger = logging.getLogger("test") + self.logger.setLevel(logging.INFO) + + def test_timestamp_includes_milliseconds(self): + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="test.py", + lineno=1, + msg="hello", + args=None, + exc_info=None, + ) + output = self.formatter.format(record) + log_entry = json.loads(output) + timestamp = log_entry["timestamp"] + + pattern = r"^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z$" + self.assertRegex( + timestamp, + pattern, + f"Timestamp '{timestamp}' does not match expected format YYYY-MM-DDTHH:MM:SS.mmmZ", + ) + + def test_timestamp_milliseconds_are_accurate(self): + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="test.py", + lineno=1, + msg="hello", + args=None, + exc_info=None, + ) + record.created = 1718838785.068 + output = self.formatter.format(record) + log_entry = json.loads(output) + + self.assertEqual(log_entry["timestamp"], "2024-06-19T23:13:05.068Z") + + def test_timestamp_zero_milliseconds(self): + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="test.py", + lineno=1, + msg="hello", + args=None, + exc_info=None, + ) + record.created = 1718838785.0 + output = self.formatter.format(record) + log_entry = json.loads(output) + + self.assertEqual(log_entry["timestamp"], "2024-06-19T23:13:05.000Z") + + def test_timestamps_differ_within_same_second(self): + record1 = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="test.py", + lineno=1, + msg="first", + args=None, + exc_info=None, + ) + record1.created = 1718838785.100 + + record2 = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="test.py", + lineno=1, + msg="second", + args=None, + exc_info=None, + ) + record2.created = 1718838785.200 + + output1 = json.loads(self.formatter.format(record1)) + output2 = json.loads(self.formatter.format(record2)) + + self.assertNotEqual(output1["timestamp"], output2["timestamp"]) + self.assertEqual(output1["timestamp"], "2024-06-19T23:13:05.100Z") + self.assertEqual(output2["timestamp"], "2024-06-19T23:13:05.200Z")