Skip to content

Docs: add notice about mutating attributes in custom log formatters #3588

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

Closed
VladimirGorobetsWildix opened this issue Feb 11, 2025 · 3 comments · Fixed by #3604
Closed

Docs: add notice about mutating attributes in custom log formatters #3588

VladimirGorobetsWildix opened this issue Feb 11, 2025 · 3 comments · Fixed by #3604
Assignees
Labels
completed This item is complete and has been merged/shipped logger This item relates to the Logger Utility not-a-bug New and existing bug reports incorrectly submitted as bug

Comments

@VladimirGorobetsWildix
Copy link

Expected Behavior

No change original event fields.

Current Behavior

Original event fields changed in logFormatter after upgrade 2.13.1 -> 2.14.0

Image

Code snippet

import middy from '@middy/core'
import {LogFormatter, Logger, LogItem} from "@aws-lambda-powertools/logger";
import type {LogAttributes, UnformattedAttributes} from '@aws-lambda-powertools/logger/types';
import {injectLambdaContext} from "@aws-lambda-powertools/logger/middleware";


class MyCompanyLogFormatter extends LogFormatter {
    private hideFields = [
        'authorization',
        'password',
        'secret',
        'key',
        'token',
    ]

    processObject(obj: Record<string, any>) {
        for (const key in obj) {
            if (typeof obj[key] === 'object') {
                this.processObject(obj[key])
            } else if (typeof obj[key] === 'string' && obj[key].length) {
                if (this.hideFields.includes(key)) {
                    obj[key] = '**** hidden ****'; // Maybe incorrect solution, but it worked in 2.13.1
                }
            }
        }
    }

    public formatAttributes(
        attributes: UnformattedAttributes,
        additionalLogAttributes: LogAttributes
    ): LogItem {
        const {message, ...rest} = structuredClone(attributes);

        try {
            this.processObject(rest);
            this.processObject(additionalLogAttributes);
        } catch (e) {
        }

        const logItem = new LogItem({
            attributes: {
                message,
                ...rest,
            },
        })
        logItem.addAttributes(additionalLogAttributes);

        return logItem;
    }
}

(async () => {
    const logger = new Logger({
        logFormatter: new MyCompanyLogFormatter()
    })

    const lambdaHandler = async (event: Event) => {
        logger.info('==> Event in handler (secure)', {event});
        console.log('==> Event in handler (raw)', JSON.stringify(event));

        return {success: true}
    }

    const handler = middy()
        .use(injectLambdaContext(logger, {logEvent: true}))
        .handler(lambdaHandler)


    const rawEvent = {
        headers: {
            authorization: 'Bearer aaa.bbb.ccc',
            'content-type': 'application/json',
        }
    }

    // @ts-ignore
    await handler(rawEvent, {}, {});
})()

Steps to Reproduce

  1. Run code with @aws-lambda-powertools/logger: 2.13.1
  2. Receive response ==> Event in handler (raw) {"headers":{"authorization":"Bearer aaa.bbb.ccc","content-type":"application/json"}}
  3. Run code with @aws-lambda-powertools/logger: 2.14.0
    4 Receive response ==> Event in handler (raw) {"headers":{"authorization":"**** hidden ****","content-type":"application/json"}}

Possible Solution

No response

Powertools for AWS Lambda (TypeScript) version

2.14.0

AWS Lambda function runtime

22.x

Packaging format used

npm

Execution logs

@VladimirGorobetsWildix VladimirGorobetsWildix added bug Something isn't working triage This item has not been triaged by a maintainer, please wait labels Feb 11, 2025
@dreamorosi
Copy link
Contributor

Hi @VladimirGorobetsWildix, thank you for opening this issue.

The change of order of the fields has nothing to do with what you're observing. The change you're referring to was made in the in the default log formatter (here) which you're completely bypassing by providing your own custom log formatter (see logic that decides which one is used here).

The reason why you're seeing this behavior is that you're mutating directly the additionalLogAttributes object rather than working on a copy, like you're doing for the attributes one with structuredClone.

I would recommend changing the logic in your log formatter to something like this, which I confirmed works as intended:

class MyCompanyLogFormatter extends LogFormatter {
  private hideFields = ['authorization', 'password', 'secret', 'key', 'token'];

  processObject(obj: Record<string, any>) {
    for (const key in obj) {
      if (typeof obj[key] === 'object') {
        this.processObject(obj[key]);
      } else if (typeof obj[key] === 'string' && obj[key].length) {
        if (this.hideFields.includes(key)) {
          obj[key] = '**** hidden ****'; // Maybe incorrect solution, but it worked in 2.13.1
        }
      }
    }

    return obj; // return mutated object
  }

  public formatAttributes(
    attributes: UnformattedAttributes,
    additionalLogAttributes: LogAttributes
  ): LogItem {
    const { message, ...rest } = structuredClone(attributes);

    const logItem = new LogItem({
      attributes: {
        message,
      },
    });
    try {
      const sanitizedRest = this.processObject(rest);
      logItem.addAttributes(sanitizedRest);
    } catch {
      logItem.addAttributes(rest);
    }

    try {
      const sanitizedAdditional = this.processObject(
        structuredClone(additionalLogAttributes) // now it's a deep clone and can be mutated
      );
      logItem.addAttributes(sanitizedAdditional);
    } catch {
      logItem.addAttributes(additionalLogAttributes);
    }

    return logItem;
  }
}

I have tested the implementation above with the latest version and confirmed it logs as expected, and leaves the event unchanged:

{"message":"Lambda invocation event","logLevel":"INFO","timestamp":"2025-02-11T16:48:48.190Z","xRayTraceId":"1-67ab7f6f-722297141fd59b5c6ce6ed2e","awsRegion":"eu-west-1","serviceName":"service_undefined","sampleRateValue":0,"lambdaContext":{"invokedFunctionArn":"arn:aws:lambda:eu-west-1:123456789012:function:loggerorder-aamorosi-loggerOrderFunction-cefusswu","coldStart":true,"awsRequestId":"51f675cb-a01a-4afb-beb2-12ae229dbb81","memoryLimitInMB":"1024","functionName":"loggerorder-aamorosi-loggerOrderFunction-cefusswu","functionVersion":"$LATEST"},"event":{"headers":{"authorization":"**** hidden ****","content-type":"application/json"}}}
{"message":"==> Event in handler (secure)","logLevel":"INFO","timestamp":"2025-02-11T16:48:48.195Z","xRayTraceId":"1-67ab7f6f-722297141fd59b5c6ce6ed2e","awsRegion":"eu-west-1","serviceName":"service_undefined","sampleRateValue":0,"lambdaContext":{"invokedFunctionArn":"arn:aws:lambda:eu-west-1:123456789012:function:loggerorder-aamorosi-loggerOrderFunction-cefusswu","coldStart":true,"awsRequestId":"51f675cb-a01a-4afb-beb2-12ae229dbb81","memoryLimitInMB":"1024","functionName":"loggerorder-aamorosi-loggerOrderFunction-cefusswu","functionVersion":"$LATEST"},"event":{"headers":{"authorization":"**** hidden ****","content-type":"application/json"}}}
2025-02-11T16:48:48.196Z        51f675cb-a01a-4afb-beb2-12ae229dbb81    INFO    ==> Event in handler (raw) {"headers":{"authorization":"Bearer aaa.bbb.ccc","content-type":"application/json"}}

In the latest release we made some slight changes to how the attributes are handled internally to reduce object mutation and improve resource usage. Since they were internal changes we didn't include them in the release notes.

Likewise, I would not consider this a regression, since the contract between the Logger and LogFormatter class remained unchanged, and the parameters (aka the attributes) passed to the formatAttributes method are still the same / in the same order.

I will however open a PR to improve the documentation & examples around custom log formatters to advise customers to make a clone of these attributes if they intend to mutate them, rather than just rearrange/omit some of them.

@dreamorosi dreamorosi added logger This item relates to the Logger Utility confirmed The scope is clear, ready for implementation not-a-bug New and existing bug reports incorrectly submitted as bug and removed bug Something isn't working triage This item has not been triaged by a maintainer, please wait labels Feb 11, 2025
@dreamorosi dreamorosi changed the title Bug: changed behavior for logFormatter in v 2.14.0 the fields of the original event are changed Docs: add notice about mutating attributes in custom log formatters Feb 11, 2025
@dreamorosi dreamorosi self-assigned this Feb 11, 2025
@dreamorosi dreamorosi moved this from Triage to Backlog in Powertools for AWS Lambda (TypeScript) Feb 11, 2025
@dreamorosi dreamorosi moved this from Backlog to Working on it in Powertools for AWS Lambda (TypeScript) Feb 14, 2025
@github-project-automation github-project-automation bot moved this from Working on it to Coming soon in Powertools for AWS Lambda (TypeScript) Feb 15, 2025
Copy link
Contributor

⚠️ COMMENT VISIBILITY WARNING ⚠️

This issue is now closed. Please be mindful that future comments are hard for our team to see.

If you need more assistance, please either tag a team member or open a new issue that references this one.

If you wish to keep having a conversation with other community members under this issue feel free to do so.

@github-actions github-actions bot added pending-release This item has been merged and will be released soon and removed confirmed The scope is clear, ready for implementation labels Feb 15, 2025
Copy link
Contributor

This is now released under v2.15.0 version!

@github-actions github-actions bot added completed This item is complete and has been merged/shipped and removed pending-release This item has been merged and will be released soon labels Feb 25, 2025
@dreamorosi dreamorosi moved this from Coming soon to Shipped in Powertools for AWS Lambda (TypeScript) Feb 25, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
completed This item is complete and has been merged/shipped logger This item relates to the Logger Utility not-a-bug New and existing bug reports incorrectly submitted as bug
Projects
2 participants