[_]: refactor/enhance error logging with request IDs

src/services/drive/drive-item.service.ts

@@ -1,7 +1,7 @@
 import { DriveItemRepository } from '../database/drive-item/drive-item.repository';
 import { DriveFileItem, DriveFolderItem } from '../../types/drive.types';
-import { NotFoundError } from '../../utils/errors.utils';
-import { logger } from '../../utils/logger.utils';
+import { ErrorUtils, NotFoundError } from '../../utils/errors.utils';
+import { webdavLogger } from '../../utils/logger.utils';
 import { DriveFileService } from './drive-file.service';
 import { DriveFolderService } from './drive-folder.service';
 import { DriveItemBD } from '../database/drive-item/drive-item.domain';
@@ -22,8 +22,11 @@ export class DriveItemService {
         },
       ]);
       return item;
-    } catch {
-      logger.warn('File metadata by uuid failed, falling back to path lookup', { path, uuid: cached.uuid });
+    } catch (error) {
+      webdavLogger.warn(ErrorUtils.withRequestId('File metadata by uuid failed, falling back to path lookup', error), {
+        path,
+        uuid: cached.uuid,
+      });
       await DriveItemRepository.instance.delete([cached.uuid]);
     }
   };
@@ -44,8 +47,11 @@ export class DriveItemService {
         },
       ]);
       return item;
-    } catch {
-      logger.warn('Folder metadata by uuid failed, falling back to path lookup', { path, uuid: cached.uuid });
+    } catch (error) {
+      webdavLogger.warn(
+        ErrorUtils.withRequestId('Folder metadata by uuid failed, falling back to path lookup', error),
+        { path, uuid: cached.uuid },
+      );
       await DriveItemRepository.instance.delete([cached.uuid]);
     }
   };
@@ -70,7 +76,8 @@ export class DriveItemService {
         },
       ]);
       return item;
-    } catch {
+    } catch (error) {
+      ErrorUtils.logIfUnexpected(webdavLogger, 'File lookup by path failed', error, { path });
       throw new NotFoundError(`File not found at path: ${path}`);
     }
   };
@@ -95,7 +102,8 @@ export class DriveItemService {
         },
       ]);
       return item;
-    } catch {
+    } catch (error) {
+      ErrorUtils.logIfUnexpected(webdavLogger, 'Folder lookup by path failed', error, { path });
       throw new NotFoundError(`Folder not found at path: ${path}`);
     }
   };

src/utils/cli.utils.ts

@@ -261,12 +261,7 @@ export class CLIUtils {
     debugMode?: boolean;
   }) => {
     let message = '';
-    let requestId: string | undefined;
-    if ('requestId' in error) {
-      requestId = error.requestId;
-    } else if ('xRequestId' in error) {
-      requestId = error.xRequestId;
-    }
+    const requestId = ErrorUtils.getRequestId(error);
 
     if ('message' in error && typeof error.message === 'string' && error.message?.trim?.().length > 0) {
       message = error.message;
@@ -304,7 +299,7 @@ export class CLIUtils {
       if (debugMode) {
         ErrorUtils.report(error);
       }
-      CLIUtils.error(logReporter, message + (requestId ? ` (requestId: ${requestId})` : ''));
+      CLIUtils.error(logReporter, ErrorUtils.withRequestId(message, error));
     }
   };
 

src/utils/errors.utils.ts

@@ -1,3 +1,4 @@
+import { Logger } from 'winston';
 import { logger } from './logger.utils';
 
 export class ErrorUtils {
@@ -11,10 +12,14 @@ export class ErrorUtils {
   static readonly report = (error: unknown, props: Record<string, unknown> = {}) => {
     if (this.isError(error)) {
       logger.error(
-        `[REPORTED_ERROR]: ${error.message}\nProperties => ${JSON.stringify(props, null, 2)}\nStack => ${error.stack}`,
+        `[REPORTED_ERROR]: ${this.withRequestId(error.message, error)}\n` +
+          `Properties => ${JSON.stringify(props, null, 2)}\nStack => ${error.stack}`,
       );
     } else {
-      logger.error(`[REPORTED_ERROR]: ${JSON.stringify(error)}\nProperties => ${JSON.stringify(props, null, 2)}\n`);
+      logger.error(
+        `[REPORTED_ERROR]: ${this.withRequestId(JSON.stringify(error), error)}\n` +
+          `Properties => ${JSON.stringify(props, null, 2)}\n`,
+      );
     }
   };
 
@@ -28,6 +33,40 @@ export class ErrorUtils {
   static readonly isFileNotFoundError = (error: unknown): error is NodeJS.ErrnoException => {
     return this.isError(error) && 'code' in error && error.code === 'ENOENT';
   };
+
+  static readonly getRequestId = (error: unknown): string | undefined => {
+    if (typeof error !== 'object' || error === null) return undefined;
+
+    const { requestId, xRequestId, data } = error as { requestId?: unknown; xRequestId?: unknown; data?: unknown };
+    const bodyRequestId =
+      typeof data === 'object' && data !== null ? (data as { requestId?: unknown }).requestId : undefined;
+
+    return [requestId, xRequestId, bodyRequestId].find(
+      (candidate): candidate is string => typeof candidate === 'string' && candidate.length > 0,
+    );
+  };
+
+  static readonly withRequestId = (message: string, error: unknown): string => {
+    const requestId = this.getRequestId(error);
+    return requestId ? `${message} (requestId: ${requestId})` : message;
+  };
+
+  static readonly isNotFoundError = (error: unknown): boolean => {
+    if (typeof error !== 'object' || error === null) return false;
+    const { status, statusCode } = error as { status?: unknown; statusCode?: unknown };
+    return status === 404 || statusCode === 404;
+  };
+
+  static readonly logIfUnexpected = (
+    log: Logger,
+    message: string,
+    error: unknown,
+    meta?: Record<string, unknown>,
+  ) => {
+    if (this.isNotFoundError(error)) return;
+    const errorMessage = this.isError(error) ? error.message : String(error);
+    log.warn(this.withRequestId(`${message}: ${errorMessage}`, error), meta);
+  };
 }
 
 export class ConflictError extends Error {

src/webdav/handlers/PUT.handler.ts

@@ -3,7 +3,7 @@ import { DriveFileService } from '../../services/drive/drive-file.service';
 import { DriveItemRepository } from '../../services/database/drive-item/drive-item.repository';
 import { AuthService } from '../../services/auth.service';
 import { WebDavMethodHandler } from '../../types/webdav.types';
-import { ConflictError } from '../../utils/errors.utils';
+import { ConflictError, ErrorUtils } from '../../utils/errors.utils';
 import { WebDavUtils } from '../../utils/webdav.utils';
 import { webdavLogger } from '../../utils/logger.utils';
 import { EncryptionVersion } from '@internxt/sdk/dist/drive/storage/types';
@@ -114,9 +114,12 @@ export class PUTRequestHandler implements WebDavMethodHandler {
         file = await DriveFileService.instance.replaceFile(driveFileItem.uuid, filePayload);
       } catch (error) {
         webdavLogger.warn(
-          `[PUT] File replace failed for '${resource.url}', falling back to delete and create: ${
-            error instanceof Error ? error.message : String(error)
-          }`,
+          ErrorUtils.withRequestId(
+            `[PUT] File replace failed for '${resource.url}', falling back to delete and create: ${
+              error instanceof Error ? error.message : String(error)
+            }`,
+            error,
+          ),
         );
         await WebDavUtils.deleteOrTrashItem(driveFileItem);
         file = await DriveFileService.instance.createFile(filePayload);

src/webdav/index.ts

@@ -6,6 +6,7 @@ import { AuthService } from '../services/auth.service';
 import { webdavLogger } from '../utils/logger.utils';
 import { SdkManager } from '../services/sdk-manager.service';
 import { DatabaseService } from '../services/database/database.service';
+import { ErrorUtils } from '../utils/errors.utils';
 
 dotenv.config({ quiet: true });
 
@@ -23,11 +24,11 @@ const init = async () => {
   new WebDavServer(express())
     .start()
     .then()
-    .catch((err) => webdavLogger.error('Failed to start WebDAV server', err));
+    .catch((err) => webdavLogger.error(ErrorUtils.withRequestId('Failed to start WebDAV server', err), err));
 };
 
 process.on('uncaughtException', (err) => {
-  webdavLogger.error('Unhandled exception:', err);
+  webdavLogger.error(ErrorUtils.withRequestId('Unhandled exception:', err), err);
 });
 
 init();

src/webdav/middewares/auth.middleware.ts

@@ -26,10 +26,11 @@ export const AuthMiddleware = (): RequestHandler => {
         let message = 'Authentication required to access this resource.';
         if (ErrorUtils.isError(error)) {
           message = error.message;
+          const logMessage = ErrorUtils.withRequestId(message, error);
           if (error.stack) {
-            webdavLogger.error(`Error from AuthMiddleware: ${message}\nStack: ${error.stack}`);
+            webdavLogger.error(`Error from AuthMiddleware: ${logMessage}\nStack: ${error.stack}`);
           } else {
-            webdavLogger.error(`Error from AuthMiddleware: ${message}`);
+            webdavLogger.error(`Error from AuthMiddleware: ${logMessage}`);
           }
         }
         const errorBodyXML = XMLUtils.toWebDavXML(

src/webdav/middewares/errors.middleware.ts

@@ -41,10 +41,14 @@ export const ErrorHandlingMiddleware: ErrorRequestHandler = (err, req, res, _) =
     message += ` [${detail}]`;
   }
 
+  const logMessage = ErrorUtils.withRequestId(message, err);
+
   if (ErrorUtils.isError(err) && err.stack) {
-    webdavLogger.error(`[ERROR MIDDLEWARE] [${req.method.toUpperCase()} - ${req.url}] ${message}\nStack: ${err.stack}`);
+    webdavLogger.error(
+      `[ERROR MIDDLEWARE] [${req.method.toUpperCase()} - ${req.url}] ${logMessage}\nStack: ${err.stack}`,
+    );
   } else {
-    webdavLogger.error(`[ERROR MIDDLEWARE] [${req.method.toUpperCase()} - ${req.url}] ${message}`);
+    webdavLogger.error(`[ERROR MIDDLEWARE] [${req.method.toUpperCase()} - ${req.url}] ${logMessage}`);
   }
 
   const errorBodyXML = XMLUtils.toWebDavXML(

test/services/drive/drive-item.service.test.ts

@@ -6,11 +6,44 @@ import { DriveFileService } from '../../../src/services/drive/drive-file.service
 import { DriveFolderService } from '../../../src/services/drive/drive-folder.service';
 import { newFileItem, newFolderItem } from '../../fixtures/drive.fixture';
 import { NotFoundError } from '../../../src/utils/errors.utils';
+import { webdavLogger } from '../../../src/utils/logger.utils';
+import { AxiosResponseError } from '@internxt/sdk/dist/shared/types/errors';
+
+const createApiError = (status: number, requestId: string) =>
+  new AxiosResponseError(`Request failed with status code ${status}`, 'GET files/meta', {
+    status,
+    data: {},
+    headers: { 'x-request-id': requestId },
+    statusText: '',
+    // @ts-expect-error partial AxiosResponse fixture, only the fields read by AxiosResponseError are needed
+    config: {},
+  });
 
 describe('Drive Item Service', () => {
   const sut = DriveItemService.instance;
 
   describe('getting a file by path', () => {
+    test('when the path lookup fails with an unexpected API error, then it is logged with its request id', async () => {
+      const path = '/test/file.txt';
+      vi.spyOn(DriveItemRepository.instance, 'getByPath').mockResolvedValue(undefined);
+      vi.spyOn(DriveFileService.instance, 'getFileMetadataByPath').mockRejectedValue(createApiError(500, 'req-123'));
+
+      await expect(sut.getFileByPath(path)).rejects.toThrow('File not found at path');
+      expect(webdavLogger.warn).toHaveBeenCalledWith(
+        'File lookup by path failed: Request failed with status code 500 (requestId: req-123)',
+        { path },
+      );
+    });
+
+    test('when the path lookup fails because the file does not exist, then nothing is logged', async () => {
+      const path = '/test/file.txt';
+      vi.spyOn(DriveItemRepository.instance, 'getByPath').mockResolvedValue(undefined);
+      vi.spyOn(DriveFileService.instance, 'getFileMetadataByPath').mockRejectedValue(createApiError(404, 'req-404'));
+
+      await expect(sut.getFileByPath(path)).rejects.toThrow('File not found at path');
+      expect(webdavLogger.warn).not.toHaveBeenCalled();
+    });
+
     test('when the file is in cache and the API responds, then the cached file is returned', async () => {
       const path = '/test/file.txt';
       const cachedItem = new DriveItemBD({

test/utils/errors.utils.test.ts

@@ -1,6 +1,7 @@
 import { describe, expect, test } from 'vitest';
 import { ErrorUtils } from '../../src/utils/errors.utils';
 import { logger } from '../../src/utils/logger.utils';
+import { AxiosResponseError } from '@internxt/sdk/dist/shared/types/errors';
 
 describe('Errors Utils', () => {
   test('when an error is reported, then it is logged with its details', () => {
@@ -87,4 +88,65 @@ describe('Errors Utils', () => {
       expect(ErrorUtils.isFileNotFoundError(123)).toBe(false);
     });
   });
+
+  describe('getRequestId', () => {
+    test('when a Drive API error carries the x-request-id header, then its request id is returned', () => {
+      const error = new AxiosResponseError('Request failed with status code 500', 'PUT /files/uuid', {
+        status: 500,
+        data: {},
+        headers: { 'x-request-id': 'req-123' },
+        statusText: 'Internal Server Error',
+        // @ts-expect-error partial AxiosResponse fixture, only the fields read by AxiosResponseError are needed
+        config: {},
+      });
+
+      expect(ErrorUtils.getRequestId(error)).toBe('req-123');
+    });
+
+    test('when a Drive API error only carries the request id in its response body, then it is returned', () => {
+      const error = new AxiosResponseError('Request failed with status code 500', 'PUT /files/uuid', {
+        status: 500,
+        data: { statusCode: 500, message: 'Internal Server Error', requestId: 'req-789' },
+        headers: {},
+        statusText: 'Internal Server Error',
+        // @ts-expect-error partial AxiosResponse fixture, only the fields read by AxiosResponseError are needed
+        config: {},
+      });
+
+      expect(ErrorUtils.getRequestId(error)).toBe('req-789');
+    });
+
+    test('when an error carries a requestId property, then it is returned', () => {
+      const error = Object.assign(new Error('Something failed'), { requestId: 'req-456' });
+
+      expect(ErrorUtils.getRequestId(error)).toBe('req-456');
+    });
+
+    test('when an error has no request id, then nothing is returned', () => {
+      expect(ErrorUtils.getRequestId(new Error('Something failed'))).toBeUndefined();
+      expect(ErrorUtils.getRequestId({ xRequestId: '' })).toBeUndefined();
+      expect(ErrorUtils.getRequestId('string error')).toBeUndefined();
+      expect(ErrorUtils.getRequestId(null)).toBeUndefined();
+    });
+  });
+
+  describe('withRequestId', () => {
+    test('when the error has a request id, then it is appended to the message', () => {
+      const error = Object.assign(new Error('Something failed'), { requestId: 'req-123' });
+
+      expect(ErrorUtils.withRequestId('Something failed', error)).toBe('Something failed (requestId: req-123)');
+    });
+
+    test('when the error has no request id, then the message is unchanged', () => {
+      expect(ErrorUtils.withRequestId('Something failed', new Error('Something failed'))).toBe('Something failed');
+    });
+  });
+
+  test('when a reported error has a request id, then it is logged with it', () => {
+    const error = Object.assign(new Error('Test Error'), { xRequestId: 'req-123' });
+
+    ErrorUtils.report(error);
+
+    expect(logger.error).toHaveBeenCalledWith(expect.stringContaining('[REPORTED_ERROR]: Test Error (requestId: req-123)'));
+  });
 });