8

I am trying to mock a winston.Logger instance that is encapsulated within a service class created with NestJS. I have included my code below.

I cannot get the mocked logger instance to be triggered from within the service class. Can anyone explain where I am going wrong?

import * as winston from 'winston';

import { loggerOptions } from '../logger/logger.config';
import { LoggingService } from '../logger/logger.service';

const logger: winston.Logger = winston.createLogger(loggerOptions);

// trying to mock createLogger to return a specific logger instance
const winstonMock = jest.mock('winston', () => (
    {
        format: {
            colorize: jest.fn(),
            combine: jest.fn(),
            label: jest.fn(),
            timestamp: jest.fn(),
            printf: jest.fn()
        },
        createLogger: jest.fn().mockReturnValue(logger),
        transports: {
            Console: jest.fn()
        }
    })
);


describe("-- Logging Service --", () => {
    let loggerMock: winston.Logger;

    test('testing logger log function called...', () => {        
        const mockCreateLogger = jest.spyOn(winston, 'createLogger');
        const loggingService: LoggingService = LoggingService.Instance;
        loggerMock = mockCreateLogger.mock.instances[0];
        expect(loggingService).toBeInstanceOf(LoggingService)
        expect(loggingService).toBeDefined();
        expect(mockCreateLogger).toHaveBeenCalled()

        // spy on the winston.Logger instance within this test and check
        // that it is called - this is working from within the test method
        const logDebugMock = jest.spyOn(loggerMock, 'log');
        loggerMock.log('debug','test log debug');
        expect(logDebugMock).toHaveBeenCalled();

        // now try and invoke the logger instance indirectly through the service class
        // check that loggerMock is called a second time - this fails, only called once
        // from the preceding lines in this test
        loggingService.debug('debug message');
        expect(logDebugMock).toHaveBeenCalledTimes(2);
    });

   ...

LoggingService debug method code

public debug(message: string) {
        this.logger.log(
            {
                level: types.LogLevel.DEBUG,
                message: message,
                meta: {
                    context: this.contextName
                }
            }
        );
    }

Update: 3/09/2019

Refactored my nestjs LoggingService to dependency inject winston logger instance in constructor to facilitate unit testing. This enables me to use jest.spyOn on the winston logger's log method and check that it has been called within the service instance:

// create winstonLoggerInstance here, e.g. in beforeEach()....
const winstonLoggerMock = jest.spyOn(winstonLoggerInstance, 'log');
serviceInstance.debug('debug sent from test');
expect(winstonLoggerMock).toHaveBeenCalled();
skyboyer
  • 22,209
  • 7
  • 57
  • 64
dcs3spp
  • 493
  • 1
  • 9
  • 23

3 Answers3

16

I have tested your code and it seems there are multiple issues with the usage of jest.mock.

In order to mock a module properly, you must mock it first, before you import it. This is an internal mechanism (how jest mocks modules) and you must follow this rule.

const logger = {
  debug: jest.fn(),
  log: jest.fn()
};

// IMPORTANT First mock winston
jest.mock("winston", () => ({
  format: {
    colorize: jest.fn(),
    combine: jest.fn(),
    label: jest.fn(),
    timestamp: jest.fn(),
    printf: jest.fn()
  },
  createLogger: jest.fn().mockReturnValue(logger),
  transports: {
    Console: jest.fn()
  }
}));

// IMPORTANT import the mock after
import * as winston from "winston";
// IMPORTANT import your service (which imports winston as well)
import { LoggingService } from "../logger/logger.service";

As you can see, you cannot use a winston instance as a returning value for your mock, but no worries, mock the instance as well. (you can see it in the previous code example as well)

const logger = {
  debug: jest.fn(),
  log: jest.fn()
};

Finally, you don't need to spy what you have mocked once, so just ask the mock directly.

The complete code is here:

const logger = {
  debug: jest.fn(),
  log: jest.fn()
};

// trying to mock createLogger to return a specific logger instance
jest.mock("winston", () => ({
  format: {
    colorize: jest.fn(),
    combine: jest.fn(),
    label: jest.fn(),
    timestamp: jest.fn(),
    printf: jest.fn()
  },
  createLogger: jest.fn().mockReturnValue(logger),
  transports: {
    Console: jest.fn()
  }
}));

import * as winston from "winston";
import { LoggingService } from "./logger.service";

describe("-- Logging Service --", () => {
  let loggerMock: winston.Logger;

  test("testing logger log function called...", () => {
    const mockCreateLogger = jest.spyOn(winston, "createLogger");
    const loggingService: LoggingService = LoggingService.Instance;
    loggerMock = mockCreateLogger.mock.instances[0];
    expect(loggingService).toBeInstanceOf(LoggingService);
    expect(loggingService).toBeDefined();
    expect(mockCreateLogger).toHaveBeenCalled();

    // spy on the winston.Logger instance within this test and check
    // that it is called - this is working from within the test method
    logger.log("debug", "test log debug");
    expect(logger.log).toHaveBeenCalled();

    // now try and invoke the logger instance indirectly through the service class
    // check that loggerMock is called a second time - this fails, only called once
    // from the preceding lines in this test
    loggingService.debug("debug message");

    expect(logger.debug).toHaveBeenCalledTimes(1); // <- here
  });
});

I changed the final assertion to one, because I called log in the test, and debug in the LoggingService.

This is the logger service I used:

import * as winston from "winston";

export class LoggingService {
  logger: winston.Logger;

  static get Instance() {
    return new LoggingService();
  }

  constructor() {
    this.logger = winston.createLogger();
  }

  debug(message: string) {
    this.logger.debug(message);
  }
}

Have fun!

csakbalint
  • 698
  • 7
  • 16
  • Thanks Bálint, your answer has been very helpful. So the key lesson I have learned here is to define any mocks first and ensure that they are independent of the library being mocked, e.g mock any API objects returned from the library functions, such as winston.createLogger in this example. After the mocks have been defined then do the imports. Not sure I understand what mean by you don't need to spy on what you have mocked once, do you mean the line ```const mockCreateLogger = jest.spyOn(winston, "createLogger");```? Thanks again Bálint, this has been very helpful :) – dcs3spp Sep 04 '19 at 10:20
  • 1
    You must mock the module before import it for the actual usage. This is important. I bet Jest replace the result of the import when it mocks some module. If you already have the reference of the actual module (not the mock), I'm afraid `Jest` cannot deal with it. You don't have to spy the mocked function, because it already has the behaviour of a spy. `Jest` can do the same assertions both with spies or mocks. – csakbalint Sep 04 '19 at 10:50
  • Ok thanks Bálint, so I could do..```const winstonMock = { format: { colorize: jest.fn(), combine: jest.fn(), label: jest.fn(), timestamp: jest.fn(), printf: jest.fn() }, createLogger: jest.fn().mockReturnValue(logger), transports: { Console: jest.fn() } } // trying to mock createLogger to return a specific logger instance jest.mock("winston", () => (winstonMock));``` and then test createLogger mock function has been called with the line expect(winstonMock.createLogger).toHaveBeenCalled(); instead of using spyOn?? apologies re code format!!!! – dcs3spp Sep 04 '19 at 11:06
  • 1
    Exactly! It's simpler and safer. Don't forget to restore mocked module at the end of your test suit. – csakbalint Sep 04 '19 at 13:21
  • 1
    Got it. Many thanks again for your help Balint, appreciated :) – dcs3spp Sep 05 '19 at 12:16
  • 1
    According to Jest doc, jest.mock() are hoisted to the top of the file - see https://jestjs.io/docs/es6-class-mocks (section Calling jest.mock() with the module factory parameter, warning part): CAUTION Since calls to jest.mock() are hoisted to the top of the file, Jest prevents access to out-of-scope variables. By default, you cannot first define a variable and then use it in the factory. Jest will disable this check for variables that start with the word mock. However, it is still up to you to guarantee that they will be initialized on time. Be aware of Temporal Dead Zone. – Vitaliy Markitanov Dec 06 '22 at 22:54
8

I recently had the same question and solved it by using jest.spyOn with my custom logger.

NOTE: You shouldn't have to unit test winston.createLogger(). The Winston module has its own unit tests that cover that functionality.

Some function that logs an error(i.e. ./controller.ts):

import defaultLogger from '../config/winston';

export const testFunction = async () => {
  try {
    throw new Error('This error should be logged');
  } catch (err) {
    defaultLogger.error(err);
    return;
  }
};

The test file for that function (i.e. `./tests/controller.test.ts):

import { Logger } from 'winston';
import defaultLogger from '../../config/winston';
import testFunction from '../../controller.ts';

const loggerSpy = jest.spyOn(defaultLogger, 'error').mockReturnValue(({} as unknown) as Logger);

test('Logger should have logged', async (done) => {
  await testFunction();

  expect(loggerSpy).toHaveBeenCalledTimes(1);
});
Borduhh
  • 1,975
  • 2
  • 19
  • 33
3

On top of the selected answer, I would add that you don't need to mock the whole Winston object. You can mock a certain part like this:

jest.mock("winston", () => {
    const winston = jest.requireActual("winston");
    winston.transports.Console.prototype.log = jest.fn();
    return winston;
});

That way, you only focus on mocking that part, with the other parts intact.

Kat Lim Ruiz
  • 2,425
  • 2
  • 26
  • 32