Logsage

Logsage Logger represents a pioneering logging solution specifically tailored for NestJS applications. It marks a significant milestone as the first logger package designed for distributed logging within the NestJS ecosystem, creatively engineered atop both Winston and Pino. This unique fusion offers developers unmatched flexibility, allowing seamless switching between Pino and Winston as the underlying logging mechanism, all while fine-tuning logging behavior to individual preferences.

Inspired by Java's Mapped Diagnostic Context (MDC) pattern, Logsage Logger revolutionizes distributed tracing within NestJS applications. Similar to how the MDC pattern empowers Java developers with comprehensive logging capabilities, our Logger package extends similar prowess to the Node.js realm, facilitating efficient management of contextual information across asynchronous operations.

Mapped Diagnostic Context (MDC) in JAVA

The Mapped Diagnostic Context (MDC) pattern, commonly employed in Java logging frameworks like Logback and Log4j, enriches log messages with contextual information specific to the current execution context. In Java, MDC utilizes thread-local variables to store and propagate this context throughout the application's lifecycle.

However, JavaScript, including Node.js and NestJS, lacks native support for thread-local variables. Instead, asynchronous context management libraries like SpeedCache can be utilized to implement a similar mechanism.

SpeedCache, a custom library used in building Logsage, facilitates asynchronous context management within Node.js applications. It allows developers to store and retrieve contextual information across asynchronous function calls without the need for explicit passing of data as function arguments.

In the context of NestJS, the LoggerMiddleware showcased earlier leverages SpeedCache to manage the trace ID associated with each incoming request. This middleware ensures that the trace ID is extracted from the request headers (x-trace-id) or generated if absent. The trace ID is then stored in the SpeedCache instance, making it accessible throughout the request lifecycle. Subsequently, this trace ID is utilized in log messages, enabling distributed tracing and contextual logging within the NestJS application.

In summary, while MDC is commonly used in Java logging frameworks, a similar functionality can be achieved in JavaScript and NestJS applications using asynchronous context management libraries like SpeedCache. The LoggerMiddleware provided demonstrates how seamlessly integrate such functionality for distributed tracing and contextual logging within NestJS applications.

Components:

• Logger: The logging framework responsible for emitting log messages.
• MDC: A thread-local map provided by the logging framework to store contextual information.

Architecture Design:

                +---------------------------------------+
                |                                       |
                |            Application Code           |
                |                                       |
                +---------------------------------------+
                                  |
                                  |
                                  v
                +---------------------------------------+
                |                                       |
                |   Logger (e.g., Logback, Log4j)       |
                |                                       |
                +---------------------------------------+
                                  |
                                  |
                                  v
                +---------------------------------------+
                |                                       |
                |            Mapped Diagnostic          |
                |               Context (MDC)            |
                |                                       |
                +---------------------------------------+

Workflow:

• Application Code: The application code emits log messages using the logger provided by the logging framework.
• Logger: The logging framework intercepts log messages generated by the application code. Before emitting a log message, it checks the MDC for any contextual information associated with the current thread.
• Mapped Diagnostic Context (MDC): The MDC is a thread-local map provided by the logging framework. It allows developers to store and retrieve contextual information specific to the current thread. Before logging a message, the logging framework retrieves contextual information from the MDC and includes it in the log message.

Features of LogSage

• Seamless integration with NestJS applications.
• Option to choose between Pino and Winston as the logging library.
• Easy configuration management for fine-tuning logging behavior.
• Supports various configuration options such as log levels, output formats, and log destinations.
• Enhanced debugging capabilities for gaining insights into application behavior and performance.
• Distributed Logging: The Logger package enables distributed logging, allowing developers to efficiently manage contextual information across asynchronous operations within NestJS applications.
• MessagePattern Integration: Logsage Logger seamlessly integrates with NestJS's MessagePattern decorator, facilitating the logging of messages exchanged between microservices.
• PayloadWithTraceId Support: With support for PayloadWithTraceId, Logsage Logger enhances traceability by associating unique trace IDs with log messages.
• Automatic TraceID Injection: Logsage Logger now seamlessly injects TraceID into log messages exchanged between microservices using Kafka, RabbitMQ, or NestJS's MessagePattern.

Trace ID Management

• Trace ID Injection: The LoggerMiddleware seamlessly manages trace IDs within incoming requests. When a request is received, the middleware checks for the presence of a trace ID (x-trace-id header, body, query params). If a trace ID is found, it is utilized throughout the request lifecycle. If not, the middleware generates a unique trace ID and attaches it to the request. This automatic handling ensures that each request within your NestJS application is associated with a trace ID, facilitating distributed tracing.

• Facilitating Distributed Tracing: Trace IDs play a crucial role in distributed tracing by correlating and tracking requests as they traverse various services within a distributed system. With the LoggerMiddleware in place, each log entry associated with a request includes the corresponding trace ID. This enables end-to-end visibility into request flows, allowing developers to trace the path of a request across multiple microservices and gain insights into performance bottlenecks or errors.

• Enhanced Observability: By incorporating trace IDs into log entries, the LoggerMiddleware enhances the observability of your application. Developers can utilize trace IDs to trace the journey of individual requests, troubleshoot issues, and analyze the behavior of the application under different scenarios. This level of visibility empowers teams to identify and address issues promptly, leading to improved reliability and performance.

• Interoperability: The use of standardized trace IDs (t-trace-id) ensures interoperability with existing distributed tracing systems and tools. These trace IDs can be propagated across service boundaries, allowing seamless integration with external tracing solutions such as Jaeger, Zipkin, or OpenTelemetry. This interoperability enables organizations to leverage their preferred tracing infrastructure while still benefiting from the logging capabilities provided by the LoggerMiddleware.

Installation

npm install logsage

Usage

AppModule Configuration

This configuration sets up logging in the AppModule:

Imports: The LoggerModule is imported, enabling logging features within the application.

Providers:

• AppService is provided as a singleton, serving as a service layer.
• LoggerService is provided using a factory function to initialize a Winston logger (LoggerType.WINSTON).

Controllers: The AppController is declared, handling incoming HTTP requests.

import { MiddlewareConsumer, Module } from '@nestjs/common';
import { AppController } from './app.controller';
import { AppService } from './app.service';
import {
  LoggerMiddleware,
  LoggerModule,
  LoggerService,
  LoggerType,
} from 'logsage';

@Module({
  imports: [LoggerModule],
  controllers: [AppController],
  providers: [
    AppService,
    {
      provide: LoggerService,
      useFactory: () => {
        return new LoggerService(LoggerType.PINO);
      },
    },
  ],
})
export class AppModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(LoggerMiddleware).forRoutes('*');
  }
}

Service Injection with LoggerService

In the AppController, the LoggerService is injected as a dependency alongside AppService. This setup leverages the logger initialized in the AppModule configuration.

import { Controller, Get, Req } from '@nestjs/common';
import { AppService } from './app.service';
import { LoggerService, TraceIdHandler } from 'logsage';
import { Request } from 'express';

@Controller()
export class AppController {
  constructor(
    private readonly appService: AppService,
    private readonly logger: LoggerService,
  ) {}

  @Get()
  getHello(@Req() req: Request) {
    const traceId = req.headers[TraceIdHandler.getTraceIdField()];
    this.logger.info('Hello from AppController');
    return this.appService.getHello({ traceId: traceId as string });
  }
}

Usage in Distributed System with Logsage Logger

In a distributed system architecture, communication between microservices often occurs through message brokers like Kafka or RabbitMQ. Logsage Logger enhances traceability within this ecosystem by automatically injecting TraceID into log messages, enabling seamless correlation of log events across services.

Producing a Message

To produce a message with Logsage Logger, follow these steps:

import { Injectable } from '@nestjs/common';
import { ProducerService } from './kafka/producer.service';
import { LoggerService } from 'logsage';

@Injectable()
export class AppService {
  constructor(
    private readonly producerService: ProducerService,
    private readonly logger: LoggerService,
  ) {}

  async getHello({ traceId }: { traceId: string }) {
    this.logger.info('Hello from AppService ');
    await this.producerService.produce('test', {
      value: JSON.stringify({ traceId }),
    });
    return { traceId };
  }
}

In this example, the AppService logs a message using Logsage Logger (this.logger.info) and then produces a message to the Kafka topic 'test'. The TraceID is automatically injected into the log message, ensuring traceability.

Consuming a Message

When consuming a message within a NestJS controller, Logsage Logger facilitates easy TraceID injection into log messages:

Note: Instead of using the regular Payload from @nestjs/microservices, PayloadWithTraceId from Logsage Logger is utilized, ensuring automatic TraceID injection into log messages.

import { Controller } from '@nestjs/common';
import { AppService } from './app.service';
import { MessagePattern, Payload } from '@nestjs/microservices';
import { LoggerService, PayloadWithTraceId } from 'logsage';

@Controller()
export class AppController {
  constructor(
    private readonly appService: AppService,
    private readonly logger: LoggerService,
  ) {}

  @MessagePattern('test')
  getHello(@PayloadWithTraceId() message) {
    this.logger.info('Hello from AppController ', { message });
    return this.appService.getHello({ message });
  }
}

In this code snippet, the AppController receives a message from Kafka with the pattern 'test'. Logsage Logger automatically injects the TraceID associated with the message, allowing seamless correlation of log events within the distributed system.

With Logsage Logger, tracing and debugging in distributed systems become more efficient and streamlined, enhancing developers' ability to monitor and troubleshoot microservices architectures.

Request Headers Example

{
  host: 'localhost:1337',
  connection: 'keep-alive',
  'cache-control': 'max-age=0',
  'sec-ch-ua': '"Google Chrome";v="123", "Not:A-Brand";v="8", "Chromium";v="123"',
  'sec-ch-ua-mobile': '?0',
  'sec-ch-ua-platform': '"macOS"',
  'upgrade-insecure-requests': '1',
  'user-agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36',
  accept: 'text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7',
  'sec-fetch-site': 'none',
  'sec-fetch-mode': 'navigate',
  'sec-fetch-user': '?1',
  'sec-fetch-dest': 'document',
  'accept-encoding': 'gzip, deflate, br, zstd',
  'accept-language': 'en-GB,en-US;q=0.9,en;q=0.8',
  'if-none-match': 'W/"c-Lve95gjOVATpfV8EL5X4nxwjKHE"',
  'x-trace-id': '5e58338c-919f-42ea-89bc-78144d365d10'
}
[ 2024-03-20T22:19:08 ] INFO: [5e58338c-919f-42ea-89bc-78144d365d10] : {"message":"Hello from Controller!"}
[ 2024-03-20T22:19:08 ] INFO: [5e58338c-919f-42ea-89bc-78144d365d10] : {"message":"Hello from Service!"}

Logs Output:

[ 2024-03-20T22:19:08 ] INFO: [5e58338c-919f-42ea-89bc-78144d365d10] : {"message":"Hello from Controller!"}
[ 2024-03-20T22:19:08 ] INFO: [5e58338c-919f-42ea-89bc-78144d365d10] : {"message":"Hello from Service!"}

Log Output Breakdown

| Part | Description | Example | | --------------- | --------------------------------------------------------- | ---------------------------------------- | | Timestamp | Timestamp indicating when the log entry was generated. | [ 2024-03-20T22:19:08 ] | | Log Level | Severity of the log message. | INFO | | Trace ID | Unique identifier associated with the log entry. | [5e58338c-919f-42ea-89bc-78144d365d10] | | Separator | Character separating the trace ID and the log message. | : | | Log Message | Details about the logged event, typically in JSON format. | {"message":"Hello from Controller!"} |

Setting up TraceIdHandler

To set a different traceId field for the header or body, you can use the TraceIdHandler class provided by the logsage package. Here's how you can do it:

import { NestFactory } from '@nestjs/core';
import { AppModule } from './app.module';
import { TraceIdHandler } from 'logsage';

async function bootstrap() {
  const app = await NestFactory.create(AppModule);
  
  // Set a new traceId field
  TraceIdHandler.setTraceId('callId');

  await app.listen(3000);
}
bootstrap();

Getting TraceId in Controller

Once you've set up the TraceIdHandler, you can retrieve the traceId using the getTraceIdField method from the TraceIdHandler class. Here's an example of how to use it in a controller:

import { Controller, Post, Req } from '@nestjs/common';
import { AppService } from './app.service';
import { LoggerService, TraceIdHandler } from 'logsage';
import { Request } from 'express';

@Controller()
export class AppController {
  constructor(
    private readonly appService: AppService,
    private readonly logger: LoggerService,
  ) {}

  @Post()
  getHello(@Req() req: Request) {
    // Get the traceId from the request headers using TraceIdHandler
    const traceId = req.headers[TraceIdHandler.getTraceIdField()];
    this.logger.info('Hello from AppController');    
    return this.appService.getHello({ traceId: traceId as string });
  }
}

This setup ensures that tracing information is seamlessly injected into incoming requests, facilitating distributed tracing across your NestJS application. By utilizing the LoggerMiddleware, trace IDs are automatically managed, either by extracting them from the incoming requests' headers (x-trace-id) or generating unique IDs if not provided.

With the integration of the LoggerMiddleware, you can effectively monitor request flows and diagnose performance issues, ultimately enhancing the observability of your application. This allows for comprehensive tracing of request paths, enabling deeper insights into the behavior and performance of your services.

Components:

• LoggerMiddleware: Middleware responsible for managing the trace ID and logging requests.
• LoggerService: Service responsible for configuring and interacting with the underlying logging library (Pino or Winston).
• In-Memory TraceId Database: Developed to maintain traceId field across asynchronous operations within the application, ensuring consistent context management.

Architecture

                        +-------------------+
                        |                   |
                        |   Request Flow    |
                        |                   |
                        +-------------------+
                                  |
                                  |
                                  v
                        +-------------------+
                        |                   |
                        | LoggerMiddleware  |
                        |                   |
                        +-------------------+
                                  |
                                  v
                        +-------------------+
                        |                   |
                        |    LoggerService  |
                        |                   |
                        +-------------------+
                                  |
                                  v
                        +-------------------+
                        |                   |
                        |       In          |
                        |    Memory DB      |
                        |                   |
                        +-------------------+

This architecture design provides a foundation for implementing robust logging and distributed tracing capabilities within a NestJS application, enhancing observability and facilitating efficient debugging and performance analysis.

Contributing

If you have suggestions for improvements, bug reports, or other contributions, please feel free to open an issue or create a pull request.

License

This project is licensed under the MIT License.