Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(instrumentation-pino): add log sending to Logs Bridge API #2249

Merged
merged 26 commits into from
Jun 27, 2024
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
26 commits
Select commit Hold shift + click to select a range
c8b6072
feat(instrumentation-pino): add log sending to Logs Bridge API
trentm May 27, 2024
211b198
Merge branch 'main' into tm-pino-logs-bridge
trentm May 27, 2024
d817eb0
refactor tests (mostly from separate #2247 PR); lint:fix; some in-pro…
trentm May 28, 2024
72c086b
remove some old dev/debug code
trentm May 28, 2024
b0ed6a1
feat!: make it so re-enabled instr after creating a logger will NOT c…
trentm May 28, 2024
26256d4
impl disableLogCorrelation config; undo the previous commit so that l…
trentm May 28, 2024
59baad8
log sending: first tests; change impl to use pino.multistream
trentm May 28, 2024
5e0123d
edge case tests; almost complete
trentm May 29, 2024
2db3a8c
more tests and a fix for 'useOnlyCustomLevels: true' usage
trentm May 29, 2024
fe0a655
lint:fix
trentm May 29, 2024
0201e80
refactor some code out to utils file
trentm May 30, 2024
aa2e224
add some internal docs
trentm May 30, 2024
ce12413
update readme
trentm May 30, 2024
2a630f2
fix lint
trentm May 30, 2024
2abd655
Merge branch 'main' into tm-pino-logs-bridge
trentm May 30, 2024
be12617
avoid a possible flaky error if using pino 'unixTime' and logging in …
trentm May 30, 2024
899f153
limit log-sending to pino@7 and later because that's when pino.multis…
trentm May 30, 2024
77b1877
lint:fix
trentm May 30, 2024
37a59de
discuss pino-opentelemetry-transport alternative
trentm May 31, 2024
158fd6a
Merge branch 'main' into tm-pino-logs-bridge
trentm Jun 7, 2024
f1b83a8
fix a mis-merge
trentm Jun 7, 2024
954642a
update changed deps to their new latest
trentm Jun 7, 2024
3d1c5da
Merge branch 'main' into tm-pino-logs-bridge
trentm Jun 10, 2024
7116e6a
typo in README
trentm Jun 24, 2024
1bb7260
Merge branch 'main' into tm-pino-logs-bridge
trentm Jun 24, 2024
632e5c9
Merge branch 'main' into tm-pino-logs-bridge
pichlermarc Jun 27, 2024
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
impl disableLogCorrelation config; undo the previous commit so that l…
…og-correlation *will* follow the live instr enable/disable state
  • Loading branch information
trentm committed May 28, 2024
commit 26256d4e1fc7224c472e21e59da5fc52115313d4
Original file line number Diff line number Diff line change
Expand Up @@ -121,35 +121,31 @@ export class PinoInstrumentation extends InstrumentationBase {
const otelLogger = logs.getLogger(PACKAGE_NAME, PACKAGE_VERSION);

const patchedPino = Object.assign((...args: unknown[]) => {
// XXX instrumentatin.getConfig(); usage
// const config = instrumentation.getConfig();
const optLogCorrelation = true;
const optLogSending = true;
const config = instrumentation.getConfig();
const isEnabled = instrumentation.isEnabled();

const logger = moduleExports(...args);

if (isEnabled && optLogCorrelation) {
// Note: If the Pino logger is configured with `nestedKey`, then
// the `trace_id` et al fields added by `otelMixin` will be nested
// as well. https://getpino.io/#/docs/api?id=mixin-function
const otelMixin = instrumentation._getMixinFunction();
const mixinSym = moduleExports.symbols.mixinSym;
const origMixin = logger[mixinSym];
if (origMixin === undefined) {
// console.warn('XXX adding otelMixin', )
logger[mixinSym] = otelMixin;
} else {
logger[mixinSym] = (ctx: object, level: number) => {
return Object.assign(
otelMixin(ctx, level),
origMixin(ctx, level)
);
};
}
// Setup "log correlation" -- injection of `trace_id` et al fields.
// Note: If the Pino logger is configured with `nestedKey`, then
// the `trace_id` et al fields added by `otelMixin` will be nested
// as well. https://getpino.io/#/docs/api?id=mixin-function
const otelMixin = instrumentation._getMixinFunction();
const mixinSym = moduleExports.symbols.mixinSym;
const origMixin = logger[mixinSym];
if (origMixin === undefined) {
logger[mixinSym] = otelMixin;
} else {
logger[mixinSym] = (ctx: object, level: number) => {
return Object.assign(
otelMixin(ctx, level),
origMixin(ctx, level)
trentm marked this conversation as resolved.
Show resolved Hide resolved
);
};
}

if (isEnabled && optLogSending) {
// Setup "log sending" -- sending log records to the Logs API.
if (isEnabled && !config.disableLogSending) {
// Shim the Pino logger's `stream.write` for log sending.
const stream = logger[moduleExports.symbols.streamSym];
if (typeof stream.write !== 'function') {
Expand Down Expand Up @@ -261,6 +257,13 @@ export class PinoInstrumentation extends InstrumentationBase {
private _getMixinFunction() {
const instrumentation = this;
return function otelMixin(_context: object, level: number) {
if (
!instrumentation.isEnabled() ||
instrumentation.getConfig().disableLogCorrelation
) {
return {};
}

const span = trace.getSpan(context.active());

if (!span) {
Expand Down
24 changes: 23 additions & 1 deletion plugins/node/opentelemetry-instrumentation-pino/src/types.ts
Original file line number Diff line number Diff line change
Expand Up @@ -25,9 +25,31 @@ export type LogHookFunction = (
) => void;

export interface PinoInstrumentationConfig extends InstrumentationConfig {
/**
* Whether to disable the automatic sending of log records to the
* OpenTelemetry Logs SDK.
* @default false
*/
disableLogSending?: boolean;

/**
* Whether to disable the injection trace-context fields, and possibly other
* fields from `logHook()`, into log records for log correlation.
* @default false
*/
disableLogCorrelation?: boolean;

/**
* A function that allows injecting additional fields in log records. It is
* called, as `logHook(span, record)`, for each log record emitted in a valid
* span context. It requires `disableLogCorrelation` to be false.
*/
logHook?: LogHookFunction;

/** Configure the names of field injected into logs when there is span context available. */
/**
* Configure the names of field injected into logs when there is span context
* available.
*/
logKeys?: {
traceId: string;
spanId: string;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -111,6 +111,18 @@ describe('PinoInstrumentation', () => {
assert.strictEqual(record['resource.service.name'], undefined);
});
});

it('injects span context once re-enabled', () => {
instrumentation.enable();
tracer.startActiveSpan('abc', span => {
logger.info('a message');
span.end();

sinon.assert.calledOnce(writeSpy);
const record = JSON.parse(writeSpy.firstCall.args[0].toString());
assertRecord(record, span);
});
});
});

describe('log correlation', () => {
Expand Down Expand Up @@ -235,6 +247,33 @@ describe('PinoInstrumentation', () => {
});
});

it('does not inject or call logHook if disableLogCorrelation=true', () => {
instrumentation.setConfig({
disableLogCorrelation: true,
logHook: (_span, record) => {
record['resource.service.name'] = 'test-service';
},
});
tracer.startActiveSpan('abc', span => {
logger.info('foo');
span.end();

sinon.assert.calledOnce(writeSpy);
const record = JSON.parse(writeSpy.firstCall.args[0].toString());
assert.strictEqual('foo', record['msg']);
assert.strictEqual(record['trace_id'], undefined);
assert.strictEqual(record['span_id'], undefined);
assert.strictEqual(record['trace_flags'], undefined);
assert.strictEqual(record['resource.service.name'], undefined);
// XXX restore this
// assert.strictEqual(
// memExporter.getFinishedLogRecords().length,
// 1,
// 'Log sending still works'
// );
});
});

it('instrumentation of `pino.default(...)` works', function () {
if (!pino.default) {
this.skip();
Expand Down