Repository: nestjs/nest
Pull request #10531 (2022-11-07 21:40:16)

fix(common): correct order for logger error parameters
The error() function of a logger has two optional parameters: the trace and the context. The logger now no longer passes the global context as the first optional parameter when there are is no value supplied for the trace parameter. Instead, the trace parameter is passed as undefined and the context is passed as the second optional parameter.

This fixes a bug where the trace is overwritten by the context when passed to custom loggers. Fixes gremo/nest-winston#473

## PR Checklist
Please check if your PR fulfills the following requirements:

- [x] The commit message follows our guidelines: https://github.com/nestjs/nest/blob/master/CONTRIBUTING.md
- [x] Tests for the changes have been added (for bug fixes / features)
- [ ] Docs have been added / updated (for bug fixes / features) *Couldn't find any reference to this behavior in the docs.*


## PR Type
What kind of change does this PR introduce?

<!-- Please check the one that applies to this PR using "x". -->
- [x] Bugfix
- [ ] Feature
- [ ] Code style update (formatting, local variables)
- [ ] Refactoring (no functional changes, no api changes)
- [ ] Build related changes
- [ ] CI related changes
- [ ] Other... Please describe:

## What is the current behavior?
<!-- Please describe the current behavior that you are modifying, or link to a relevant issue. -->
When implementing a custom logger, instantiating the Nest `Logger` with a context and then calling `logger.error(message)`, the Nest logger will call the underlying logger's function with `customLogger.error(message, context)`. 

However, the interface for the `error` message is defined as follows: `error(message: any, stack?: string, context?: string): void;` This clearly shows that the first parameter after the message is the stack and the second parameter is the context. Consequently, Nest passing the context as the second parameter (i.e. first optional parameter) is incorrect.

An example of this behavior causing problems for custom logger implementations can be found in gremo/nest-winston#473

Issue Number: N/A


## What is the new behavior?
In the case mentioned above with a custom logger and a Nest logger with a global context, calling `logger.error(message)` in the code will now make Nest correctly call the underlying logger with `customLogger.error(message, undefined, context)`. Note how the first optional parameter (the trace) is now passed as `undefined` and the second optional parameter contains the context.


## Does this PR introduce a breaking change?
- [ ] Yes
- [x] No

<!-- If this PR contains a breaking change, please describe the impact and migration path for existing applications below. -->

If users correctly used the `error()` function of the `Logger`, i.e. they used the first optional parameter for the trace and the second optional parameter for the context, there is no need to change anything.
If users copied the behavior of Nest of setting the context to the first optional parameter of the `error()` function (e.g. calling `logger.error(message, context)`), then the code needs to be changed to correctly pass the context as the second optional parameter: `logger.error(message, undefined, context)`

## Other information


Patch:
diff --git a/packages/common/services/logger.service.ts b/packages/common/services/logger.service.ts
index 6f7f38712..db7452be6 100644
--- a/packages/common/services/logger.service.ts
+++ b/packages/common/services/logger.service.ts
@@ -108,7 +108,9 @@ export class Logger implements LoggerService {
   @Logger.WrapBuffer
   error(message: any, ...optionalParams: any[]) {
     optionalParams = this.context
-      ? optionalParams.concat(this.context)
+      ? (optionalParams.length ? optionalParams : [undefined]).concat(
+          this.context,
+        )
       : optionalParams;
 
     this.localInstance?.error(message, ...optionalParams);


Test patch:
diff --git a/packages/common/test/services/logger.service.spec.ts b/packages/common/test/services/logger.service.spec.ts
index 258e78e6f..6ac32bc64 100644
--- a/packages/common/test/services/logger.service.spec.ts
+++ b/packages/common/test/services/logger.service.spec.ts
@@ -480,43 +480,87 @@ describe('Logger', () => {
         warn(message: any, context?: string) {}
       }
 
-      const customLogger = new CustomLogger();
-      const originalLogger = new Logger();
+      describe('with global context', () => {
+        const customLogger = new CustomLogger();
+        const globalContext = 'RandomContext';
+        const originalLogger = new Logger(globalContext);
 
-      let previousLoggerRef: LoggerService;
+        let previousLoggerRef: LoggerService;
 
-      beforeEach(() => {
-        previousLoggerRef =
-          Logger['localInstanceRef'] || Logger['staticInstanceRef'];
-        Logger.overrideLogger(customLogger);
-      });
+        beforeEach(() => {
+          previousLoggerRef =
+            Logger['localInstanceRef'] || Logger['staticInstanceRef'];
+          Logger.overrideLogger(customLogger);
+        });
 
-      afterEach(() => {
-        Logger.overrideLogger(previousLoggerRef);
-      });
+        afterEach(() => {
+          Logger.overrideLogger(previousLoggerRef);
+        });
 
-      it('should call custom logger "#log()" method', () => {
-        const message = 'random message';
-        const context = 'RandomContext';
+        it('should call custom logger "#log()" method with context as second argument', () => {
+          const message = 'random log message with global context';
 
-        const customLoggerLogSpy = sinon.spy(customLogger, 'log');
+          const customLoggerLogSpy = sinon.spy(customLogger, 'log');
 
-        originalLogger.log(message, context);
+          originalLogger.log(message);
 
-        expect(customLoggerLogSpy.called).to.be.true;
-        expect(customLoggerLogSpy.calledWith(message, context)).to.be.true;
+          expect(customLoggerLogSpy.called).to.be.true;
+          expect(customLoggerLogSpy.calledWith(message, globalContext)).to.be
+            .true;
+        });
+        it('should call custom logger "#error()" method with context as third argument', () => {
+          const message = 'random error message with global context';
+
+          const customLoggerErrorSpy = sinon.spy(customLogger, 'error');
+
+          originalLogger.error(message);
+
+          expect(customLoggerErrorSpy.called).to.be.true;
+          expect(
+            customLoggerErrorSpy.calledWith(message, undefined, globalContext),
+          ).to.be.true;
+        });
       });
+      describe('without global context', () => {
+        const customLogger = new CustomLogger();
+        const originalLogger = new Logger();
 
-      it('should call custom logger "#error()" method', () => {
-        const message = 'random message';
-        const context = 'RandomContext';
+        let previousLoggerRef: LoggerService;
 
-        const customLoggerErrorSpy = sinon.spy(customLogger, 'error');
+        beforeEach(() => {
+          previousLoggerRef =
+            Logger['localInstanceRef'] || Logger['staticInstanceRef'];
+          Logger.overrideLogger(customLogger);
+        });
 
-        originalLogger.error(message, context);
+        afterEach(() => {
+          Logger.overrideLogger(previousLoggerRef);
+        });
 
-        expect(customLoggerErrorSpy.called).to.be.true;
-        expect(customLoggerErrorSpy.calledWith(message, context)).to.be.true;
+        it('should call custom logger "#log()" method', () => {
+          const message = 'random message';
+          const context = 'RandomContext';
+
+          const customLoggerLogSpy = sinon.spy(customLogger, 'log');
+
+          originalLogger.log(message, context);
+
+          expect(customLoggerLogSpy.called).to.be.true;
+          expect(customLoggerLogSpy.calledWith(message, context)).to.be.true;
+        });
+
+        it('should call custom logger "#error()" method', () => {
+          const message = 'random message';
+          const context = 'RandomContext';
+
+          const customLoggerErrorSpy = sinon.spy(customLogger, 'error');
+
+          originalLogger.error(message, undefined, context);
+
+          expect(customLoggerErrorSpy.called).to.be.true;
+          expect(customLoggerErrorSpy.calledWith(message, undefined, context))
+            .to.be.true;
+        });
       });
     });
   });