Request scope context with Logger

[Aaron-Zhao-Asurion]

Hi, I was reading powertools logger about persistentLogAttributes that it can be used to persistent the log context throughout the invocation/request, and then coupled with clearState, this will clear the log context preventing it from being reused for the next invocation/request since they are not relevant. This to me, kind of achieved request scope context tracking.

My question is how is this implemented in powertools logger to achieve that? My research tells me that AsyncLocalStorage is only way to achieve request scope context tracking in NodeJS, since nodejs is single threaded there is no thread level storage for request scope data like we have with other traditional servers. But I don't find the use of AsyncLocalStorage in this repo.

Is it there is another way to achieve request scope data in nodejs that I didn't know about OR am I misunderstanding the use of clearState in powertools logger or lambda nodejs env is different from vanilla nodejs?

[Aaron-Zhao-Asurion]

AWS lambda specific
#1328 (comment)

https://docs.aws.amazon.com/lambda/latest/dg/lambda-runtime-environment.html#runtimes-lifecycle

[dreamorosi]

Looking at the lifecycle of an execution environment (docs) we can see that there are three distinct phases: 1/ Init, 2/ Invoke, and 3/ Shutdown:

Let's take this code:

const name = 'Bob';

export const myHandler = () => {
  console.log(`Hello ${name}`);
}

The first time an execution environment is provisioned, it goes through the Init phase. In this case, the variable named name is instantiated with value 'Bob'.

After that, the function handler (in this case, the function with name myHandler) is run during the Invoke phase. For each request that comes, Lambda will call the handler in an existing or new execution environment. The handler, and an execution environment, can only ever receive one request at the time.

By storing a reference of the name variable outside the function handler, we can persist some state across invocations. This means our function will always log the string 'Hello Bob'.

The Logger utility, as well as all others in Powertools, are based on this concept. We create an object (in the case of Powertools a class instance) outside of the function handler, and then later on for each request that goes to the same execution environment, we use that same object.

The main limitation, which things like AsyncLocalStorage mitigate, is that we need to pass a reference of that object around. If your application is working across different files and/or spawning different worker threads/parallel promises, then this method might not be suitable.

In the context of Lambda, especially on the Node.js runtime, most functions only process one request at the time and multi-threading is not generally used.

[Aaron-Zhao-Asurion]

Thank you for the detailed reply @dreamorosi. One detail is still not clear to me, if I don't want the "name=bob" to persist to the next request/invoke, we set clearState to true, and let's say for the second request I set "name=alice", I am curious how does the logger instance which is in global scope, know which name to return for request #2 and unfinished request #1 (the remaining of the run). At the time of processing 2nd request (with unfinished 1st request), the global var name is already set to "alice".

[dreamorosi]

There's no "remaining of the run".

Request #2 can be routed to the same environment as request #1 only and exclusively if #1 has already finished.

If request #2 comes while request #1 hasn't finished, Lambda will create a completely new and independent execution environment.

With this in mind, and in this particular context, race conditions cannot happen.

[dreamorosi]

In short, the fact that the two "Invoke" phases are sequential in the diagram is not just a simplification / representation, but a guarantee.

For example, looking at the diagram below:

We have request 1, 2, 3, and 4.

Since request 1 is the first, it gets a new execution environment (which goes through an Init phase).
Then, request 2 comes while request 1 hasn't finished, so Lambda has to create a second execution environment (which also goes through its own Init phase).
By the time request 3 comes, the original execution environment is now available, so Lambda uses it (this time the environment is warm)
Then, when request 4 comes, both environments are available so Lambda routes it to one of the two (in this diagram, it goes to the second since the first was now shut down, but it could have gone to the first as well if it was still available).

[Aaron-Zhao-Asurion]

sorry I think I am still missing some understanding here. Does that mean for the following example,

let name = 'default';

export const myHandler = (context) => { 
  name = context.name;
  // some async process..
  console.log(`Hello ${name}`);
}

Request 1: context.name = bob; => "this will print hello bob"

Request 2: context.name = alice; => "this will print hello alice"

This is similar to what I tried before discovering AsyncLocalStorage and this repo's logger tool. My experience was when there are concurrent requests, name will get overwritten by request 2 and results in,

Request 1: "print hello alice"

Request 2: "print hello alice"