Logger: appendKeys and promises

[matthelliwell2]

Is there a problem using logger.appendKeys with async/await?

I've got global logger instance created in my lambda. I want to use appendKeys to log some key information. The lambda reads a batch of messages from SQS and processes the message in parallel using async/await. For example, suppose I'm reading data about books from SQS and updating a database with the book info. I want to log the ISBN on each log line.

My handler might look something like

export async function handler(event: SQSEvent): Promise<SQSBatchResponse> {
    const promises = event.Records.map(async r => {
        logger.appendKeys({isbn: r.isbn})
        // Lots of async processing and logging
        logger.resetKey()
    })
    
    const results = await Promise.allSettled(promises)
...    
}

As it stands, this won't work because the calls to appendKeys will overwrite the value of key being stored in the global logger. Am I missing something or is there a workaround for this, such as using a different instance of the logger for each record.

[dreamorosi]

Hi @matthelliwell2, as you've noticed the Logger instance as of today has only one context/bag of attributes.

In your case, you're running a number of promises in parallel, so they're all appending/removing keys from the same instance, this is why keys are getting mixed and/or deleted.

As you already hinted at, the solution would be to create child loggers for each one of your parallel tasks:

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

const logger = new Logger({ logLevel: 'debug' });

export async function handler(event: SQSEvent): Promise<SQSBatchResponse> {
    logger.appendKeys({ foo: 'bar' });

    const promises = event.Records.map(async r => {
        const taskLogger = logger.createChild(); // this inherits any config from the main logger, in this case logLevel & foo key
        taskLogger.appendKeys({isbn: r.isbn}) // this key only affects this instance of taskLogger, but not the parent
        // Lots of async processing and logging
        taskLogger.resetKeys() // this also affects only this instance but not the parent
    })
    
    const results = await Promise.allSettled(promises)
    // ...    
}

The last taskLogger.resetKeys() could potentially also be removed. If there's no other reference of that promise, at some point it the entire scope, including the child logger, should be garbage collected anyway.

---

I think this is something we should call out in the docs, it's a common pitfall and right now I don't think we mention this anywhere.

Likewise, I think there are other solutions we could implement, like using AsyncLocalStorage internally but they require research and there hasn't been any demand just yet.