fix(logger): stop adding milliseconds twice when use_datetime_directive is set (#8632)

Signed-off-by: Sebastian Turner <sebastiant3484@gmail.com>

Author: sebxt

aws_lambda_powertools/logging/formatter.py

@@ -237,13 +237,11 @@ def formatTime(self, record: logging.LogRecord, datefmt: str | None = None) -> s
         # by default, those migrating from std logging will use time format codes
         # https://docs.python.org/3/library/datetime.html#strftime-and-strptime-format-codes
         if self.use_datetime_directive and datefmt:
-            # record.msecs are microseconds, divide by 1000 to get milliseconds
-            timestamp = record.created + record.msecs / 1000
-
+            # record.created already carries the sub-second part, so it is used as is
             if self.utc:
-                dt = datetime.fromtimestamp(timestamp, tz=timezone.utc)
+                dt = datetime.fromtimestamp(record.created, tz=timezone.utc)
             else:
-                dt = datetime.fromtimestamp(timestamp).astimezone()
+                dt = datetime.fromtimestamp(record.created).astimezone()
 
             custom_fmt = datefmt.replace(self.custom_ms_time_directive, msecs)
             return dt.strftime(custom_fmt)

tests/functional/logger/required_dependencies/test_logger.py

@@ -1084,6 +1084,24 @@ def test_use_datetime(stdout, service_name, utc):
     )
 
 
+@pytest.mark.parametrize("utc", [False, True])
+def test_use_datetime_does_not_shift_timestamp(utc):
+    # GIVEN a formatter using datetime directives
+    formatter = LambdaPowertoolsFormatter(datefmt="%Y-%m-%d %H:%M:%S.%F|%f", use_datetime_directive=True, utc=utc)
+
+    # AND a log record created 750 milliseconds after a full second
+    record = logging.LogRecord("test", logging.INFO, __file__, 1, "message", None, None)
+    record.created = 1700000000.75
+    record.msecs = 750.0
+
+    # WHEN the timestamp is formatted
+    timestamp = formatter.formatTime(record, formatter.datefmt)
+
+    # THEN it matches the time the record was created
+    expected = datetime.fromtimestamp(record.created, tz=timezone.utc if utc else None)
+    assert timestamp == expected.strftime("%Y-%m-%d %H:%M:%S.750|%f")
+
+
 @pytest.mark.parametrize("utc", [False, True])
 def test_use_rfc3339_iso8601(stdout, service_name, utc):
     # GIVEN