puzpuzpuz / cls-rtracer

Request Tracer - CLS-based request id generation for Express, Fastify, Koa and Hapi, batteries included
MIT License
311 stars 24 forks source link

Example integration with Winston.. #11

Closed brahama closed 5 years ago

brahama commented 5 years ago

Hi guys!

I am new to javascript. Was trying to implement this with express and winston...

app.js

const rTracer = require("cls-rtracer");
const requestId = rTracer.id();
const { createLogger } = require("./logger"); //Here i define the transports and logic to add 
                                                                            // namespace of the file name. 
const logger = createLogger(__filename);
logger.debug("Created logger successfully");
const express = require("express");
const bodyParser = require("body-parser");

const app = express();

app.use(bodyParser.json());
app.use(rTracer.expressMiddleware());

app.use(
  "/graphql",
  graphqlHTTP({
    schema: graphQLSchema,
    rootValue: graphQLResolvers,
    graphiql: true
  })
);

app.listen(3001, () => logger.info("Listening on port 3001")); 

logger.js

  const rTracer = require("cls-rtracer");
  const { createLogger, transports, format } = require("winston");
  const packageInfo = require("../../package.json");
  const path = require("path");

function logger(filename, options = []) {
  let prefix = createPrefix(filename);
  ...
  const loggerConfig = {
    transports: []
  };
  const rid = rTracer.id();
  console.log(rid);

  loggerConfig.transports.push(
      new transports.Console({
        level: LOGGING_CLI_LEVEL,
        format: format.combine(
          format.timestamp(),
          format.label({
            label: `[${prefix}]`
          }),
          format.splat(),
          format.prettyPrint(),
          format.simple(),
          format.ms(),
          format.printf((msg) => {
            return colorizer.colorize(
              msg.level,
              `${msg.label} ${
                msg.timestamp
              } [request-id:${rid}] - ${msg.level.toUpperCase()}: ${
                msg.message
              } ${msg.ms}`
            );
          })
        )
      })
    );
  return createLogger({
    ...options,
    ...loggerConfig
  });

I get 2019-07-29T22:04:24.150Z [request-id:undefined] - INFO: Listening on port 3001 +0ms, which i think i understand as it has not recieved a request yet. So the id reqId is generated by the middleware only right? Now, the problem it seems to be in the way i use winston. i import and create the logger per module and as it is imported on load, it always get undefined. and then the reqId is never updated, and never .get from the store. Would be nice an example of multiple files where winston logger is imported. Any hints apreciatted :)

Just to add more context.

streams.js

const { createLogger } = require("../logger");
const logger = createLogger(__filename);
logger.debug("Created logger successfully");
const rTracer = require("cls-rtracer");

async function getData() {
  const requestId = rTracer.id();
  ...
  logger.info("Grabbing records from timestamp: " + timestamp); //get Undefined
  console.log(requestId); // Perfect. Same as in the middleware console.log test.
}
aigoncharov commented 5 years ago

@brahama hi! I don't see where 'rid' variable comes from in your logger.js. Try to replace it with 'rTracer.id()'

brahama commented 5 years ago

Hey @keenondrums ! let me update there the issue, to add more context. Thanks! There i added a bit more context to the logger.js. I think that will suffice. I then require it in every module I need as the streams.js example. 😄

aigoncharov commented 5 years ago

@brahama your rid there gets calculated only once before your transport is created.

Try

 const rTracer = require("cls-rtracer");
  const { createLogger, transports, format } = require("winston");
  const packageInfo = require("../../package.json");
  const path = require("path");

function logger(filename, options = []) {
  let prefix = createPrefix(filename);
  ...
  const loggerConfig = {
    transports: []
  };

  loggerConfig.transports.push(
      new transports.Console({
        level: LOGGING_CLI_LEVEL,
        format: format.combine(
          format.timestamp(),
          format.label({
            label: `[${prefix}]`
          }),
          format.splat(),
          format.prettyPrint(),
          format.simple(),
          format.ms(),
          format.printf((msg) => {
            return colorizer.colorize(
              msg.level,
              `${msg.label} ${
                msg.timestamp
              } [request-id:${rTracer.id()}] - ${msg.level.toUpperCase()}: ${
                msg.message
              } ${msg.ms}`
            );
          })
        )
      })
    );
  return createLogger({
    ...options,
    ...loggerConfig
  });
brahama commented 5 years ago

Like a charm! Thanks a lot @keenondrums !