5

I am currently using Express 4 and Node 8 in a project of mine. I want to be able to log certain things that occur in the app and have the session ID serve as the way to link a chain of logs together. I am using winston for logging.

The Question: How can I access this session ID from anywhere in the app so that it can be included in logs?

I understand that you can't just set the session id to a global variable since incoming subsequent requests will override whatever is set.

Additionally, I know it is possible to pass the session id down from the routing layer to all other functions that need it, but this can be rather cumbersome when functions at the deepest levels need the session id just for logging.

For multithreaded applications, each thread can have its own memory pool so that it can safely house a logging correlation id globally without interference from other requests. However, since Node is single-threaded, this does not seem to be possible, unless I am missing something.

Is there a way to have a request-specific global pool, or perhaps is there a better way to include a correlation id in every log statement that is made?

Auroratide
  • 2,299
  • 10
  • 15

3 Answers3

3

The Question: How can I access this session ID from anywhere in the app so that it can be included in logs?

The req object from an incoming request IS the request-specific object that will have the state for the current request (including session information). There is really no other way to do things in node.js. As you seem to already know, because of the shared, single thread architecture of node.js, there are no such things as request-specific globals where you could put something that you could access from anywhere and it would tell you what session you're serving.

If you want access to the session state, then you have to pass the req object or the session state itself down to the level where you want to log it. There just really isn't another way to do things.

I understand that you can't just set the session id to a global variable since incoming subsequent requests will override whatever is set.

Correct. Trying to put any request-specific state in a global space will just cause it to regularly get tromped on by the cooperative event processing of several different requests interleaving their work.

For multithreaded applications, each thread can have its own memory pool so that it can safely house a logging correlation id globally without interference from other requests. However, since Node is single-threaded, this does not seem to be possible, unless I am missing something.

You're not missing anything.

Is there a way to have a request-specific global pool, or perhaps is there a better way to include a correlation id in every log statement that is made?

No, there is not. You just have to pass the req object or pass session-specific state down to the level you want to log it at. There is no request-specific global pool. node.js does not maintain some sort of state about which request has code running at any given time. As you probably already know, one request can start processing, then return control back to the system while it awaits some async operation and another starts processing and then when that one returns control while it awaits some async operation, the former gets an event and starts executing code. When subsequent async events cause new code in service of a request to be executed again, the stack is empty again (there is no request-specific state on it).

The likely key to making this possible or tenable has to do with how your code is structured, what objects are available at a fairly low level so you can figure out what object you can attach session info to that makes it accessible where you need it. This is not a generic solution, but depends upon the exact layout and structure of your code so without seeing the specific code you have in mind, we can't really advise any more specifically other than "pass the session info down to where you need it".

jfriend00
  • 683,504
  • 96
  • 985
  • 979
2

I had this same problem, and after a big research, I finally could find out a way to solve it. I explained it in this question: NodeJS Express - Global Unique Request Id But basically I used 2 libraries: - node-uuid: to generate unique ids for each request - continuation-local-storage: to share the id with the different modules that are going to need it.

I wrote down all this information with a complete code example in this post: https://solidgeargroup.com/express-logging-global-unique-request-identificator-nodejs

In my case, as I used Winston for logging, the example is made with this library, but it would work with any other.

David Vicente
  • 3,091
  • 1
  • 17
  • 27
0

you can use async_hooks which acts similarly to ThreadLocal.

I have used correlation-id as a wrapper to async_hooks, and then you can use this correlation-id from anywhere in the code related to each request. For example:

import * as correlator from 'correlation-id';
...
app.get('/run/', async (req: express.Request, res: express.Response) => {
    try {
        const correlatorId = Math.floor(Math.random() * 100000);
        correlator.withId(correlatorId, async () => {
            logger.info(`received 'run' request`);
    
            const result = await new Service().doSomething();
    
            logger.info(`result: ${result}`);
            res.status(200).send({ result });
        });
    
    } catch (e) ...
});

and consume it this way:

import * as correlator from 'correlation-id';

correlator.getId();

...I know it is possible to pass the session id down from the routing layer to all other functions that need it, but this can be rather cumbersome when functions at the deepest levels need the session id just for logging.

Understood. Using the method above, the task cannot be simpler!

BTW, I was using log4js, so I changed the layout to be as elegant as possible.

All this information with a complete code example in this post: https://medium.com/p/7ef0562efeb2

OhadR
  • 8,276
  • 3
  • 47
  • 53