Update logs

app-config.yaml

@@ -28,6 +28,8 @@ logging:
   appServer: info
   database: info
   s3Storage: info
+  middlewares: 'info'
+  policies: 'info'
 
 s3:
   accessKeyId: 'secret'

eslint.config.mjs

@@ -77,6 +77,9 @@ export default [
       'n/no-unsupported-features/es-builtins': ['error', {
         version: '>=22.1.0',
       }],
+      'n/no-unsupported-features/node-builtins': ['error', {
+        version: '>=22.1.0',
+      }],
       '@typescript-eslint/naming-convention': ['error', {
         selector: 'property',
         format: ['camelCase', 'PascalCase'],

src/infrastructure/config/index.ts

@@ -91,6 +91,8 @@ export const LoggingConfig = z.object({
   appServer: LoggingLevel,
   database: LoggingLevel,
   s3Storage: LoggingLevel,
+  middlewares: LoggingLevel,
+  policies: LoggingLevel,
 });
 
 export type LoggingConfig = z.infer<typeof LoggingConfig>;
@@ -161,6 +163,8 @@ const defaultConfig: AppConfig = {
     appServer: 'info',
     database: 'info',
     s3Storage: 'info',
+    middlewares: 'info',
+    policies: 'info',
   },
   database: {
     dsn: 'postgres://user:pass@postgres/codex-notes',

src/infrastructure/logging/index.ts

@@ -2,6 +2,7 @@ import { pino } from 'pino';
 import * as process from 'process';
 import type { LoggingConfig } from '../config/index.js';
 import appConfig from '../config/index.js';
+import { getCurrentReqId } from './reqId.context.js';
 
 const loggerConfig = process.env['NODE_ENV'] === 'production'
   ? {}
@@ -16,11 +17,19 @@ const loggerConfig = process.env['NODE_ENV'] === 'production'
 
 const rootLogger = pino(loggerConfig);
 
+let loggerCache = new Map<keyof LoggingConfig, pino.Logger>();
+
 /**
  * Creates child logger and returns it.
  * @param moduleName - name of the module that is logging
  */
 export function getLogger(moduleName: keyof LoggingConfig): pino.Logger {
+  const cachedLogger = loggerCache.get(moduleName);
+
+  if (cachedLogger) {
+    return cachedLogger;
+  }
+
   const childLogger = rootLogger.child({
     module: moduleName,
   });
@@ -33,9 +42,29 @@ export function getLogger(moduleName: keyof LoggingConfig): pino.Logger {
 
   childLogger.level = logLevel;
 
+  loggerCache.set(moduleName, childLogger);
+
   return childLogger;
 }
 
+/**
+ * Creates a request-scoped logger that includes the request ID
+ * @param moduleName - name of the module that is logging
+ * @returns Logger instance with request ID context
+ */
+export function getRequestLogger(moduleName: keyof LoggingConfig): pino.Logger {
+  const baseLogger = getLogger(moduleName);
+  const reqId = getCurrentReqId();
+
+  if (reqId != null && reqId !== '') {
+    return baseLogger.child({
+      reqId,
+    });
+  }
+
+  return baseLogger;
+}
+
 const logger = getLogger('global');
 
 export default logger;

src/infrastructure/logging/reqId.context.ts

@@ -0,0 +1,24 @@
+import { AsyncLocalStorage } from 'node:async_hooks';
+
+/**
+ * Context for storing reqId within asynchronous operations
+ */
+interface RequestContext {
+  reqId?: string;
+}
+
+/**
+ * AsyncLocalStorage for storing request context
+ * Allows tying database logs to the corresponding request
+ */
+export const requestContextStorage = new AsyncLocalStorage<RequestContext>();
+
+/**
+ * Gets the current reqId from the execution context
+ * @returns reqId or undefined if context is not set
+ */
+export function getCurrentReqId(): string | undefined {
+  const context = requestContextStorage.getStore();
+
+  return context?.reqId;
+}

src/presentation/http/http-api.ts

@@ -9,6 +9,7 @@ import { fastifyOauth2 } from '@fastify/oauth2';
 import fastifySwagger from '@fastify/swagger';
 import fastifySwaggerUI from '@fastify/swagger-ui';
 import addUserIdResolver from '@presentation/http/middlewares/common/userIdResolver.js';
+import addReqIdContext from '@presentation/http/middlewares/common/reqIdContext.js';
 import cookie from '@fastify/cookie';
 import { notFound, forbidden, unauthorized, notAcceptable, domainError } from './decorators/index.js';
 import NoteRouter from '@presentation/http/router/note.js';
@@ -324,7 +325,8 @@ export default class HttpApi implements Api {
       throw new Error('Server is not initialized');
     }
 
-    addUserIdResolver(this.server, domainServices.authService, appServerLogger);
+    addReqIdContext(this.server);
+    addUserIdResolver(this.server, domainServices.authService);
   }
 
   /**

src/presentation/http/middlewares/common/reqIdContext.ts

@@ -0,0 +1,18 @@
+import type { FastifyInstance } from 'fastify';
+import { requestContextStorage } from '@infrastructure/logging/reqId.context.js';
+
+/**
+ * Adds middleware to set reqId context at the beginning of each request
+ * @param server - fastify instance
+ */
+export default function addReqIdContext(server: FastifyInstance): void {
+  /**
+   * Sets reqId context for all asynchronous operations within the request
+   * Uses 'onRequest' hook so context is available in all subsequent hooks and handlers
+   */
+  server.addHook('onRequest', (request, _reply, done) => {
+    requestContextStorage.run({ reqId: request.id }, () => {
+      done();
+    });
+  });
+}

src/presentation/http/middlewares/common/userIdResolver.ts

@@ -1,15 +1,14 @@
 import type { FastifyInstance } from 'fastify';
 import type AuthService from '@domain/service/auth.js';
-import type Logger from '@infrastructure/logging/index.js';
 import { notEmpty } from '@infrastructure/utils/empty.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 
 /**
  * Add middleware for resolve userId from Access Token and add it to request
  * @param server - fastify instance
  * @param authService - auth domain service
- * @param logger - logger instance
  */
-export default function addUserIdResolver(server: FastifyInstance, authService: AuthService, logger: typeof Logger): void {
+export default function addUserIdResolver(server: FastifyInstance, authService: AuthService): void {
   /**
    * Default userId value — null
    */
@@ -19,6 +18,7 @@ export default function addUserIdResolver(server: FastifyInstance, authService:
    * Resolve userId from Access Token on each request
    */
   server.addHook('preHandler', (request, _reply, done) => {
+    const logger = getRequestLogger('middlewares');
     const authorizationHeader = request.headers.authorization;
 
     if (notEmpty(authorizationHeader)) {

src/presentation/http/middlewares/note/useNoteResolver.ts

@@ -3,7 +3,7 @@ import type NoteService from '@domain/service/note.js';
 import { notEmpty } from '@infrastructure/utils/empty.js';
 import { StatusCodes } from 'http-status-codes';
 import hasProperty from '@infrastructure/utils/hasProperty.js';
-import { getLogger } from '@infrastructure/logging/index.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 import type { Note, NotePublicId } from '@domain/entities/note.js';
 
 /**
@@ -18,11 +18,6 @@ export default function useNoteResolver(noteService: NoteService): {
    */
   noteResolver: preHandlerHookHandler;
 } {
-  /**
-   * Get logger instance
-   */
-  const logger = getLogger('appServer');
-
   /**
    * Search for Note by public id in passed payload and resolves a note by it
    * @param requestData - fastify request data. Can be query, params or body
@@ -40,6 +35,7 @@ export default function useNoteResolver(noteService: NoteService): {
 
   return {
     noteResolver: async function noteIdResolver(request, reply) {
+      const logger = getRequestLogger('middlewares');
       let note: Note | undefined;
 
       let statusCode = StatusCodes.NOT_ACCEPTABLE;

src/presentation/http/middlewares/noteSettings/useMemberRoleResolver.ts

@@ -1,5 +1,5 @@
 import type { preHandlerHookHandler } from 'fastify';
-import { getLogger } from '@infrastructure/logging/index.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 import type NoteSettingsService from '@domain/service/noteSettings.js';
 import type { MemberRole } from '@domain/entities/team.js';
 import { isEmpty } from '@infrastructure/utils/empty.js';
@@ -16,13 +16,9 @@ export default function useMemberRoleResolver(noteSettingsService: NoteSettingsS
    */
   memberRoleResolver: preHandlerHookHandler;
 } {
-  /**
-   * Get logger instance
-   */
-  const logger = getLogger('appServer');
-
   return {
     memberRoleResolver: async function memberRoleResolver(request, reply) {
+      const logger = getRequestLogger('middlewares');
       /** If MemberRole equals null, it means that user is not in the team or is not authenticated */
       let memberRole: MemberRole | undefined;
 
@@ -42,7 +38,11 @@ export default function useMemberRoleResolver(noteSettingsService: NoteSettingsS
           request.memberRole = memberRole;
         }
       } catch (error) {
-        logger.error('Can not resolve Member role by note [id = ${request.note.id}] and user [id = ${request.userId}]');
+        if (request.note != null && request.userId != null) {
+          logger.error(`Cannot resolve Member role by note [id = ${request.note.id}] and user [id = ${request.userId}]`);
+        } else {
+          logger.error('Cannot resolve Member role - note or user ID not available');
+        }
         logger.error(error);
 
         await reply.notAcceptable('Team member not found');

src/presentation/http/middlewares/noteSettings/useNoteSettingsResolver.ts

@@ -1,5 +1,5 @@
 import type { preHandlerHookHandler } from 'fastify';
-import { getLogger } from '@infrastructure/logging/index.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 import type NoteSettingsService from '@domain/service/noteSettings.js';
 import type NoteSettings from '@domain/entities/noteSettings.js';
 
@@ -15,13 +15,9 @@ export default function useNoteSettingsResolver(noteSettingsService: NoteSetting
    */
   noteSettingsResolver: preHandlerHookHandler;
 } {
-  /**
-   * Get logger instance
-   */
-  const logger = getLogger('appServer');
-
   return {
     noteSettingsResolver: async function noteSettingsResolver(request, reply) {
+      const logger = getRequestLogger('middlewares');
       let noteSettings: NoteSettings | null;
 
       try {

src/presentation/http/policies/authRequired.ts

@@ -1,15 +1,21 @@
 import type { PolicyContext } from '@presentation/http/types/PolicyContext.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 
 /**
  * Policy to enforce user to be logged in
  * @param context - Context object, containing Fatify request, Fastify reply and domain services
  */
 export default async function authRequired(context: PolicyContext): Promise<void> {
   const { request, reply } = context;
+  const logger = getRequestLogger('policies');
 
   const { userId } = request;
 
   if (userId === null) {
+    logger.warn('User is not authenticated');
+
     return await reply.unauthorized();
   }
+
+  logger.debug('User authenticated');
 }

src/presentation/http/policies/notePublicOrUserInTeam.ts

@@ -1,20 +1,24 @@
 import { isEmpty } from '@infrastructure/utils/empty.js';
 import { notEmpty } from '@infrastructure/utils/empty.js';
 import type { PolicyContext } from '@presentation/http/types/PolicyContext.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 
 /**
  * Policy to check does user have permission to access note
  * @param context - Context, object containing Fatify request, Fastify reply and domain services
  */
 export default async function notePublicOrUserInTeam(context: PolicyContext): Promise<void> {
   const { request, reply, domainServices } = context;
+  const logger = getRequestLogger('policies');
 
   const { userId } = request;
 
   /**
    * If note or noteSettings not resolved, we can't check permissions
    */
   if (isEmpty(request.note) || isEmpty(request.noteSettings)) {
+    logger.warn('Note or note settings not found');
+
     return await reply.notAcceptable('Note not found');
   };
 
@@ -36,10 +40,15 @@ export default async function notePublicOrUserInTeam(context: PolicyContext): Pr
   if (isPublic === false) {
     /** If user is unathorized we return 401 unauthorized */
     if (isEmpty(userId)) {
+      logger.warn('Unauthorized user trying to access private note');
+
       return await reply.unauthorized();
     /** If user is authorized, but is not in the team, we return 403 forbidden */
     } else if (isEmpty(memberRole)) {
+      logger.warn('User not in team for private note');
+
       return await reply.forbidden();
     }
   }
+  logger.debug('Note access check completed successfully');
 }

src/presentation/http/policies/userCanEdit.ts

@@ -1,27 +1,33 @@
 import { isEmpty } from '@infrastructure/utils/empty.js';
 import { MemberRole } from '@domain/entities/team.js';
 import type { PolicyContext } from '@presentation/http/types/PolicyContext.js';
+import { getRequestLogger } from '@infrastructure/logging/index.js';
 
 /**
  * Policy to check whether a user has permission to edit the note
  * @param context - Context object, containing Fatify request, Fastify reply and domain services
  */
 export default async function userCanEdit(context: PolicyContext): Promise<void> {
   const { request, reply, domainServices } = context;
+  const logger = getRequestLogger('policies');
 
   const { userId } = request;
 
   /**
    * If user is not authorized, we can't check his permissions
    */
   if (isEmpty(userId)) {
+    logger.warn('User not authenticated for edit access');
+
     return await reply.unauthorized();
   };
 
   /**
    * If note is not resolved, we can't check permissions
    */
   if (isEmpty(request.note)) {
+    logger.warn('Note not found for edit permission check');
+
     return await reply.notAcceptable('Note not found');
   };
 
@@ -32,6 +38,10 @@ export default async function userCanEdit(context: PolicyContext): Promise<void>
    * he doesn't have permission to edit the note
    */
   if (memberRole !== MemberRole.Write) {
+    logger.warn('User does not have write permission for note');
+
     return await reply.forbidden();
   }
+
+  logger.debug('User edit permission check completed successfully');
 }