Skip to content

Commit 5997da5

Browse files
authored
fix(logger): force Logger to use local timezone when UTC flag is not set (#3168)
1 parent 141750e commit 5997da5

27 files changed

+337
-209
lines changed

aws_lambda_powertools/logging/formatter.py

+2
Original file line numberDiff line numberDiff line change
@@ -146,6 +146,8 @@ def __init__(
146146

147147
if self.utc:
148148
self.converter = time.gmtime
149+
else:
150+
self.converter = time.localtime
149151

150152
self.keys_combined = {**self._build_default_keys(), **kwargs}
151153
self.log_format.update(**self.keys_combined)

docs/core/logger.md

+19-9
Original file line numberDiff line numberDiff line change
@@ -39,7 +39,7 @@ Your Logger will include the following keys to your structured logging:
3939
| **level**: `str` | `INFO` | Logging level |
4040
| **location**: `str` | `collect.handler:1` | Source code location where statement was executed |
4141
| **message**: `Any` | `Collecting payment` | Unserializable JSON values are casted as `str` |
42-
| **timestamp**: `str` | `2021-05-03 10:20:19,650+0200` | Timestamp with milliseconds, by default uses local timezone |
42+
| **timestamp**: `str` | `2021-05-03 10:20:19,650+0000` | Timestamp with milliseconds, by default uses default AWS Lambda timezone (UTC) |
4343
| **service**: `str` | `payment` | Service name defined, by default `service_undefined` |
4444
| **xray_trace_id**: `str` | `1-5759e988-bd862e3fe1be46a994272793` | When [tracing is enabled](https://docs.aws.amazon.com/lambda/latest/dg/services-xray.html){target="_blank"}, it shows X-Ray Trace ID |
4545
| **sampling_rate**: `float` | `0.1` | When enabled, it shows sampling rate in percentage e.g. 10% |
@@ -337,12 +337,12 @@ By default, the Logger will automatically include the full stack trace in JSON f
337337

338338
### Date formatting
339339

340-
Logger uses Python's standard logging date format with the addition of timezone: `2021-05-03 11:47:12,494+0200`.
340+
Logger uses Python's standard logging date format with the addition of timezone: `2021-05-03 11:47:12,494+0000`.
341341

342342
You can easily change the date format using one of the following parameters:
343343

344344
* **`datefmt`**. You can pass any [strftime format codes](https://strftime.org/){target="_blank" rel="nofollow"}. Use `%F` if you need milliseconds.
345-
* **`use_rfc3339`**. This flag will use a format compliant with both RFC3339 and ISO8601: `2022-10-27T16:27:43.738+02:00`
345+
* **`use_rfc3339`**. This flag will use a format compliant with both RFC3339 and ISO8601: `2022-10-27T16:27:43.738+00:00`
346346

347347
???+ tip "Prefer using [datetime string formats](https://docs.python.org/3/library/datetime.html#strftime-and-strptime-format-codes){target="_blank" rel="nofollow"}?"
348348
Use `use_datetime_directive` flag along with `datefmt` to instruct Logger to use `datetime` instead of `time.strftime`.
@@ -368,6 +368,7 @@ The following environment variables are available to configure Logger at a globa
368368
| **Event Logging** | Whether to log the incoming event. | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` |
369369
| **Debug Sample Rate** | Sets the debug log sampling. | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` |
370370
| **Disable Deduplication** | Disables log deduplication filter protection to use Pytest Live Log feature. | `POWERTOOLS_LOG_DEDUPLICATION_DISABLED` | `false` |
371+
| **TZ** | Sets timezone when using Logger, e.g., `US/Eastern`. Timezone is defaulted to UTC when `TZ` is not set | `TZ` | `None` (UTC) |
371372

372373
[`POWERTOOLS_LOGGER_LOG_EVENT`](#logging-incoming-event) can also be set on a per-method basis, and [`POWERTOOLS_LOGGER_SAMPLE_RATE`](#sampling-debug-logs) on a per-instance basis. These parameter values will override the environment variable value.
373374

@@ -464,7 +465,7 @@ If you prefer configuring it separately, or you'd want to bring this JSON Format
464465
| **`json_default`** | function to coerce unserializable values, when no custom serializer/deserializer is set | `str` |
465466
| **`datefmt`** | string directives (strftime) to format log timestamp | `%Y-%m-%d %H:%M:%S,%F%z`, where `%F` is a custom ms directive |
466467
| **`use_datetime_directive`** | format the `datefmt` timestamps using `datetime`, not `time` (also supports the custom `%F` directive for milliseconds) | `False` |
467-
| **`utc`** | set logging timestamp to UTC | `False` |
468+
| **`utc`** | enforce logging timestamp to UTC (ignore `TZ` environment variable) | `False` |
468469
| **`log_record_order`** | set order of log keys when logging | `["level", "location", "message", "timestamp"]` |
469470
| **`kwargs`** | key-value to be included in log messages | `None` |
470471

@@ -583,17 +584,26 @@ You can change the order of [standard Logger keys](#standard-structured-keys) or
583584
--8<-- "examples/logger/src/reordering_log_keys_output.json"
584585
```
585586

586-
#### Setting timestamp to UTC
587+
#### Setting timestamp to custom Timezone
587588

588-
By default, this Logger and standard logging library emits records using local time timestamp. You can override this behavior via `utc` parameter:
589+
By default, this Logger and the standard logging library emit records with the default AWS Lambda timestamp in **UTC**.
589590

590-
=== "setting_utc_timestamp.py"
591+
<!-- markdownlint-disable MD013 -->
592+
If you prefer to log in a specific timezone, you can configure it by setting the `TZ` environment variable. You can do this either as an AWS Lambda environment variable or directly within your Lambda function settings. [Click here](https://docs.aws.amazon.com/lambda/latest/dg/configuration-envvars.html#configuration-envvars-runtime){target="_blank"} for a comprehensive list of available Lambda environment variables.
593+
<!-- markdownlint-enable MD013 -->
594+
595+
???+ tip
596+
`TZ` environment variable will be ignored if `utc` is set to `True`
591597

592-
```python hl_lines="6"
598+
=== "setting_custom_timezone.py"
599+
600+
```python hl_lines="9 12"
593601
--8<-- "examples/logger/src/setting_utc_timestamp.py"
594602
```
595603

596-
=== "setting_utc_timestamp_output.json"
604+
1. if you set TZ in your Lambda function, `time.tzset()` need to be called. You don't need it when setting TZ in AWS Lambda environment variable
605+
606+
=== "setting_custom_timezone_output.json"
597607

598608
```json hl_lines="6 13"
599609
--8<-- "examples/logger/src/setting_utc_timestamp_output.json"

examples/logger/src/append_keys_extra_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:9",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"request_id": "1123"
88
}

examples/logger/src/append_keys_kwargs_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:8",
44
"message": "Collecting payment",
5-
"timestamp": "2022-11-26 11:47:12,494+0200",
5+
"timestamp": "2022-11-26 11:47:12,494+0000",
66
"service": "payment",
77
"request_id": "1123"
88
}

examples/logger/src/append_keys_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:11",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"order_id": "order_id_value"
88
}
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
{
22
"level": "INFO",
33
"location": "<module>:16",
4-
"timestamp": "2021-12-30 13:41:53,413+0100",
4+
"timestamp": "2021-12-30 13:41:53,413+0000",
55
"service": "payment",
66
"event": "hello"
77
}

examples/logger/src/clear_state_event_one.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:10",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"special_key": "debug_key",
88
"cold_start": true,

examples/logger/src/clear_state_event_two.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:10",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"cold_start": false,
88
"function_name": "test",

examples/logger/src/date_formatting_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
"level": "INFO",
44
"location": "<module>:6",
55
"message": "Collecting payment",
6-
"timestamp": "2022-10-28T14:35:03.210+02:00",
6+
"timestamp": "2022-10-28T14:35:03.210+00:00",
77
"service": "payment"
88
},
99
{

examples/logger/src/inject_lambda_context_output.json

+2-2
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
"level": "INFO",
44
"location": "collect.handler:9",
55
"message": "Collecting payment",
6-
"timestamp": "2021-05-03 11:47:12,494+0200",
6+
"timestamp": "2021-05-03 11:47:12,494+0000",
77
"service": "payment",
88
"cold_start": true,
99
"function_name": "test",
@@ -18,7 +18,7 @@
1818
"operation": "collect_payment",
1919
"charge_id": "ch_AZFlk2345C0"
2020
},
21-
"timestamp": "2021-05-03 11:47:12,494+0200",
21+
"timestamp": "2021-05-03 11:47:12,494+0000",
2222
"service": "payment",
2323
"cold_start": true,
2424
"function_name": "test",

examples/logger/src/logger_reuse_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:12",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"cold_start": true,
88
"function_name": "test",

examples/logger/src/logging_exceptions_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "ERROR",
33
"location": "collect.handler:15",
44
"message": "Received a HTTP 5xx error",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"exception_name": "RuntimeError",
88
"exception": "Traceback (most recent call last):\n File \"<input>\", line 2, in <module> RuntimeError: Unable to fullfil request"

examples/logger/src/logging_uncaught_exceptions_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "ERROR",
33
"location": "log_uncaught_exception_hook:756",
44
"message": "500 Server Error: INTERNAL SERVER ERROR for url: http://httpbin.org/status/500",
5-
"timestamp": "2022-11-16 13:51:29,198+0100",
5+
"timestamp": "2022-11-16 13:51:29,198+0000",
66
"service": "payment",
77
"exception": "Traceback (most recent call last):\n File \"<input>\", line 52, in <module>\n handler({}, {})\n File \"<input>\", line 17, in handler\n ret.raise_for_status()\n File \"<input>/lib/python3.9/site-packages/requests/models.py\", line 1021, in raise_for_status\n raise HTTPError(http_error_msg, response=self)\nrequests.exceptions.HTTPError: 500 Server Error: INTERNAL SERVER ERROR for url: http://httpbin.org/status/500",
88
"exception_name": "HTTPError"

examples/logger/src/overriding_log_records_output.json

+2-2
Original file line numberDiff line numberDiff line change
@@ -3,13 +3,13 @@
33
"level": "INFO",
44
"location": "[<module>] overriding_log_records",
55
"message": "Collecting payment",
6-
"timestamp": "2022-10-28 14:40:43,801+0200",
6+
"timestamp": "2022-10-28 14:40:43,801+0000",
77
"service": "payment"
88
},
99
{
1010
"level": "INFO",
1111
"message": "Calculating points",
12-
"timestamp": "2022-10-28 14:40:43,801+0200",
12+
"timestamp": "2022-10-28 14:40:43,801+0000",
1313
"service": "loyalty"
1414
}
1515
]

examples/logger/src/remove_keys_output.json

+2-2
Original file line numberDiff line numberDiff line change
@@ -3,15 +3,15 @@
33
"level": "INFO",
44
"location": "collect.handler:9",
55
"message": "Collecting payment",
6-
"timestamp": "2021-05-03 11:47:12,494+0200",
6+
"timestamp": "2021-05-03 11:47:12,494+0000",
77
"service": "payment",
88
"sample_key": "value"
99
},
1010
{
1111
"level": "INFO",
1212
"location": "collect.handler:12",
1313
"message": "Collecting payment without sample key",
14-
"timestamp": "2021-05-03 11:47:12,494+0200",
14+
"timestamp": "2021-05-03 11:47:12,494+0000",
1515
"service": "payment"
1616
}
1717
]

examples/logger/src/reordering_log_keys_output.json

+2-2
Original file line numberDiff line numberDiff line change
@@ -3,14 +3,14 @@
33
"message": "hello world",
44
"level": "INFO",
55
"location": "<module>:11",
6-
"timestamp": "2022-06-24 11:25:40,143+0200",
6+
"timestamp": "2022-06-24 11:25:40,143+0000",
77
"service": "payment"
88
},
99
{
1010
"request_id": "123",
1111
"level": "INFO",
1212
"location": "<module>:12",
13-
"timestamp": "2022-06-24 11:25:40,144+0200",
13+
"timestamp": "2022-06-24 11:25:40,144+0000",
1414
"service": "order",
1515
"message": "hello universe"
1616
}

examples/logger/src/sampling_debug_logs_output.json

+2-2
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
"level": "DEBUG",
44
"location": "collect.handler:7",
55
"message": "Verifying whether order_id is present",
6-
"timestamp": "2021-05-03 11:47:12,494+0200",
6+
"timestamp": "2021-05-03 11:47:12,494+0000",
77
"service": "payment",
88
"cold_start": true,
99
"function_name": "test",
@@ -16,7 +16,7 @@
1616
"level": "INFO",
1717
"location": "collect.handler:7",
1818
"message": "Collecting payment",
19-
"timestamp": "2021-05-03 11:47:12,494+0200",
19+
"timestamp": "2021-05-03 11:47:12,494+0000",
2020
"service": "payment",
2121
"cold_start": true,
2222
"function_name": "test",

examples/logger/src/set_correlation_id_jmespath_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:11",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"cold_start": true,
88
"function_name": "test",

examples/logger/src/set_correlation_id_method_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:13",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"correlation_id": "correlation_id_value"
88
}

examples/logger/src/set_correlation_id_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"level": "INFO",
33
"location": "collect.handler:10",
44
"message": "Collecting payment",
5-
"timestamp": "2021-05-03 11:47:12,494+0200",
5+
"timestamp": "2021-05-03 11:47:12,494+0000",
66
"service": "payment",
77
"cold_start": true,
88
"function_name": "test",
+10-4
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,13 @@
1+
import os
2+
import time
3+
14
from aws_lambda_powertools import Logger
25

3-
logger = Logger(service="payment")
4-
logger.info("Local time")
6+
logger_in_utc = Logger(service="payment")
7+
logger_in_utc.info("Logging with default AWS Lambda timezone: UTC time")
8+
9+
os.environ["TZ"] = "US/Eastern"
10+
time.tzset() # (1)!
511

6-
logger_in_utc = Logger(service="order", utc=True)
7-
logger_in_utc.info("GMT time zone")
12+
logger = Logger(service="order")
13+
logger.info("Logging with US Eastern timezone")
Original file line numberDiff line numberDiff line change
@@ -1,16 +1,16 @@
11
[
22
{
3-
"level": "INFO",
4-
"location": "<module>:4",
5-
"message": "Local time",
6-
"timestamp": "2022-06-24 11:39:49,421+0200",
7-
"service": "payment"
3+
"level":"INFO",
4+
"location":"<module>:7",
5+
"message":"Logging with default AWS Lambda timezone: UTC time",
6+
"timestamp":"2023-10-09 21:33:55,733+0000",
7+
"service":"payment"
88
},
99
{
10-
"level": "INFO",
11-
"location": "<module>:7",
12-
"message": "GMT time zone",
13-
"timestamp": "2022-06-24 09:39:49,421+0100",
14-
"service": "order"
10+
"level":"INFO",
11+
"location":"<module>:13",
12+
"message":"Logging with US Eastern timezone",
13+
"timestamp":"2023-10-09 17:33:55,734-0400",
14+
"service":"order"
1515
}
1616
]

examples/logger/src/unserializable_values_output.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,6 @@
55
"ingestion_time": "2022-06-24T10:12:09.526365",
66
"serialize_me": "<non-serializable: Unserializable>"
77
},
8-
"timestamp": "2022-06-24 12:12:09,526+0200",
8+
"timestamp": "2022-06-24 12:12:09,526+0000",
99
"service": "payment"
1010
}

0 commit comments

Comments
 (0)