Winston logging not working with node js

[tarunsinghh]

This is package.json
"dependencies": {
"@opentelemetry/api": "1.4.1",
"@opentelemetry/api-logs": "^0.52",
"@opentelemetry/sdk-trace-node": "^1.25.0",
"@opentelemetry/sdk-logs": "^0.52",
"@opentelemetry/instrumentation-http": "^0.52.0",
"@opentelemetry/instrumentation-express": "^0.40",
"@opentelemetry/instrumentation-winston": "0.38",
"@opentelemetry/core": "^1.25",
"express": "^4.19",
"axios": "^1.7",
"winston": "^3.13"
}

This is the real code in tracer.js

const { NodeTracerProvider } = require('@opentelemetry/sdk-trace-node');
const logsAPI = require('@opentelemetry/api-logs');
const {
LoggerProvider,
SimpleLogRecordProcessor,
ConsoleLogRecordExporter,
} = require('@opentelemetry/sdk-logs');
const { WinstonInstrumentation } = require('@opentelemetry/instrumentation-winston');
const { registerInstrumentations } = require('@opentelemetry/instrumentation');

const tracerProvider = new NodeTracerProvider();
tracerProvider.register();

// To start a logger, you first need to initialize the Logger provider.
const loggerProvider = new LoggerProvider();
// Add a processor to export log record
loggerProvider.addLogRecordProcessor(
new SimpleLogRecordProcessor(new ConsoleLogRecordExporter())
);
logsAPI.logs.setGlobalLoggerProvider(loggerProvider);

registerInstrumentations({
instrumentations: [
new WinstonInstrumentation({
level:'info',
logHook: (record, span) => {
// Add custom attributes or context to log records
record.attributes['trace_id'] = span.spanContext().traceId;
record.attributes['span_id'] = span.spanContext().spanId;
}
// See below for Winston instrumentation options.
}),
],
});

const winston = require('winston');
const logger = winston.createLogger({
level: "info",
format: winston.format.json(),

transports: [new winston.transports.Console()],

})
logger.info('foobar'); // prints {"level":"info","message":"foobar"} no traceid keys

No opentelemetry trace ids are getting printed, I required this in some other file in server.js there also its not printing trace id.

[architgarg95]

You need to add the winston transport as well for this to work: https://www.npmjs.com/package/@opentelemetry/winston-transport

[tarunsinghh]

You need to add the winston transport as well for this to work: https://www.npmjs.com/package/@opentelemetry/winston-transport

Adding this giving more output but still spanId and traceId are not coming .

const { OpenTelemetryTransportV3 } = require('@opentelemetry/winston-transport');
transports: [new winston.transports.Console(), new OpenTelemetryTransportV3()

output : -

{"level":"info","message":"foobar"}
{
resource: {
attributes: {
'service.name': 'unknown_service:C:\Program Files\nodejs\node.exe',
'telemetry.sdk.language': 'nodejs',
'telemetry.sdk.name': 'opentelemetry',
'telemetry.sdk.version': '1.25.0'
}
},
timestamp: 1718785914695000,
traceId: undefined,
spanId: undefined,
traceFlags: undefined,
severityText: 'info',
severityNumber: 9,
body: 'foobar',
attributes: {}
}

[architgarg95]

can you try removing the hook use, I haven't used hooks then also its working fine for me

[tarunsinghh]

yeah removed it and posted then only

registerInstrumentations({
instrumentations: [
new WinstonInstrumentation({
level:'info',
/* logHook: (record, span) => {
// Add custom attributes or context to log records
record.attributes['trace_id'] = span.spanContext().traceId;
record.attributes['span_id'] = span.spanContext().spanId;
}*/
// See below for Winston instrumentation options.
}),
],
});

[architgarg95]

even mine isn't working wherein I have a library which uses opentelemetry and exposes a few things of it to the using application.

If I run tracing otherwise works fine for me.

In my tracing isn't working at all not sure why even though verbose logging shows express etc. all instrumented correctly. Also I am doing this in the library test file.

If anyone can help getting some console.error
Trace {
resource: {.....}
}

at resource/detector.ts not sure why as all resources are showing correctly in the logs etc as well

[jennysson-junior]

Try to install the the winston transport @opentelemetry/winston-transport.

It looks like an problem with dependecies for @opentelemetry/instrumentation-winston.

[jeromeSH26]

Try to install the the winston transport @opentelemetry/winston-transport.

It looks like an problem with dependecies for @opentelemetry/instrumentation-winston.

I have got same problem, traceId and spanId are undefined. Is there anything to configure ?

here are the transports I set in winston.:

      transports: [
        new winston.transports.Console({
          format: winston.format.combine(
            winston.format.timestamp(),
            winston.format.ms(),
            nestWinstonModuleUtilities.format.nestLike(
              globalConfig().applicationName,
              {
                colors: true,
                prettyPrint: true,
                processId: true,
                appName: true,
              },
            ),
          ),
        }),
        new OpenTelemetryTransportV3(),

and the logs (everything is undefined)

timestamp: 1730232570662000,
  traceId: undefined,
  timestamp: 1730232570662000,
  traceId: undefined,
  traceId: undefined,
  spanId: undefined,
  spanId: undefined,
  traceFlags: undefined,
  severityText: 'error',
  severityNumber: 17,
  body: 'demarrage test scenarios',
  attributes: { context: undefined, stack: [ undefined ] }

[jennysson-junior]

It seems that the traceId and spanId fields are undefined because there’s no active trace context available at the time the logs are being created. OpenTelemetry requires an active span for trace context to propagate to the logs, but looks like Winston doesn’t automatically generate or inherit this context.

I just make a little repo to help you clarify this situation.

https://github.com/jennysson-junior/demo-instrumenting-winston

[jeromeSH26]

It seems that the traceId and spanId fields are undefined because there’s no active trace context available at the time the logs are being created. OpenTelemetry requires an active span for trace context to propagate to the logs, but looks like Winston doesn’t automatically generate or inherit this context.

I just make a little repo to help you clarify this situation.

https://github.com/jennysson-junior/demo-instrumenting-winston

thks but I can't see where you are injecting the context. It is destructered from the library but never used in your file

[jennysson-junior]

thks but I can't see where you are injecting the context. It is destructered from the library but never used in your file

I just forget to remove, It isn't necessary. It's all inject by auto instrumentation.

[jeromeSH26]

thks but I can't see where you are injecting the context. It is destructered from the library but never used in your file

I just forget to remove, It isn't necessary. It's all inject by auto instrumentation.

got it, but this means that auto instrumentation in necessary and that the example in the readme file is wring, which is a problem.

[jennysson-junior]

Not Really, the point is that traceId and spanId fields are undefined because there’s no active trace. In my example I've use auto instrumentation to simplify the process. In case that I've present as example, when have log on listen haven't active trace, So its undefined. When I have an request being called, there is an activa trace and finally have a traceId and spanId.

got it, but this means that auto instrumentation in necessary and that the example in the readme file is wring, which is a problem.

[jeromeSH26]

looking further and the issue is in this line : logs.setGlobalLoggerProvider(loggerProvider);
(logs is imported from @telemetry/api-logs)

When commenting this line out, spanId and traceId are set and no longer undefined. But I guess then, the winston logs are not sent to opentelemetry ?

[trentm]

There is some confusion here:

1. Initially, the OP's example didn't have the @opentelemetry/winston-transport dep, which is required for "log sending" to work. (It is an unfortunate and subtle requirement.)
2. There is some confusion between "log correlation" fields (trace_id, span_id) and the span context fields added to an OTel Log Record by the "log sending" feature (traceId, spanId).
3. The instrumentation-winston README example (https://github.com/open-telemetry/opentelemetry-js-contrib/blob/main/plugins/node/opentelemetry-instrumentation-winston/README.md#usage) is somewhat misleading because it shows example output for logger.info('foobar') which includes span_id, even though the example code there has no span context from which to get a span ID. I think a PR to try to clarify that would be welcome.

One complicating factor is that there is a known issue where the "log
correlation" feature doesn't always set traceId and spanId:
#2010
The issue is demonstrated here: #1837 (comment)
It is related to Winston transports sometimes being run asynchronously.

However, the known issue doesn't seem to be a problem for @jennysson-junior's demo code (https://github.com/jennysson-junior/demo-instrumenting-winston).