Winston http log level behaves different than info

Question

I am using winston to log incoming request on a node v16 express.js server using following code sample (boiled down to the essentials to reproduce the behaviour).

I am not sure what is causing this difference in behaviour and I could not find any documentation relevant to it.

Package:

"express": "^4.17.1",
"winston": "~3.3.3"

Server script:

import express from 'express';
import winston from 'winston';

const app = express();

export const TEST_LOGGER = winston.createLogger(
{
  level: 'silly',
  format: winston.format.json(),
  defaultMeta: { service: 'test' },
  transports: [
    new winston.transports.Console({
      format: winston.format.combine(
        winston.format.errors({ stack: true }),
        winston.format.timestamp(),
        winston.format.cli(),
      ),
    }),
  ],
});
TEST_LOGGER.info(`\u27F5 Starting http logging`);
TEST_LOGGER.http(`\u27F5 Starting http logging`);

app.use((req, _response, next) =>
{
  TEST_LOGGER.error(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  TEST_LOGGER.warn(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  TEST_LOGGER.info(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  TEST_LOGGER.verbose(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  TEST_LOGGER.http(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  TEST_LOGGER.debug(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  TEST_LOGGER.silly(`\u27F5 ${ req.method } '${ req.originalUrl }'`);
  next();
});

app.listen(8080, () =>
{
  TEST_LOGGER.info(`\u26A1 'server' launched`);
});

Logs when starting up the server and calling /:

info:    ⟵ Starting http logging
http:undefined⟵ Starting http logging
info:     ⚡ 'server' launched
error:   ⟵ GET '/'
warn:    ⟵ GET '/'
info:    ⟵ GET '/'
verbose: ⟵ GET '/'
http:undefined⟵ GET '/'
debug:   ⟵ GET '/'
silly:   ⟵ GET '/'
error:   ⟵ GET '/'
warn:    ⟵ GET '/'
info:    ⟵ GET '/'
verbose: ⟵ GET '/'
http:undefined⟵ GET '/'
debug:   ⟵ GET '/'
silly:   ⟵ GET '/'
error:   ⟵ GET '/'
warn:    ⟵ GET '/'
info:    ⟵ GET '/'
verbose: ⟵ GET '/'
http:undefined⟵ GET '/'
debug:   ⟵ GET '/'
silly:   ⟵ GET '/'

Where do those undefined come from?

Issue raised on GitHub: https://github.com/winstonjs/logform/issues/183

user_1281901 · Answer

Interestingly the http log level is missing from the standard log levels in the source:

https://github.com/winstonjs/winston/blob/master/lib/winston.js#L87

// Pass through the target methods onto `winston.
Object.keys(exports.config.npm.levels)
  .concat([
    'log',
    'query',
    'stream',
    'add',
    'remove',
    'clear',
    'profile',
    'startTimer',
    'handleExceptions',
    'unhandleExceptions',
    'handleRejections',
    'unhandleRejections',
    'configure',
    'child'
  ])
  .forEach(
    method => (exports[method] = (...args) => defaultLogger[method](...args))
  );

And seems to be coming from the package logform:

https://www.npmjs.com/package/logform

So I would conclude that http isn't a valid winston log level, this should probably be raised as an issue on the winston github.

Winston http log level behaves different than info

1 Answers