Skip to content

feat(logger): time zone aware timestamp in Logger #2710

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
21 commits
Select commit Hold shift + click to select a range
bdc225a
feat: format timestamp with timezone offset
arnabrahman Jun 9, 2024
d6f6a28
test: formatTimestamp with different timezone
arnabrahman Jun 20, 2024
c8d1899
Merge branch 'main' into 1774-logger-timezone-aware-timestamp
arnabrahman Jun 20, 2024
2238370
feat: get timezone from `envVarsService` during formatting
arnabrahman Jun 23, 2024
ae74643
fix: formatTimestamp tests when `envVarsService` is present
arnabrahman Jun 23, 2024
35da8d5
feat: formatTimestamp tests when `envVarsService` is not present
arnabrahman Jun 23, 2024
c1d0c61
fix: update comparison as default `TZ` value is `:UTC`
arnabrahman Jun 23, 2024
fc0cb73
docs: custom timezone section with examples
arnabrahman Jun 23, 2024
0903e5a
doc: fix the special note
arnabrahman Jun 29, 2024
020e5d8
test: group the test cases close the each other
arnabrahman Jun 29, 2024
8eeb735
Merge branch 'main' into 1774-logger-timezone-aware-timestamp
dreamorosi Jul 1, 2024
8d03e87
Update docs/core/logger.md
dreamorosi Jul 1, 2024
8b29c00
Update docs/core/logger.md
arnabrahman Jul 2, 2024
b92db99
Update docs/core/logger.md
arnabrahman Jul 2, 2024
b58d58c
Update docs/core/logger.md
arnabrahman Jul 2, 2024
51bf3d7
Update docs/core/logger.md
arnabrahman Jul 2, 2024
4e633ac
Update examples/snippets/logger/customTimezone.ts
arnabrahman Jul 2, 2024
ed60848
Update examples/snippets/logger/customTimezoneOutput.json
arnabrahman Jul 2, 2024
1fb398e
Update docs/core/logger.md
arnabrahman Jul 2, 2024
2997dd1
Merge branch 'main' into 1774-logger-timezone-aware-timestamp
dreamorosi Jul 2, 2024
47c813f
Merge branch 'main' into 1774-logger-timezone-aware-timestamp
dreamorosi Jul 3, 2024
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
20 changes: 20 additions & 0 deletions docs/core/logger.md
Original file line number Diff line number Diff line change
Expand Up @@ -519,6 +519,26 @@ We prioritise log level settings in this order:

In the event you have set a log level in Powertools to a level that is lower than the ACL setting, we will output a warning log message informing you that your messages will be discarded by Lambda.

### Setting timestamp to custom Timezone

By default, Logger emits records with the default Lambda timestamp in **UTC**, i.e. `2016-06-20T12:08:10.000Z`

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 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.

=== "customTimezone.ts"

```typescript hl_lines="8"
--8<-- "examples/snippets/logger/customTimezone.ts"
```

=== "customTimezoneOutput.json"

```json hl_lines="7 15"
--8<-- "examples/snippets/logger/customTimezoneOutput.json"
```

### Using multiple Logger instances across your code

The `createChild` method allows you to create a child instance of the Logger, which inherits all of the attributes from its parent. You have the option to override any of the settings and attributes from the parent logger, including [its settings](#utility-settings), any [extra keys](#appending-additional-keys), and [the log formatter](#custom-log-formatter-bring-your-own-formatter).
Expand Down
13 changes: 13 additions & 0 deletions examples/snippets/logger/customTimezone.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
import { Logger } from '@aws-lambda-powertools/logger';

const logger = new Logger({ serviceName: 'serverlessAirline' });

export const handler = async (): Promise<void> => {
logger.info('Hello, World!');

process.env.TZ = 'Europe/Rome';

const childLogger = logger.createChild();

childLogger.info('Ciao, Mondo!');
};
18 changes: 18 additions & 0 deletions examples/snippets/logger/customTimezoneOutput.json
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
[
{
"level": "INFO",
"message": "Hello, World!",
"sampling_rate": 0,
"service": "serverlessAirline",
"timestamp": "2024-07-01T11:00:37.886Z",
"xray_trace_id": "1-66828c55-2bb635c65eb609c820ebe7bc"
},
{
"level": "INFO",
"message": "Ciao, Mondo!",
"sampling_rate": 0,
"service": "serverlessAirline",
"timestamp": "2024-07-01T13:00:37.934+02:00",
"xray_trace_id": "1-66828c55-2bb635c65eb609c820ebe7bc"
}
]
69 changes: 68 additions & 1 deletion packages/logger/src/formatter/LogFormatter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -57,12 +57,24 @@ abstract class LogFormatter implements LogFormatterInterface {
}

/**
* It formats a date into a string in simplified extended ISO format (ISO 8601).
* Formats a given date into an ISO 8601 string, considering the configured timezone.
* If `envVarsService` is set and the configured timezone differs from 'UTC',
* the date is formatted to that timezone. Otherwise, it defaults to 'UTC'.
*
* @param {Date} now
* @returns {string}
*/
public formatTimestamp(now: Date): string {
const defaultTimezone = 'UTC';

/**
* If a specific timezone is configured and it's not the default `UTC`,
* format the timestamp with the appropriate timezone offset.
**/
const configuredTimezone = this.envVarsService?.getTimezone();
if (configuredTimezone && !configuredTimezone.includes(defaultTimezone))
return this.#generateISOTimestampWithOffset(now, configuredTimezone);

return now.toISOString();
}

Expand Down Expand Up @@ -91,6 +103,61 @@ abstract class LogFormatter implements LogFormatterInterface {

return '';
}

/**
* Generates a new Intl.DateTimeFormat object configured with the specified time zone
* and formatting options. The time is displayed in 24-hour format (hour12: false).
*
* @param {string} timeZone - the IANA time zone identifier (e.g., "Asia/Dhaka").
*/
#getDateFormatter = (timeZone: string): Intl.DateTimeFormat => {
const twoDigitFormatOption = '2-digit';

return new Intl.DateTimeFormat('en', {
year: 'numeric',
month: twoDigitFormatOption,
day: twoDigitFormatOption,
hour: twoDigitFormatOption,
minute: twoDigitFormatOption,
second: twoDigitFormatOption,
hour12: false,
timeZone,
});
};

/**
* Generates an ISO 8601 timestamp string with the specified time zone and the local time zone offset.
*
* @param {Date} date - the date to format
* @param {string} timeZone - the IANA time zone identifier (e.g., "Asia/Dhaka").
*/
#generateISOTimestampWithOffset(date: Date, timeZone: string): string {
const { year, month, day, hour, minute, second } = this.#getDateFormatter(
timeZone
)
.formatToParts(date)
.reduce(
(acc, item) => {
acc[item.type] = item.value;

return acc;
},
{} as Record<Intl.DateTimeFormatPartTypes, string>
);
const datePart = `${year}-${month}-${day}T${hour}:${minute}:${second}`;
const offset = -date.getTimezoneOffset();
const offsetSign = offset >= 0 ? '+' : '-';
const offsetHours = Math.abs(Math.floor(offset / 60))
.toString()
.padStart(2, '0');
const offsetMinutes = Math.abs(offset % 60)
.toString()
.padStart(2, '0');
const millisecondPart = date.getMilliseconds().toString().padStart(3, '0');
const offsetPart = `${offsetSign}${offsetHours}:${offsetMinutes}`;

return `${datePart}.${millisecondPart}${offsetPart}`;
}
}

export { LogFormatter };
168 changes: 165 additions & 3 deletions packages/logger/tests/unit/formatter/PowertoolsLogFormatter.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,13 +8,20 @@ import { PowertoolsLogFormatter } from '../../../src/formatter/PowertoolsLogForm
import { LogItem } from '../../../src/index.js';
import type { UnformattedAttributes } from '../../../src/types/Logger.js';
import type { LogAttributes } from '../../../src/types/Log.js';
import { EnvironmentVariablesService } from '../../../src/config/EnvironmentVariablesService.js';

describe('Class: PowertoolsLogFormatter', () => {
const mockDate = new Date(1466424490000);
const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate);
const ENVIRONMENT_VARIABLES = process.env;

beforeEach(() => {
dateSpy.mockClear();
const mockDate = new Date(1466424490000);
jest.useFakeTimers().setSystemTime(mockDate);
process.env = { ...ENVIRONMENT_VARIABLES };
});

afterAll(() => {
process.env = ENVIRONMENT_VARIABLES;
jest.useRealTimers();
});

describe('Method: formatAttributes', () => {
Expand Down Expand Up @@ -309,6 +316,161 @@ describe('Class: PowertoolsLogFormatter', () => {
// Assess
expect(timestamp).toEqual('2016-06-20T12:08:10.000Z');
});

test('it formats the timestamp to ISO 8601, accounting for the `America/New_York` timezone offset', () => {
// Prepare
process.env.TZ = 'America/New_York';
/*
Difference between UTC and `America/New_York`(GMT -04.00) is 240 minutes.
The positive value indicates that `America/New_York` is behind UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(240);
const formatter = new PowertoolsLogFormatter({
envVarsService: new EnvironmentVariablesService(),
});

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-20T08:08:10.000-04:00');
});

test('it formats the timestamp to ISO 8601 with correct milliseconds for `America/New_York` timezone', () => {
// Prepare
process.env.TZ = 'America/New_York';
const mockDate = new Date('2016-06-20T12:08:10.910Z');
jest.useFakeTimers().setSystemTime(mockDate);
/*
Difference between UTC and `America/New_York`(GMT -04.00) is 240 minutes.
The positive value indicates that `America/New_York` is behind UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(240);
const formatter = new PowertoolsLogFormatter({
envVarsService: new EnvironmentVariablesService(),
});

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-20T08:08:10.910-04:00');
});

test('it formats the timestamp to ISO 8601, adjusting for `America/New_York` timezone, preserving milliseconds and accounting for date change', () => {
// Prepare
process.env.TZ = 'America/New_York';
const mockDate = new Date('2016-06-20T00:08:10.910Z');
jest.useFakeTimers().setSystemTime(mockDate);
/*
Difference between UTC and `America/New_York`(GMT -04.00) is 240 minutes.
The positive value indicates that `America/New_York` is behind UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(240);
const formatter = new PowertoolsLogFormatter({
envVarsService: new EnvironmentVariablesService(),
});

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-19T20:08:10.910-04:00');
});

test('if `envVarsService` is not set, ensures timestamp is formatted to `UTC` even with `America/New_York` timezone', () => {
// Prepare
process.env.TZ = 'America/New_York';
/*
Difference between UTC and `America/New_York`(GMT -04.00) is 240 minutes.
The positive value indicates that `America/New_York` is behind UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(240);
const formatter = new PowertoolsLogFormatter();

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-20T12:08:10.000Z');
});

test('it formats the timestamp to ISO 8601, accounting for the `Asia/Dhaka` timezone offset', () => {
// Prepare
process.env.TZ = 'Asia/Dhaka';
/*
Difference between UTC and `Asia/Dhaka`(GMT +06.00) is 360 minutes.
The negative value indicates that `Asia/Dhaka` is ahead of UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(-360);
const formatter = new PowertoolsLogFormatter({
envVarsService: new EnvironmentVariablesService(),
});

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-20T18:08:10.000+06:00');
});

test('it formats the timestamp to ISO 8601 with correct milliseconds for `Asia/Dhaka` timezone', () => {
// Prepare
process.env.TZ = 'Asia/Dhaka';
jest.useFakeTimers().setSystemTime(new Date('2016-06-20T12:08:10.910Z'));
/*
Difference between UTC and `Asia/Dhaka`(GMT +06.00) is 360 minutes.
The negative value indicates that `Asia/Dhaka` is ahead of UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(-360);
const formatter = new PowertoolsLogFormatter({
envVarsService: new EnvironmentVariablesService(),
});

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-20T18:08:10.910+06:00');
});

test('it formats the timestamp to ISO 8601, adjusting for `Asia/Dhaka` timezone, preserving milliseconds and accounting for date change', () => {
// Prepare
process.env.TZ = 'Asia/Dhaka';
const mockDate = new Date('2016-06-20T20:08:10.910Z');
jest.useFakeTimers().setSystemTime(mockDate);
/*
Difference between UTC and `Asia/Dhaka`(GMT +06.00) is 360 minutes.
The negative value indicates that `Asia/Dhaka` is ahead of UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(-360);
const formatter = new PowertoolsLogFormatter({
envVarsService: new EnvironmentVariablesService(),
});

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-21T02:08:10.910+06:00');
});

test('if `envVarsService` is not set, ensures timestamp is formatted to `UTC` even with `Asia/Dhaka` timezone', () => {
// Prepare
process.env.TZ = 'Asia/Dhaka';
/*
Difference between UTC and `Asia/Dhaka`(GMT +06.00) is 360 minutes.
The negative value indicates that `Asia/Dhaka` is ahead of UTC.
*/
jest.spyOn(Date.prototype, 'getTimezoneOffset').mockReturnValue(-360);
const formatter = new PowertoolsLogFormatter();

// Act
const timestamp = formatter.formatTimestamp(new Date());

// Assess
expect(timestamp).toEqual('2016-06-20T12:08:10.000Z');
});
});

describe('Method: getCodeLocation', () => {
Expand Down