[FEATURE REQUEST] Logger usage outside HTTP context

[mentos1386]

• I've read the docs of nestjs-pino
• I've read the docs of pino
• I couldn't find the same question about nestjs-pino

Question

I'm trying to use logger.assign outside of HTTP context. Specifically, inside sqs consumer's handleMessage function.

I figured out with the help of #788 to initiate the storage.run on my own. The problem was that i don't have access to req.log so i used PinoLogger.root instead. Is this supposed to be used like this?

import { storage, Store } from 'nestjs-pino/storage';
import { PinoLogger } from 'nestjs-pino';

---

    this.consumer = Consumer.create({
      // this magic creates AsyncLocalStorage context
      // for nestjs-pino to work with. It allows the use
      // of this.logger.assign() method.
      handleMessage: message =>
        storage.run(new Store(PinoLogger.root), () =>
          this.processMessage(message),
        ),
    });

It seems to work fine. But want to make sure we won't break something in strange ways.

I guess this also relates to @nestjs/bull and @nestjs/microservices are those environments supported? As they are similarly not inside HTTP context (not passing middlewares afaik).

Edit: If this is a valid usage, maybe it could be wrapped in a nicer withNestPinoContext(() => this.processMessage(message)) like function.

[iamolegga]

Desired behavior is not supported at the moment. You can try any hacks (as presented above) to make it work but on your own risk. This is not tested and not supported.

For this feature we need something similar to pino-http-like settings with a lot of settings beside pino-related ones. So this is huge feature and it need a lot of time for implementation. Unfortunately I'm not able to invest in this at the moment. But maybe this year on my current project we will need such feature too, then I think we can invest some time for this. But that's not 100%. In case anyone would like to implement this, feel free to open detailed RFC for this first, before opening PR.

Will change this issue to feature request.

[iamolegga]

OK, in next month or two I'm going to investigate if it's possible to make such feature work with different microservices' transports including custom strategies.

For implementing this feature in a clear way we need middlewares for microservices to be landed in nest. Until then this solution could be used.

[KieronWiltshire]

@iamolegga consider setting up a bounty program. I'd be willing to contribute funding for you to do this if you'd prefer to handle it yourself.

[iamolegga]

@KieronWiltshire answering your question from different issue

Some thought on design for this feature:

I believe the configuration for microservices should be as close as possible to the configuration of pino-http.

Existing pino-http parameters could be:

• reused (e.g. autoLogging, stream, logger etc)
• skipped (?)
• duplicated with different arguments: req/res arguments should be changed to message (e.g. genReqId, customLogLevel, autoLogging.ignore, customReceivedMessage, etc).

Maybe some extra parameters could be added?

Maybe this should be done in different npm package and reused here, the same as pino-http is reused.

[KieronWiltshire]

@iamolegga to be honest... I'm not sure why this approach was even taken. Surely it would've just made sense to pass the pinojs parameters through the module and allow fully interoperability with the official pinojs package. Maybe some of your thoughts on this initial implementation would help me understand more here.

[iamolegga]

@iamolegga consider setting up a bounty program. I'd be willing to contribute funding for you to do this if you'd prefer to handle it yourself.

I'm ok to handle it by myself, but this needs time to make a good API for end-users and good internal design.

So far due to personal reasons I'm not able to invest such time in this feature not in working hours, I hope for your understanding. But to work on this in working hours this needs to be prioritized on my current project where we are using this library, and I believe won't happen in the nearest future as we are building and starting MVP at the moment.

Answering your question: thank you for the suggestion, but it won't work as this is not about money but time. Anyway if someone wants to thank me for the work that's already done in this library please consider donating to Ukraine by the links in docs header 🙏

@iamolegga to be honest... I'm not sure why this approach was even taken. Surely it would've just made sense to pass the pinojs parameters through the module and allow fully interoperability with the official pinojs package. Maybe some of your thoughts on this initial implementation would help me understand more here.

sorry, didn't get what do you mean. If you have a better solution you are more than welcome to fork it or open PR

[KieronWiltshire]

@iamolegga sorry, didn't mean to insult. I'm glad you've created this project, just looking to improve on what you've already built.

sorry, didn't get what do you mean. If you have a better solution you are more than welcome to fork it or open PR

Basically... this package assumes the logging through HTTP or now at this point, microservice, but what about during queue workers etc... what I'm saying is, wouldn't it make more sense to just support pinojs as the module itself, or even better allow the passing of a pinojs instance from forRoot or forRootAsync

Would you like to converse over something like discord for this? or keep it here?

[mentos1386]

@KieronWiltshire please keep the conversation here, or provide a summary in case conversation would take place somewhere else. I would like to know where this is going as well :)

[iamolegga]

sorry, didn't mean to insult

no worries 🙂

this package assumes the logging through HTTP or now at this point, microservice, but what about during queue workers etc.

Sure, queue workers you mean bull, right? Yes, basically we have to create some generic factory that will call parameters methods with the provided argument type. It could be bull's job, microservice's messages and events or any other context.

what I'm saying is, wouldn't it make more sense to just support pinojs as the module itself, or even better allow the passing of a pinojs instance from forRoot or forRootAsync

could you please describe more on this? What API are you expecting?

Would you like to converse over something like discord for this? or keep it here?

agree with @mentos1386 let's keep it here for now

[clintonb]

@iamolegga no need for a separate issue. After looking at the code I see what I need to do. I'll show you code snippet so you understand, but this seems ridiculously backwards. I think you should consider creating a pino instance and attaching the pino-http package to it instead of the other way around.

Here:

import {
  Module,
  NestModule,
} from '@nestjs/common';
import { ConfigModule, ConfigService } from '@nestjs/config';
import { LoggerModule } from 'nestjs-pino';
import pino, { transport } from 'pino';

@Module({
  imports: [
    ConfigModule.forRoot({
      cache: true,
      isGlobal: true,
      load: [
        appConfig,
        databaseConfig,
        redisConfig,
        sentryConfig
      ]
    }),
    LoggerModule.forRootAsync({
      imports: [ConfigModule],
      useFactory: (config: ConfigService) => {
        const pinoLogger = pino(transport({
            target: "pino-sentry-transport",
            options: {
              sentry: {
                dsn: "https://<key>:<secret>@sentry.io/<project>",
                // aditional options for sentry
              },
              withLogRecord: true, // default false - send the log record to sentry as a context.(if its more then 8Kb Sentry will throw an error)
              tags: ['id'], // sentry tags to add to the event, uses lodash.get to get the value from the log record
              context: ['hostname'], // sentry context to add to the event, uses lodash.get to get the value from the log record,
              minLevel: 40, // which level to send to sentry
            }
        }));
        return {
          pinoHttp: {
            logger: pinoLogger,
          }
        }
      },
      inject: [ConfigService]
    }),
  ],
})
export class AppModule implements NestModule {}

Because of the way you instantiate a pino logger, I have to pass it through the pinoHttp.logger option. Realistically, I should just be able to provide a pino instance without going through pinoHttp. It doesn't really matter, but I feel like it's something that could be improved upon.

I'm not sure why this answer is marked as off-topic, but this is the ideal solution. I do the following:

1. Create a "root" pino logger with the relevant configuration.
2. Pass this root logger as pinoHttp.logger.

[michaeljauk]

Hey @iamolegga any update on this? :) Or any recommended workaround?

[iddan]

My current workaround: Using withLoggerContext decorator over the functions I would like to use context.
Example:

@withLoggerContext
foo() {

Here is the code for withLoggerContext:

import { Store, storage } from 'nestjs-pino/storage';
import logger from './pino-logger-instance'; // this should be the same pino instance nestjs-pino uses

export const withLoggerContext: MethodDecorator = (
  target,
  propertyKey,
  descriptor,
) => {
  const methodFunc = descriptor.value;
  if (!methodFunc) {
    return;
  }
  const newMethodFunc = function (...args) {
    // @ts-expect-error
    storage.run(new Store(logger.child({})), () => methodFunc.call(this, args));
  };
  // @ts-expect-error
  descriptor.value = newMethodFunc;
};

[clintonb]

Here is a version of WithLoggerContext that works for async functions and properly pass through all arguments:

import { Store, storage } from 'nestjs-pino/storage';
import rootPinoLogger from './pino-logger-instance'; // this should be the same pino instance nestjs-pino uses

export function WithLoggerContext() {
  return function (
    target,
    key: string | symbol,
    descriptor: PropertyDescriptor
  ) {
    const methodFunc = descriptor.value;
    if (!methodFunc) {
      return descriptor;
    }

    if (methodFunc.constructor.name === 'AsyncFunction') {
      descriptor.value = async function (...args) {
        return storage.run(new Store(rootPinoLogger.child({})), async () =>
          methodFunc.apply(this, args)
        );
      };
    } else {
      descriptor.value = function (...args) {
        return storage.run(new Store(rootPinoLogger.child({})), () =>
          methodFunc.apply(this, args)
        );
      };
    }

    return descriptor;
  };
}

[conioX]

can you share

import rootPinoLogger from './pino-logger-instance';

@iddan

[ajfranzoia]

@conioX you can just create your logger instance like this:

pino(
    {
      level: 'debug',
      transport:
        process.env.NODE_ENV !== 'production'
          ? { target: 'pino-pretty' }
          : undefined,
    },
    stream,
  )

[descampsk]

Hello,
First of all, thanks @iamolegga for your awesome work!
Nestjs-pino is really cool :)

I also have this issue with my application which is a nestjs REST API but also use nest-js commander to launch some scripts within the same codebase.

And I wanted to use the same logger for both commander and the REST API and to be able to use logger.assign.

I found a solution which seems a bit complex but works then transparently.

I extend PinoLogger to override Logger.assign and Logger.logger to use nestjs-cls where I use commander and to rely on the existing storage in case of the API.

In details, here are the three files:

// logger.service.ts

import { Injectable, Inject } from '@nestjs/common';
import { ClsService } from 'nestjs-cls';
import { PinoLogger, Params, PARAMS_PROVIDER_TOKEN } from 'nestjs-pino';
import { type Logger, type Bindings } from 'pino';

@Injectable()
export class LoggerService extends PinoLogger {
  constructor(
    @Inject(PARAMS_PROVIDER_TOKEN) params: Params,
    private readonly cls: ClsService,
  ) {
    super(params);
  }

  assign(fields: Bindings) {
    const logger = this.cls.get<Logger | undefined>('logger');
    if (logger) {
      this.cls.set('logger', logger.child(fields));
      return;
    }

    try {
      super.assign(fields);
    } catch (error) {
      this.warn(error);
    }
  }

  get logger(): Logger {
    const logger = this.cls.get<Logger | undefined>('logger');
    if (logger) {
      return logger;
    }

    return super.logger;
  }
}

// logger.module.ts
import { Global, Module } from '@nestjs/common';
import { ClsModule } from 'nestjs-cls';
import { LoggerConfig } from './logger.config';
import { LoggerService } from './logger.service';

@Global()
@Module({
  providers: [LoggerService],
  exports: [LoggerService],
  imports: [
    ClsModule.forRoot({
      global: true,
    }),
    LoggerConfig,
  ],
})
export class LoggerModule {}

// logger.config.ts
import { ConfigModule, ConfigService } from '@nestjs/config';
import { type Request, type Response } from 'express';
import { type IncomingMessage } from 'http';
import { LoggerModule } from 'nestjs-pino';
import { v4 as uuidv4 } from 'uuid';

const customReceivedMessage = (req: IncomingMessage) => {
  const { method, url } = req;
  return `[Request] ${method} ${url}`;
};

const customSuccessMessage = (
  req: IncomingMessage,
  res: Response,
  responseTime: number,
) => {
  const { method, url } = req;
  const { statusCode } = res;
  return `[Response] ${method} ${url} - ${statusCode} in ${responseTime}ms`;
};

export const LoggerConfig = LoggerModule.forRootAsync({
  imports: [ConfigModule],
  inject: [ConfigService],
  useFactory: (configService: ConfigService) => {
    // We can do some await here
    return {
      pinoHttp: {
        level: configService.get('LOG_LEVEL', 'debug'),
        autoLogging: true,
        base: null,
        quietReqLogger: true,
        genReqId: (request: Request) =>
          (request.headers['x-correlation-id'] as string | undefined) ??
          uuidv4(),
        messageKey: 'message',
        customReceivedMessage,
        customSuccessMessage,
        transport:
          process.env.NODE_ENV !== 'production' &&
          configService.get('LOG_TARGET', 'CONSOLE') === 'CONSOLE'
            ? {
                target: 'pino-pretty',
                options: {
                  colorize: true,
                  ignore:
                    'reqId,req.headers,req.remoteAddress,req.remotePort,pid,hostname,res.headers',
                  messageKey: 'message',
                },
              }
            : undefined,
      },
    };
  },
});

Then I can use it like that:

export class Command extends CommandRunner {
  constructor(
    private readonly logger: LoggerService,
  ) {
    super();
  }

  @UseCls({
    setup(this: LaunchNangoSyncCommand, cls: ClsService) {
      cls.set('logger', this.logger.logger);
    },
  })
  async run(): Promise<void> {
    this.logger.assign({
      reqId: uuidV4(),
    });
   
     this.logger.info('test');

    }
  }
}

@iamolegga Do you think I can find a way to insert nestjs-cls in your project to be able to do that?