Skip to content

Commit 91577e0

Browse files
cindy-pengcindy-penggcf-owl-bot[bot]
authored
feat: Open telemetry integration and span Id fix for nodejs logging library (#1497)
* feat: OpenTelemetry integration * feat: add otel system testing with cloud tracing * Add unit testing for otel context * Add parseOtelContext test * testing entry metadata population * Add system test suites * remove only mocha test keywords * Fix lint errors * fix lint issues * 🦉 Updates from OwlBot post-processor See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md * Add span end method in system tests * fix gts check * 🦉 Updates from OwlBot post-processor See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md * 🦉 Updates from OwlBot post-processor See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md * Remove comments * move otel packages to peer dependencies * move otel packages to peer dependencies * fix system test * add bitmask for tracesampled flag * fix pack-n-play testing * revert pack-n-play sample configuration * Make otel api as dependency due to low npm version in kokoro infra * 🦉 Updates from OwlBot post-processor See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md * fix comments to return value directy --------- Co-authored-by: cindy-peng <[email protected]> Co-authored-by: Owl Bot <gcf-owl-bot[bot]@users.noreply.github.com>
1 parent ee374a2 commit 91577e0

File tree

7 files changed

+739
-172
lines changed

7 files changed

+739
-172
lines changed

‎package.json

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -59,7 +59,8 @@
5959
"on-finished": "^2.3.0",
6060
"pumpify": "^2.0.1",
6161
"stream-events": "^1.0.5",
62-
"uuid": "^9.0.0"
62+
"uuid": "^9.0.0",
63+
"@opentelemetry/api": "^1.7.0"
6364
},
6465
"devDependencies": {
6566
"@google-cloud/bigquery": "^7.0.0",
@@ -93,7 +94,14 @@
9394
"typescript": "^5.1.6",
9495
"uglify-js": "^3.13.5",
9596
"webpack": "^5.0.0",
96-
"webpack-cli": "^5.0.0"
97+
"webpack-cli": "^5.0.0",
98+
"@opentelemetry/api": "^1.7.0",
99+
"@opentelemetry/sdk-trace-node": "^1.23.0",
100+
"@opentelemetry/sdk-node": "^0.50.0",
101+
"@opentelemetry/semantic-conventions": "^1.23.0",
102+
"@opentelemetry/sdk-trace-base": "^1.23.0",
103+
"@opentelemetry/resources": "^1.23.0",
104+
"@google-cloud/opentelemetry-cloud-trace-exporter": "^2.1.0"
97105
},
98106
"engines": {
99107
"node": ">=14.0.0"

‎src/entry.ts

Lines changed: 34 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,11 @@ import {
3030
RawHttpRequest,
3131
isRawHttpRequest,
3232
} from './utils/http-request';
33-
import {CloudTraceContext, getOrInjectContext} from './utils/context';
33+
import {
34+
CloudTraceContext,
35+
getContextFromOtelContext,
36+
getOrInjectContext,
37+
} from './utils/context';
3438

3539
const eventId = new EventId();
3640

@@ -229,16 +233,17 @@ class Entry {
229233
const req = this.metadata.httpRequest;
230234
if (isRawHttpRequest(req)) {
231235
entry.httpRequest = makeHttpRequestData(req);
232-
// Format trace and span
233-
const traceContext = this.extractTraceFromHeaders(projectId);
234-
if (traceContext) {
235-
if (!this.metadata.trace && traceContext.trace)
236-
entry.trace = traceContext.trace;
237-
if (!this.metadata.spanId && traceContext.spanId)
238-
entry.spanId = traceContext.spanId;
239-
if (this.metadata.traceSampled === undefined)
240-
entry.traceSampled = traceContext.traceSampled;
241-
}
236+
}
237+
238+
// Format trace and span
239+
const traceContext = this.extractTraceContext(projectId);
240+
if (traceContext) {
241+
if (!this.metadata.trace && traceContext.trace)
242+
entry.trace = traceContext.trace;
243+
if (!this.metadata.spanId && traceContext.spanId)
244+
entry.spanId = traceContext.spanId;
245+
if (this.metadata.traceSampled === undefined)
246+
entry.traceSampled = traceContext.traceSampled;
242247
}
243248
return entry;
244249
}
@@ -308,26 +313,31 @@ class Entry {
308313
const req = meta.httpRequest;
309314
if (isRawHttpRequest(req)) {
310315
entry.httpRequest = makeHttpRequestData(req);
311-
// Detected trace context from headers if applicable.
312-
const traceContext = this.extractTraceFromHeaders(projectId);
313-
if (traceContext) {
314-
if (!entry[TRACE_KEY] && traceContext.trace)
315-
entry[TRACE_KEY] = traceContext.trace;
316-
if (!entry[SPAN_ID_KEY] && traceContext.spanId)
317-
entry[SPAN_ID_KEY] = traceContext.spanId;
318-
if (entry[TRACE_SAMPLED_KEY] === undefined)
319-
entry[TRACE_SAMPLED_KEY] = traceContext.traceSampled;
320-
}
316+
}
317+
318+
// Detected trace context from OpenTelemetry context or http headers if applicable.
319+
const traceContext = this.extractTraceContext(projectId);
320+
if (traceContext) {
321+
if (!entry[TRACE_KEY] && traceContext.trace)
322+
entry[TRACE_KEY] = traceContext.trace;
323+
if (!entry[SPAN_ID_KEY] && traceContext.spanId)
324+
entry[SPAN_ID_KEY] = traceContext.spanId;
325+
if (entry[TRACE_SAMPLED_KEY] === undefined)
326+
entry[TRACE_SAMPLED_KEY] = traceContext.traceSampled;
321327
}
322328
return entry;
323329
}
324330

325331
/**
326-
* extractTraceFromHeaders extracts trace and span information from raw HTTP
327-
* request headers only.
332+
* extractTraceContext extracts trace and span information from OpenTelemetry
333+
* span context or raw HTTP request headers.
328334
* @private
329335
*/
330-
private extractTraceFromHeaders(projectId: string): CloudTraceContext | null {
336+
private extractTraceContext(projectId: string): CloudTraceContext | null {
337+
// Extract trace context from OpenTelemetry span context.
338+
const otelContext = getContextFromOtelContext(projectId);
339+
if (otelContext) return otelContext;
340+
// Extract trace context from http request headers.
331341
const rawReq = this.metadata.httpRequest;
332342
if (rawReq && 'headers' in rawReq) {
333343
return getOrInjectContext(rawReq, projectId, false);

‎src/index.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1604,3 +1604,4 @@ module.exports.v2 = v2;
16041604
import * as protos from '../protos/protos';
16051605
export {protos};
16061606
export {v2};
1607+
export * from '@opentelemetry/api';

‎src/utils/context.ts

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,7 @@
3030
import * as http from 'http';
3131
import * as uuid from 'uuid';
3232
import * as crypto from 'crypto';
33+
import {trace, isSpanContextValid} from '@opentelemetry/api';
3334

3435
/** Header that carries span context across Google infrastructure. */
3536
export const X_CLOUD_TRACE_HEADER = 'x-cloud-trace-context';
@@ -98,7 +99,13 @@ export function getOrInjectContext(
9899
inject?: boolean
99100
): CloudTraceContext {
100101
const defaultContext = toCloudTraceContext({}, projectId);
102+
103+
// Get trace context from OpenTelemetry span context.
104+
const otelContext = getContextFromOtelContext(projectId);
105+
if (otelContext) return otelContext;
106+
101107
const wrapper = makeHeaderWrapper(req);
108+
102109
if (wrapper) {
103110
// Detect 'traceparent' header.
104111
const traceContext = getContextFromTraceParent(wrapper, projectId);
@@ -149,6 +156,30 @@ function makeCloudTraceHeader(): string {
149156
return `${trace}/${spanId}`;
150157
}
151158

159+
/**
160+
* getContextFromOtelContext looks for the active open telemetry span context
161+
* per Open Telemetry specifications for tracing contexts.
162+
*
163+
* @param projectId
164+
*/
165+
export function getContextFromOtelContext(
166+
projectId: string
167+
): CloudTraceContext | null {
168+
const spanContext = trace.getActiveSpan()?.spanContext();
169+
const FLAG_SAMPLED = 1; // 00000001
170+
if (spanContext !== undefined && isSpanContextValid(spanContext)) {
171+
const otelSpanContext = {
172+
trace: spanContext?.traceId,
173+
spanId: spanContext?.spanId,
174+
traceSampled: (spanContext.traceFlags & FLAG_SAMPLED) !== 0,
175+
};
176+
177+
return toCloudTraceContext(otelSpanContext, projectId);
178+
}
179+
180+
return null;
181+
}
182+
152183
/**
153184
* getContextFromXCloudTrace looks for the HTTP header 'x-cloud-trace-context'
154185
* per Google Cloud specifications for Cloud Tracing.

‎system-test/logging.ts

Lines changed: 180 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -29,8 +29,11 @@ const http2spy = require('http2spy');
2929
import {Logging, Sink, Log, Entry, TailEntriesResponse} from '../src';
3030
import * as http from 'http';
3131
import * as instrumentation from '../src/utils/instrumentation';
32-
33-
// block all attempts to chat with the metadata server (kokoro runs on GCE)
32+
import {trace} from '@opentelemetry/api';
33+
import {Resource} from '@opentelemetry/resources';
34+
import {SEMRESATTRS_SERVICE_NAME} from '@opentelemetry/semantic-conventions';
35+
import {TraceExporter} from '@google-cloud/opentelemetry-cloud-trace-exporter';
36+
import {NodeSDK} from '@opentelemetry/sdk-node';
3437
nock(HOST_ADDRESS)
3538
.get(() => true)
3639
.replyWithError({code: 'ENOTFOUND'})
@@ -270,8 +273,8 @@ describe('Logging', () => {
270273
});
271274

272275
describe('logs', () => {
273-
function getTestLog(loggingInstnce = null) {
274-
const log = (loggingInstnce || logging).log(generateName());
276+
function getTestLog(loggingInstance = null) {
277+
const log = (loggingInstance || logging).log(generateName());
275278

276279
const logEntries = [
277280
// string data
@@ -733,15 +736,185 @@ describe('Logging', () => {
733736
});
734737
});
735738

739+
describe('logs with open telemetry context', () => {
740+
let sdk: NodeSDK;
741+
before(() => {
742+
// initialize the SDK and register with the OpenTelemetry API
743+
// this enables the API to record telemetry
744+
sdk = new NodeSDK({
745+
resource: new Resource({
746+
[SEMRESATTRS_SERVICE_NAME]: TESTS_PREFIX,
747+
}),
748+
// Add cloud trace exporter as SDK trace exporter
749+
traceExporter: new TraceExporter(),
750+
});
751+
sdk.start();
752+
});
753+
754+
after(() => {
755+
sdk.shutdown();
756+
});
757+
758+
it('should not overwrite user defined trace and spans with OpenTelemetry context', done => {
759+
trace.getTracer(TESTS_PREFIX).startActiveSpan('foo', span => {
760+
const {log} = getTestLog();
761+
const spanTestMessage = 'span test log message';
762+
const metadata = {
763+
trace: '1',
764+
spanId: '1',
765+
traceSampled: false,
766+
};
767+
const logEntry = log.entry(metadata, spanTestMessage);
768+
log.write(logEntry, err => {
769+
assert.ifError(err);
770+
getEntriesFromLog(log, {numExpectedMessages: 1}, (err, entries) => {
771+
assert.ifError(err);
772+
const entry = entries![0];
773+
assert.strictEqual(entry.data, spanTestMessage);
774+
assert.strictEqual(entry.metadata.trace, metadata.trace);
775+
assert.strictEqual(entry.metadata.spanId, metadata.spanId);
776+
assert.strictEqual(
777+
entry.metadata.traceSampled,
778+
metadata.traceSampled
779+
);
780+
});
781+
});
782+
span.end();
783+
});
784+
done();
785+
});
786+
787+
it('should write a log with trace and spans from OpenTelemetry context', done => {
788+
trace.getTracer(TESTS_PREFIX).startActiveSpan('foo', span => {
789+
const traceId = span.spanContext().traceId;
790+
const spanId = span.spanContext().spanId;
791+
const traceSampled = (span.spanContext().traceFlags & 1) !== 0;
792+
const {log} = getTestLog();
793+
const spanTestMessage = 'span test log message';
794+
const logEntry = log.entry(spanTestMessage);
795+
log.write(logEntry, err => {
796+
assert.ifError(err);
797+
getEntriesFromLog(log, {numExpectedMessages: 1}, (err, entries) => {
798+
assert.ifError(err);
799+
const entry = entries![0];
800+
assert.strictEqual(entry.data, spanTestMessage);
801+
assert.strictEqual(
802+
entry.metadata.trace,
803+
`projects/${PROJECT_ID}/traces/${traceId}`
804+
);
805+
assert.strictEqual(entry.metadata.spanId, spanId);
806+
assert.strictEqual(entry.metadata.traceSampled, traceSampled);
807+
});
808+
});
809+
span.end();
810+
});
811+
done();
812+
});
813+
814+
it('should write a log with OpenTelemetry trace and spans and ignore http requests traceparent header', done => {
815+
const {log} = getTestLog();
816+
const URL = 'http://www.google.com';
817+
trace.getTracer(TESTS_PREFIX).startActiveSpan('foo', span => {
818+
// Use the response of a http request as the incomingmessage request obj.
819+
http.get(URL, res => {
820+
res.url = URL;
821+
res.headers = {
822+
traceparent:
823+
'00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01',
824+
};
825+
const metadata = {httpRequest: res};
826+
const logEntry = log.entry(metadata, 'some log message');
827+
828+
const traceId = span.spanContext().traceId;
829+
const spanId = span.spanContext().spanId;
830+
const traceSampled = (span.spanContext().traceFlags & 1) !== 0;
831+
832+
log.write(logEntry, err => {
833+
assert.ifError(err);
834+
getEntriesFromLog(
835+
log,
836+
{numExpectedMessages: 1},
837+
(err, entries) => {
838+
assert.ifError(err);
839+
const entry = entries![0];
840+
assert.strictEqual(entry.data, 'some log message');
841+
assert.strictEqual(
842+
entry.metadata.httpRequest?.requestUrl,
843+
URL
844+
);
845+
assert.strictEqual(
846+
entry.metadata.httpRequest?.protocol,
847+
'http:'
848+
);
849+
assert.strictEqual(
850+
entry.metadata.trace,
851+
`projects/${PROJECT_ID}/traces/${traceId}`
852+
);
853+
assert.strictEqual(entry.metadata.spanId, spanId);
854+
assert.strictEqual(entry.metadata.traceSampled, traceSampled);
855+
}
856+
);
857+
});
858+
});
859+
span.end();
860+
});
861+
done();
862+
});
863+
864+
it('should write a log with OpenTelemetry trace and spans and ignore http requests x-cloud-trace-context header', done => {
865+
const {log} = getTestLog();
866+
const URL = 'http://www.google.com';
867+
trace.getTracer(TESTS_PREFIX).startActiveSpan('foo', span => {
868+
// Use the response of a http request as the incomingmessage request obj.
869+
http.get(URL, res => {
870+
res.url = URL;
871+
res.headers = {
872+
'x-cloud-trace-context': '1/2;o=1',
873+
};
874+
const metadata = {httpRequest: res};
875+
const logEntry = log.entry(metadata, 'some log message');
876+
const traceId = span.spanContext().traceId;
877+
const spanId = span.spanContext().spanId;
878+
const traceSampled = (span.spanContext().traceFlags & 1) !== 0;
879+
log.write(logEntry, err => {
880+
assert.ifError(err);
881+
getEntriesFromLog(
882+
log,
883+
{numExpectedMessages: 1},
884+
(err, entries) => {
885+
assert.ifError(err);
886+
const entry = entries![0];
887+
assert.strictEqual(entry.data, 'some log message');
888+
assert.strictEqual(
889+
entry.metadata.httpRequest?.requestUrl,
890+
URL
891+
);
892+
assert.strictEqual(
893+
entry.metadata.httpRequest?.protocol,
894+
'http:'
895+
);
896+
assert.strictEqual(
897+
entry.metadata.trace,
898+
`projects/${PROJECT_ID}/traces/${traceId}`
899+
);
900+
assert.strictEqual(entry.metadata.spanId, spanId);
901+
assert.strictEqual(entry.metadata.traceSampled, traceSampled);
902+
}
903+
);
904+
});
905+
});
906+
span.end();
907+
});
908+
done();
909+
});
910+
});
911+
736912
it('should set the default resource', done => {
737913
const {log} = getTestLog();
738-
739914
const text = 'entry-text';
740915
const entry = log.entry(text);
741-
742916
log.write(entry, err => {
743917
assert.ifError(err);
744-
745918
getEntriesFromLog(log, {numExpectedMessages: 1}, (err, entries) => {
746919
assert.ifError(err);
747920
const entry = entries![0];

0 commit comments

Comments
 (0)