Issues using Sinon to stub out Pino

Question

I am attempting to write unit test for a service function that returns a Pino log message when ran. I have built a stub, using Sinon, from the logger module I am using in service.js, but have not been able to get a successful test. The test returns: AssertionError: expected error to have been called exactly once, but it was called 0 times

Ideally I would like to be able to assert that the logger was called, and that function returned with the exact logger call and message.

Below is some sample code for what I am trying to achieve

logger.js

const pino = require('pino');

const defaultLogger = pino({}, 'output.log');


module.exports = {
  defaultLogger
}

service.js

const path = require('path');
const { defaultLogger } = require('../common/logger');
const logger = defaultLogger.child({ filename: path.basename(__filename) });

const logResponse = () => {
  return logger.info('successful');
};

service.test.js

const sinon = require('sinon');
const chai = require('chai');
const sinonChai = require('sinon-chai');
const service = require('../service.js')
const { defaultLogger } = require('../common/logger');
const { expect } = chai;
chai.should();
chai.use(sinonChai);

describe('Service Test', () => {
  it('should return a log message', () => {
    const spy = sinon.spy(service, 'logResponse')
    const stub = sinon.stub(defaultLogger, 'error');
    spy.should.have.been.calledOnce;
    expect(stub).to.have.been.calledOnce;
    spy.should.have.returned(logger.info('successful'));
  })
})

Answer 1

Here is the unit test solution:

./logger.js:

const pino = require('pino');

const defaultLogger = pino({}, 'output.log');

module.exports = {
  defaultLogger,
};

./service.js:

const path = require('path');
const { defaultLogger } = require('./logger');
const logger = defaultLogger.child({ filename: path.basename(__filename) });

const logResponse = () => {
  return logger.info('successful');
};

module.exports = {
  logResponse,
};

./service.test.js:

const { defaultLogger } = require('./logger');
const sinon = require('sinon');
const chai = require('chai');
const { expect } = chai;

describe('63618186', () => {
  it('should return a log message ', () => {
    const loggerStub = {
      info: sinon.stub().returns('anything'),
    };
    sinon.stub(defaultLogger, 'child').returns(loggerStub);
    const service = require('./service');
    const actual = service.logResponse();
    expect(actual).to.be.equal('anything');
    sinon.assert.calledOnce(defaultLogger.child);
    sinon.assert.calledWithExactly(loggerStub.info, 'successful');
  });
});

unit test result with coverage report:

  63618186
    ✓ should return a log message 


  1 passing (41ms)

------------|---------|----------|---------|---------|-------------------
File        | % Stmts | % Branch | % Funcs | % Lines | Uncovered Line #s 
------------|---------|----------|---------|---------|-------------------
All files   |     100 |      100 |     100 |     100 |                   
 logger.js  |     100 |      100 |     100 |     100 |                   
 service.js |     100 |      100 |     100 |     100 |                   
------------|---------|----------|---------|---------|-------------------