winstonjs/logform

[Bug]: Winston http log level behaves different than info

Opened this issue · 2 comments

The problem

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"

When logging with the logger.http("...") method, there is a strange undefined in the logs, but not when using logger.info("...") or any other log level function.

Where do those undefined come from?

(I am using winston already some time, and this has been something which has come very recently.)

What version of Logform presents the issue?

v2.4.0

What version of Node are you using?

v16.15.0

If this worked in a previous version of Logform, which was it?

2.2.0

Minimum Working Example

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.log('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`);
});

Additional information

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 '/'
http:undefined⟵ GET '/'
debug:   ⟵ GET '/'
silly:   ⟵ GET '/'
error:   ⟵ GET '/'
warn:    ⟵ GET '/'
info:    ⟵ GET '/'
verbose: ⟵ GET '/'
http:undefined⟵ GET '/'
http:undefined⟵ GET '/'
debug:   ⟵ GET '/'
silly:   ⟵ GET '/'
error:   ⟵ GET '/'
warn:    ⟵ GET '/'
info:    ⟵ GET '/'
verbose: ⟵ GET '/'
http:undefined⟵ GET '/'
http:undefined⟵ GET '/'
debug:   ⟵ GET '/'
silly:   ⟵ GET '/'

I have been redirected here from an answer on SO: https://stackoverflow.com/questions/72783394/winston-http-log-level-behaves-different-than-info

🔎 Search Terms

http info undefined log level

wbt commented

Thanks for the report...that does look like a bug.

Any advancements related to this issue?