Opentelemetry-js: Would a PR for plugin support for Logging Libraries (winston, bunyan, pino, etc) be accepted?

[ericmustin]

Hello,

Just wondering whether, if I ported over the plugin/instrumentation for some of the logging libraries in dd-trace-js, such as winston or bunyan, would a PR be accepted against opentelemetry-js-contrib?

Winston, for example: https://github.com/DataDog/dd-trace-js/blob/master/packages/datadog-plugin-winston/src/index.js

more info: https://datadoghq.dev/dd-trace-js/interfaces/plugins.winston.html

Essentially all it's doing is injecting the trace_id and span_id into the json logs emitted by these logging libraries. This helps users correlate logs emitted by their application with traces that were active at the time the log was emitted. The dd-trace-js implementations have some vendor specific details that would need to be to abstracted away/modified (so instead of injecting keys like dd.trace_id it could be otel.trace_id or <arbitrary_user_supplied_option_with_reasonable_default>.trace_id But otherwise the use case has value for any user and is relatively vendor agnostic imo. So i'd love to have it be something anyone can find in js-contrib, but i'm not sure if the behavior it achieves would too significantly off-spec to have it land there. In which case, no worries, can always host elsewhere and try to just have it referenced in the otel registry.

Is there currently anything in the Otel Spec for this?

[dyladan]

I have not seen anything in the spec. Previously, @obecny had created a similar plugin PR, but it was not merged at that time.

The issue I have with such a plugin is that it modifies user program behavior by modifying log output. At the very least, I would not want this installed/enabled by default without some user intervention saying that yes they do want a behavior change. Some logging libraries (including winston I think) already have support for plugins/formatters that can inject fields. Maybe it would be better to release a winston Format which uses the public API methods to inject fields?

[dyladan]

Maybe we can get some guidance from the @open-telemetry/technical-committee here?

[obecny]

FYI, I still have it in case there is desire to have it so it will be a matter of read that and fixing conflicts ;)

[yurishkuro]

According to the readme, http and grpc plugins are included directly in this repo, while all others are in contrib. I can understand http if it's based on stdlib, but why was grpc singled out?

I would recommend placing all plugins (unless they are for stdlib) into contrib.

[dyladan]

@yurishkuro http(s) is language built-in so it is in main, and gRPC from what I understand was identified early as an important plugin that MUST be supported by all SDKs, so it was also kept here. It can easily be moved to contrib though if it doesn't have the special status that I thought it did.

The question here though is about logging plugins. Is it acceptable to have an autoistrumentation which modifies logging output to include trace ids? If it is acceptable, should it be included in our "all plugins" package (plugins in this package are auto-enabled if they are installed)?

[ericmustin]

@yurishkuro fwiw i only opened the PR here for visibility, i didn't really intend to broach the topic of where all the plugins should live.

I tend to agree with @dyladan here.

it modifies user program behavior by modifying log output. At the very least, I would not want this installed/enabled by default without some user intervention saying that yes they do want a behavior change. `

If logging plugins were to land in js-contrib, they should be something that's explicitly enabled. This is the case in dd-trace-js currently fwiw (you pass in config flag or env var to enable).

That being said, if there's a reasonable way to do this already that doesn't end up bumping up against Spec, or fits within an existing otel convention, i'm fine with that approach rather than having something that's problematic, even if it requires slightly more user configuration (one of the benefits of a plugin is that user config is as simple as a config flag/env var). I think what you mentioned re: winston format is a very reasonable (i'll admit i need to learn a bit more about it and also investigate if bunyan has something similar). If that's the approach that's preferred i'd be happy to document the appropriate config/formatting required, but it would be nice to have this land somewhere such as /docs where users can discover it

[dyladan]

but it would be nice to have this land somewhere such as /docs where users can discover it

Or the registry?

[dyladan]

In bunyan it is very easy. We would have something like this:

import { trace } from "@opentelemetry/api";
import { format } from "logform";

const tracer = trace.getTracer("@opentelemetry/logform", "0.3.2");

/*
 * Returns a new instance of the OpenTelemetry Trace Context Format which adds an OpenTelemetry Trace Context
 */
export const TraceContextFormatter = format((info) => {
    const { traceId, spanId, traceFlags } = tracer.getCurrentSpan().context();
    info.traceContext = {
        traceId,
        spanId,
        sampled: !!(traceFlags & 0x1)
    };
    return info;
});

And usage would look like this:

import { TraceContextFormatter } from "@opentelemetry/logform"
import { createLogger, transports, format } from "winston";

const logger = createLogger({
    format: format.combine(
        traceContextFormatter(),
        format.json()
    ),
    transports: [new transports.Console()],
})

logger.info("some log message")
// OUTPUT: {"message":"hey","level":"info","traceContext":"[traceId=0 spanId=0 sampled=0]"}

I haven't tested this code, but it should require only very little if any modification to get working.

[naseemkullah]

That bunyan example is docs worthy imho, and examples for pino and winston would be nice as well.
What's !!(traceFlags & 0x1)is a tad obscure imho, what's it do exactly?

is !! essentially Boolean()?

[vmarchaud]

I know that this was recently merged in the specs, don't know if it should apply to 3rd party logger or only to the future logs-sdk

[dyladan]

That bunyan example is docs worthy imho, and examples for pino and winston would be nice as well.
What's !!(traceFlags & 0x1)is a tad obscure imho, what's it do exactly?

is !! essentially Boolean()?

!! casts to Boolean yes. It is a slightly more esoteric way to do it I guess. ! is not, so !! is not-not.

traceFlags & 0x1 checks to see if the first bit is set by doing a bitwise AND operation on traceflags and 00000001. The idea is that the trace flag is only the first bit, so any traceFlags value with that bit set should still return true such as 1, 3, 5, etc (any odd number has the first bit set).

[dyladan]

I know that this was recently merged in the specs, don't know if it should apply to 3rd party logger or only to the future logs-sdk

The idea behind the data model is that you should be able to convert any existing known logging data and convert it to our own data model so it can be ingested by backends. It should be losslessly convertible in both directions (conversion from source logs like syslog to our model and back to the source format should be "perfect").

[naseemkullah]

BTW I am today doing something similar with https://github.com/pinojs/pino

I leave the traceFlags key as provided from context though, @dyladan any particular reason you modify it to sampled ?

import tracer from './tracer'
import * as pino from 'pino';

export default pino({
  formatters: {
    log(object) {
      return {...object, ...tracer.getCurrentSpan()?.context()};
    },
  },
});

[naseemkullah]

Also worth noting, for the http request logger https://github.com/pinojs/pino-http I also replace reqId with spanId as such:

import tracer from './lib/tracer';
import logger from './lib/logger';
import * as pinoHttp from 'pino-http';

app.use(
  pinoHttp({
    logger,
    genReqId: () => {
      const spanId = tracer.getCurrentSpan()?.context().spanId;
      return spanId ?? 'no span id!';
    },
  })
);

[dyladan]

@dyladan any particular reason you modify it to sampled ?

I think sampled=1 is more readable to most people than TraceFlags=1. Sampled doesn't require previous knowledge of Trace Context spec and the associated TraceFlags.

edit: Also, 1 is not the only option. Technically TraceFlags=3 is still sampled, but users unfamiliar with the Trace Context spec may not know that.

[mhennoch]

As we have winston, bunyan, pino instrumentations now I'm going to guess the answer was yes and this can be closed? @dyladan