feat(logger): custom function for unserializable values (JSON replacer)

[arnabrahman]

Summary

Logger emits JSON structured logs, to do so it calls JSON.stringify() under the hood. There are several types of objects that cannot natively be serialized or that when serialized using the default behavior loose information.

Here we are giving customers a way out by providing a custom replacer function which will be used during JSON.stringify

Changes

• Introduce jsonReplacerFn property that can be passed into the constructor during initialization.
• Use the custom replacer function if provided during stringify.
• Pass ``jsonReplacerFn` to child instance.
• Unit tests for new functionality
• Update docs for the new feature

Previously:

import { Logger } from '@aws-lambda-powertools/logger';

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

export const handler = async (_event, _context): Promise<void> => {
  logger.info('Serialize with custom serializer', {
    serializedValue: new Set([1, 2, 3]),
  });
};

Output:
{
  "level": "INFO",
  "message": "Serialize with custom serializer",
  "sampling_rate": 0,
  "service": "serverlessAirline",
  "timestamp": "2024-07-07T09:52:14.212Z",
  "xray_trace_id": "1-668a654d-396c646b760ee7d067f32f18",
  "serializedValue": {}
}

Now while using custom replacer:

import { Logger } from '@aws-lambda-powertools/logger';
import type { CustomReplacerFn } from '@aws-lambda-powertools/logger/types';

const jsonReplacerFn: CustomReplacerFn = (key: string, value: unknown) =>
  value instanceof Set ? [...value] : value;

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

export const handler = async (_event, _context): Promise<void> => {
  logger.info('Serialize with custom serializer', {
    serializedValue: new Set([1, 2, 3]),
  });
};

Output:
{
  "level": "INFO",
  "message": "Serialize with custom serializer",
  "sampling_rate": 0,
  "service": "serverlessAirline",
  "timestamp": "2024-07-07T09:52:14.212Z",
  "xray_trace_id": "1-668a654d-396c646b760ee7d067f32f18",
  "serializedValue": [1, 2, 3]
}

Issue number: #1776

---

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

Disclaimer: We value your time and bandwidth. As such, any pull requests created on non-triaged issues might not be successful.

[dreamorosi]

Hi @arnabrahman - the PR is looking good!

I'm going to take a few more hours to checkout the repo and review it more in details, but I should be able to post my review today.

[dreamorosi]

Thank you for this PR, this is a feature I've been wanting to use myself for a while but never got around actually working on it.

I have left a few minor comments related to naming of the new type and examples. Also, after testing the new feature, I realized we might have a chance to make it even better for customers.

As of today, Logger already has its own custom JSON replacer function. This is used to handle some special cases like circular references, Error, and BigInt types.

With the new feature proposed, customers will be able to provide their own custom JSON replacer function, this is useful in cases where they want to log even more complex types or data structures.

In doing this however they would be losing the goodies that Logger already comes with out-of-the box. For example, by providing a custom replacer, if you still want to log a BigInt you now get a runtime error:

const jsonReplacerFn: CustomReplacerFn = (
  key: string,
  value: unknown
) => {
  if (value instanceof Set || value instanceof Map) {
    return [...value];
  }

  return value;
};

const logger = new Logger({ jsonReplacerFn });

logger.info('many complex types', {
  map: new Map([[1, 2], [3, 4]]),
  set: new Set(['a', 'b', 'c']),
  bigInt: BigInt(42)
});

What if instead of replacing the function, we treated the new function as a way to extend the built-in JSON replacer?

The experience would remain the same as the one you're proposing, except that instead of sidestepping the default JSON replacer, we'd call the one provided by the customer (if any) within the method that is currently called getDefaultReplacer (which could be renamed to getJsonReplacer:

private getJsonReplacer(): (_: string, value: unknown) => void {
  const references = new WeakSet();

  return (_, value) => {
    let item = value;

    if (this.jsonReplacerFn) item = this.jsonReplacerFn?.(_, item);

    if (item instanceof Error) {
      item = this.getLogFormatter().formatError(item);
    }
    if (typeof item === 'bigint') {
      return item.toString();
    }
    if (typeof item === 'object' && item !== null && value !== null) {
      if (references.has(item)) {
        return;
      }
      references.add(item);
    }

    return item;
  };
}

Naturally, to allow for the above we'd have to change/remove the #setJsonReplacerFn method to simply assign the customerReplacerFn value to the this.jsonReplacerFn prop while setting the options, and we'd also have to change the printLog method to call the getDefaultReplacer now-renamed method when logging.

So, to sum up, the changes needed would be:

• rename the getDefaultReplacer method (here) to getJsonReplacer, and update the implementation similar to what suggested above
• since now there's no conditional logic, remove the #setJsonReplacerFn method (here) and assign the value directly here
• call the getJsonReplacer method here
• add an unit test case similar to the one suggested below, to confirm the change works as intended

it('should serialize using both the existing replacer and the customer-provided one', () => {
  const jsonReplacerFn: CustomReplacerFn = (
    key: string,
    value: unknown
  ) => {
    if (value instanceof Set || value instanceof Map) {
      return [...value];
    }

    return value;
  };

  const logger = new Logger({ jsonReplacerFn });
  const consoleSpy = jest.spyOn(
    logger['console'],
    getConsoleMethod(methodOfLogger)
  );

  const message = `This is an ${methodOfLogger} log with Set value`;
  const logItem = { value: new Set([1, 2]), number: BigInt(42) };

  // Act
  logger[methodOfLogger](message, logItem);

  // Assess
  expect(consoleSpy).toBeCalledTimes(1);
  expect(consoleSpy).toHaveBeenNthCalledWith(
    1,
    JSON.stringify({
      level: methodOfLogger.toUpperCase(),
      message: message,
      sampling_rate: 0,
      service: 'hello-world',
      timestamp: '2016-06-20T12:08:10.000Z',
      xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793',
      value: [1, 2],
      number: '42',
    })
  );
});

Let me know what you think, or if you think this is a bad idea - and thank you for your time and effort as always!

[arnabrahman]

First of all, I apologize for the delayed response. I had hoped to review all of your messages from all the threads, but due to work commitments, I haven't been able to. Unfortunately, I won't be able to address this any time soon, as I will be going away for the next three weeks in coming days. I will get to it during the first week of August. @dreamorosi

[dreamorosi]

Hey @arnabrahman, no need to apologize, life happens!

If it's okay for you, I'll push a couple commits to the PR so we can merge it.

In the meantime, enjoy your well deserved vacation!

[arnabrahman]

@dreamorosi Sure, please go ahead.

[dreamorosi]

@am29d - I took over the PR (see comments above for context).

It's now ready to review whenever you're ready. Thanks!

[am29d]

Great addition, only minor comments on the docs

[am29d]

Great collaborative work. Thanks you @arnabrahman and @dreamorosi 👏