Skip to content
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
38 commits
Select commit Hold shift + click to select a range
59f11f3
feat(instrumentation-bunyan): add log sending to Logs Bridge API
trentm Sep 22, 2023
7d8a21f
Merge branch 'main' into trentm/logs-bridge-bunyan
trentm Oct 3, 2023
03c1c16
markdown lint fixes
trentm Oct 3, 2023
3fbfc0c
markdown lint fixes
trentm Oct 3, 2023
57b6628
Merge branch 'main' into trentm/logs-bridge-bunyan
trentm Oct 15, 2023
d5a92d1
catch up with recent core-deps update
trentm Oct 15, 2023
5b9aecb
some type tweaks suggested by David
trentm Oct 15, 2023
e3ed22c
more specific type
trentm Nov 8, 2023
bd507e2
use more self-explanatory code for mapping Bunyan level to OTel sever…
trentm Nov 8, 2023
45f2b1d
export OpenTelemetryBunyanStream for direct usage in Bunyan loggers w…
trentm Nov 8, 2023
7d1532f
.apply over .call suggestion
trentm Nov 8, 2023
ed9ddaf
consistency suggestion
trentm Nov 8, 2023
0f77516
suggestion to use the longer (perhaps clearer) logger var name
trentm Nov 8, 2023
aa81256
Merge branch 'main' into trentm/logs-bridge-bunyan
trentm Nov 8, 2023
4c94dba
switch to false-by-default config vars to avoid surprises with undefi…
trentm Nov 8, 2023
21e3a55
document using OpenTelemetryBunyanStream without the instrumentation
trentm Nov 8, 2023
44d20bd
fix https://eslint.org/docs/latest/rules/prefer-spread lint error
trentm Nov 9, 2023
751f95a
drop options to OpenTelemetryBunyanStream constructor because YAGNI
trentm Nov 9, 2023
43ab672
Merge branch 'main' into trentm/logs-bridge-bunyan
trentm Nov 9, 2023
2f0a89a
temporarily drop CI caching to test theory on unit-test (18) CI failure
trentm Nov 9, 2023
c283178
more CI debugging: restore cache, add some 'npm ls -a' to look into N…
trentm Nov 9, 2023
3638f72
elide Bunyan 'pid' and 'hostname' fields in OTel log record attributes
trentm Nov 9, 2023
303b6ab
update test for having elided 'pid' and 'hostname' fields
trentm Nov 9, 2023
018118e
CI debugging: ignore the 'npm ls -a' exit status, they shouldn't brea…
trentm Nov 9, 2023
284e4d6
fix lint and compile errors
trentm Nov 9, 2023
7fc0842
CI debugging: turn on diag DEBUG to test a theory
trentm Nov 10, 2023
54d2477
turn off diag in this example
trentm Nov 11, 2023
6de5de1
undo CI debugging changes
trentm Nov 11, 2023
bb9b2e4
Merge branch 'main' into trentm/logs-bridge-bunyan
trentm Nov 11, 2023
af2a216
Merge branch 'main' into trentm/logs-bridge-bunyan
hectorhdzg Nov 20, 2023
f3c4d03
update deps to current releases and sync package-lock.json
trentm Nov 21, 2023
c740b76
disableInjection -> disableLogCorrelation
trentm Nov 22, 2023
f850a63
disableLogsBridge -> disableLogSending
trentm Nov 23, 2023
45cbb8b
Merge branch 'main' into trentm/logs-bridge-bunyan
trentm Nov 23, 2023
b597a92
Merge branch 'main' into trentm/logs-bridge-bunyan
hectorhdzg Nov 27, 2023
39b8507
correct the default instrumentation scope name (as discussed earlier)
trentm Nov 27, 2023
a149912
tests: fix test for intrumentationScope.name change in previous commit
trentm Nov 27, 2023
ca18034
fix lint
trentm Nov 27, 2023
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
disableLogsBridge -> disableLogSending
Avoid using 'bridge' terminology at suggestion from specs that the Bridge API is an internal detail.
  • Loading branch information
trentm committed Nov 23, 2023
commit f850a63c064175f395fe3790bd3d5818d726b200
20 changes: 10 additions & 10 deletions plugins/node/opentelemetry-instrumentation-bunyan/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
[![NPM Published Version][npm-img]][npm-url]
[![Apache License][license-image]][license-image]

This module provides automatic instrumentation of the [`bunyan`](https://www.npmjs.com/package/bunyan) module to inject trace-context into Bunyan log records (Log correlation) and to bridge Bunyan logging to the OpenTelemetry Logging SDK. It may be loaded using the [`@opentelemetry/sdk-trace-node`](https://github.com/open-telemetry/opentelemetry-js/tree/main/packages/opentelemetry-sdk-trace-node) package and is included in the [`@opentelemetry/auto-instrumentations-node`](https://www.npmjs.com/package/@opentelemetry/auto-instrumentations-node) bundle.
This module provides automatic instrumentation of the [`bunyan`](https://www.npmjs.com/package/bunyan) module to inject trace-context into Bunyan log records (log correlation) and to send Bunyan logging to the OpenTelemetry Logging SDK (log sending). It may be loaded using the [`@opentelemetry/sdk-trace-node`](https://github.com/open-telemetry/opentelemetry-js/tree/main/packages/opentelemetry-sdk-trace-node) package and is included in the [`@opentelemetry/auto-instrumentations-node`](https://www.npmjs.com/package/@opentelemetry/auto-instrumentations-node) bundle.

If total installation size is not constrained, it is recommended to use the [`@opentelemetry/auto-instrumentations-node`](https://www.npmjs.com/package/@opentelemetry/auto-instrumentations-node) bundle with [@opentelemetry/sdk-node](`https://www.npmjs.com/package/@opentelemetry/sdk-node`) for the most seamless instrumentation experience.

Expand Down Expand Up @@ -39,7 +39,7 @@ const logger = bunyan.createLogger({name: 'example'});

logger.info('hi');
// 1. Log records will be sent to the SDK-registered log record processor, if any.
// This is called "bridging".
// This is called "log sending".

const tracer = api.trace.getTracer('example');
tracer.startActiveSpan('manual-span', span => {
Expand All @@ -50,13 +50,13 @@ tracer.startActiveSpan('manual-span', span => {
})
```

### Logs Bridge
### Log sending

Creation of a Bunyan Logger will automatically add a [Bunyan stream](https://github.com/trentm/node-bunyan#streams) that sends log records to the OpenTelemetry Logs Bridge API. The OpenTelemetry SDK can be configured to handle those records -- for example, sending them on to an OpenTelemetry collector for log archiving and processing. The example above shows a minimal configuration that emits OpenTelemetry log records to the console for debugging.
Creation of a Bunyan Logger will automatically add a [Bunyan stream](https://github.com/trentm/node-bunyan#streams) that sends log records to the OpenTelemetry Logs SDK. The OpenTelemetry SDK can be configured to handle those records -- for example, sending them on to an OpenTelemetry collector for log archiving and processing. The example above shows a minimal configuration that emits OpenTelemetry log records to the console for debugging.

If the OpenTelemetry SDK is not configured with a Logger provider, then this added stream will be a no-op.

The logs bridge can be disabled with the `disableLogsBridge: true` option.
Log sending can be disabled with the `disableLogSending: true` option.

### Log correlation

Expand Down Expand Up @@ -85,16 +85,16 @@ Log injection can be disabled with the `disableLogCorrelation: true` option.

| Option | Type | Description |
| ----------------------- | ----------------- | ----------- |
| `disableLogsBridge` | `boolean` | Whether to disable [logs bridging](#logs-bridge). Default `false`. |
| `disableLogSending` | `boolean` | Whether to disable [log sending](#log-sending). Default `false`. |
| `disableLogCorrelation` | `boolean` | Whether to disable [log correlation](#log-correlation). Default `false`. |
| `logHook` | `LogHookFunction` | An option hook to inject additional context to a log record after trace-context has been added. This requires `disableLogCorrelation` to be false. |

### Using OpenTelemetryBunyanStream without instrumentation

This package exports the Bunyan stream class that is used to bridge to the
OpenTelemetry Logs Bridge API. It can be used directly when configuring a
Bunyan logger if one is not using the `BunyanInstrumentation` for whatever
reason. For example:
This package exports the Bunyan stream class that is used to send records to the
OpenTelemetry Logs SDK. It can be used directly when configuring a Bunyan logger
if one is not using the `BunyanInstrumentation` for whatever reason. For
example:

```js
const { OpenTelemetryBunyanStream } = require('@opentelemetry/instrumentation-bunyan');
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -63,17 +63,17 @@ $ node -r ./telemetry.js app.js
}
```

There are two separate Bunyan instrumentation features. The first, called
"log correlation", is that Bunyan log records emitted in the context of a tracing
There are two separate Bunyan instrumentation features. The first, called "log
correlation", is that Bunyan log records emitted in the context of a tracing
span will include `trace_id` and `span_id` fields that can be used for
correlating with collected tracing data.

The second, called "logs bridging", is that a [Bunyan
The second, called "log sending", is that a [Bunyan
stream](https://github.com/trentm/node-bunyan#streams) is automatically added
to created Loggers that will send every log record to the OpenTelemetry Logs
Bridge API. This means that if the OpenTelemetry SDK has been configured with
a Logger Provider, it will receive them. (If the OpenTelemetry SDK is not
configured for this, then the added Bunyan stream will be a no-op.)
SDK. This means that if the OpenTelemetry SDK has been configured with a Logger
Provider, it will receive them. (If the OpenTelemetry SDK is not configured for
this, then the added Bunyan stream will be a no-op.)

# Resource attributes

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -97,7 +97,7 @@ function severityNumberFromBunyanLevel(lvl: number) {
}

/**
* A Bunyan stream for sending log records to the OpenTelemetry Logs Bridge API.
* A Bunyan stream for sending log records to the OpenTelemetry Logs SDK.
*/
export class OpenTelemetryBunyanStream {
private _otelLogger: Logger;
Expand Down Expand Up @@ -130,17 +130,16 @@ export class OpenTelemetryBunyanStream {
* the _emit wrapper.
*/
write(rec: Record<string, any>) {
// eslint-disable-next-line @typescript-eslint/no-unused-vars
const {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we want to control the log level that will generate log telemetry here? Python supports a env variable called OTEL_PYTHON_LOG_LEVEL more info here, is a common ask in Azure side to control which level of logs to get telemetry for

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this would be fairly straightforward. A starter patch, without error-checking:

diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts
index 8fd0d5bc..0007a119 100644
--- a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts
+++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts
@@ -160,7 +160,7 @@ export class BunyanInstrumentation extends InstrumentationBase<
     logger.addStream({
       type: 'raw',
       stream: new OpenTelemetryBunyanStream(),
-      level: logger.level(),
+      level: process.env.OTEL_NODE_LOG_LEVEL || logger.level(), // XXX obviously missing error checking
     });
   }

To be clear, my understanding is that this level would be independent of the level used for the other output streams on the logger. So instrumenting the following with OTEL_NODE_LOG_LEVEL=trace:

const logger = bunyan.createLogger({name: 'myapp', level: 'debug'})
logger.debug('hi at debug level')
logger.trace('hi at trace level')

would result in just "hi at debug level" being written to stdout, but both log messages being sent to the Logs Bridge API.

One hesitation I have here: I know Bunyan can support having different levels on different output streams/appenders/destinations. I'm not positive for Pino and Winston. What do you think about defering supporting this configuration until I (or someone else) has worked on equivalent instrumentation for those logging frameworks?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah my comment was more about adding the option to configure it, not necessary by env variable, I don't see any OTEL_NODE or similar env variable being used anywhere, maybe we can just allow it by Instrumentation config but these need to be applicable to all Instrumentations that will create logs so we need to use OTel severity names to configure it. We can follow up later and should be fine for me as well, we just need to support it eventually, if you don't add it most likely I will add it very soon. This is becoming a higher priority for us in Azure side :)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, okay. I think it would be good and useful to add the configuration option to the constructor for this.

maybe we can just allow it by Instrumentation config

+1

but these need to be applicable to all Instrumentations that will create logs so we need to use OTel severity names to configure it.

Hrm, I'm still undecided/unsure on this. If I am configuring the log level for my Winston logger, for example, should I not be able to specify the "crit" level defined at https://github.com/winstonjs/winston#logging-levels?
The Logs data model somewhat goes out of its way to not define specific level/severity names: https://opentelemetry.io/docs/specs/otel/logs/data-model/#field-severitytext

Or perhaps we need to clearly show the mappings of Bunyan, Pino, Winston log levels in this table: https://opentelemetry.io/docs/specs/otel/logs/data-model-appendix/#appendix-b-severitynumber-example-mappings
and then the config var accepts those "SeverityNumber" strings (and/or perhaps the SeverityNumber integer values).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've spun this out to a separate issue #1821
after some discussion on yesterday's OTel JS SIG.

time,
level,
msg,
v,
hostname,
pid,
trace_id,
span_id,
trace_flags,
v, // eslint-disable-line @typescript-eslint/no-unused-vars
hostname, // eslint-disable-line @typescript-eslint/no-unused-vars
pid, // eslint-disable-line @typescript-eslint/no-unused-vars
trace_id, // eslint-disable-line @typescript-eslint/no-unused-vars
span_id, // eslint-disable-line @typescript-eslint/no-unused-vars
trace_flags, // eslint-disable-line @typescript-eslint/no-unused-vars
...fields
} = rec;
let timestamp = undefined;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ import { OpenTelemetryBunyanStream } from './OpenTelemetryBunyanStream';
import type * as BunyanLogger from 'bunyan';

const DEFAULT_CONFIG: BunyanInstrumentationConfig = {
disableLogsBridge: false,
disableLogSending: false,
disableLogCorrelation: false,
};

Expand Down Expand Up @@ -153,7 +153,7 @@ export class BunyanInstrumentation extends InstrumentationBase<

private _addStream(logger: any) {
const config: BunyanInstrumentationConfig = this.getConfig();
if (!this.isEnabled() || config.disableLogsBridge) {
if (!this.isEnabled() || config.disableLogSending) {
return;
}
this._diag.debug('Adding OpenTelemetryBunyanStream to logger');
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,10 +23,10 @@ export type LogHookFunction = (span: Span, record: Record<string, any>) => void;
export interface BunyanInstrumentationConfig extends InstrumentationConfig {
/**
* Whether to disable the automatic sending of log records to the
* OpenTelemetry Logs Bridge API.
* OpenTelemetry Logs SDK.
* @default false
*/
disableLogsBridge?: boolean;
disableLogSending?: boolean;

/**
* Whether to disable the injection trace-context fields, and possibly other
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -175,13 +175,13 @@ describe('BunyanInstrumentation', () => {
assert.strictEqual(
memExporter.getFinishedLogRecords().length,
1,
'Logs Bridge still works'
'Log sending still works'
);
span.end();
});
});

it('emits log records to Logs Bridge API', () => {
it('emits log records to Logs SDK', () => {
const logRecords = memExporter.getFinishedLogRecords();

// levels
Expand Down Expand Up @@ -265,10 +265,10 @@ describe('BunyanInstrumentation', () => {
assert.strictEqual(rec.severityText, undefined);
});

it('does not emit to the Logs Bridge API if disableLogsBridge=true', () => {
instrumentation.setConfig({ disableLogsBridge: true });
it('does not emit to the Logs SDK if disableLogSending=true', () => {
instrumentation.setConfig({ disableLogSending: true });

// Changing `disableLogsBridge` only has an impact on Loggers created
// Changing `disableLogSending` only has an impact on Loggers created
// *after* it is set. So we cannot test with the `log` created in
// `beforeEach()` above.
log = Logger.createLogger({ name: 'test-logger-name', stream });
Expand All @@ -288,7 +288,7 @@ describe('BunyanInstrumentation', () => {
});
});

it('emits to the Logs Bridge API with `new Logger(...)`', () => {
it('emits to the Logs SDK with `new Logger(...)`', () => {
log = new Logger({ name: 'test-logger-name', stream });
log.info('foo');

Expand All @@ -304,7 +304,7 @@ describe('BunyanInstrumentation', () => {
assert.strictEqual(rec.attributes.aProperty, 'bar');
});

it('emits to the Logs Bridge API with `Logger(...)`', () => {
it('emits to the Logs SDK with `Logger(...)`', () => {
log = Logger({ name: 'test-logger-name', stream });
log.info('foo');

Expand Down Expand Up @@ -367,7 +367,7 @@ describe('BunyanInstrumentation', () => {
});
});

it('does not emit to the Logs Bridge API', () => {
it('does not emit to the Logs SDK', () => {
tracer.startActiveSpan('abc', span => {
log.info('foo');
assert.strictEqual(memExporter.getFinishedLogRecords().length, 0);
Expand Down