Skip to content

Commit f895f09

Browse files
timfishtimfish
authored
fix(node): Pino child loggers (#17934)
This PR: - Includes bindings from child loggers as attributes - Tests that track/untrack setting is propagated to child loggers
1 parent 7333e18 commit f895f09

File tree

4 files changed

+60
-38
lines changed

4 files changed

+60
-38
lines changed

‎dev-packages/node-integration-tests/suites/pino/scenario-track.mjs‎

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,18 @@ Sentry.withIsolationScope(() => {
1717
setTimeout(() => {
1818
Sentry.withIsolationScope(() => {
1919
Sentry.startSpan({ name: 'later' }, () => {
20-
logger.error(new Error('oh no'));
20+
// This child should be captured as we marked the parent logger to be tracked
21+
const child = logger.child({ module: 'authentication' });
22+
child.error(new Error('oh no'));
23+
24+
// This child should be ignored
25+
const child2 = logger.child({ module: 'authentication.v2' });
26+
Sentry.pinoIntegration.untrackLogger(child2);
27+
child2.error(new Error('oh no v2'));
28+
29+
// This should also be ignored as the parent is ignored
30+
const child3 = child2.child({ module: 'authentication.v3' });
31+
child3.error(new Error('oh no v3'));
2132
});
2233
});
2334
}, 1000);

‎dev-packages/node-integration-tests/suites/pino/scenario.mjs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,8 @@ Sentry.withIsolationScope(() => {
1717
setTimeout(() => {
1818
Sentry.withIsolationScope(() => {
1919
Sentry.startSpan({ name: 'later' }, () => {
20-
logger.error(new Error('oh no'));
20+
const child = logger.child({ module: 'authentication' });
21+
child.error(new Error('oh no'));
2122
});
2223
});
2324
}, 1000);

‎dev-packages/node-integration-tests/suites/pino/test.ts‎

Lines changed: 22 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,6 @@ conditionalTest({ min: 20 })('Pino integration', () => {
4545
function: '?',
4646
in_app: true,
4747
module: 'scenario',
48-
context_line: " logger.error(new Error('oh no'));",
4948
}),
5049
]),
5150
},
@@ -63,8 +62,8 @@ conditionalTest({ min: 20 })('Pino integration', () => {
6362
body: 'hello world',
6463
trace_id: expect.any(String),
6564
severity_number: 9,
66-
attributes: expect.objectContaining({
67-
'pino.logger.name': { value: 'myapp', type: 'string' },
65+
attributes: {
66+
name: { value: 'myapp', type: 'string' },
6867
'pino.logger.level': { value: 30, type: 'integer' },
6968
user: { value: 'user-id', type: 'string' },
7069
something: {
@@ -74,22 +73,22 @@ conditionalTest({ min: 20 })('Pino integration', () => {
7473
'sentry.origin': { value: 'auto.logging.pino', type: 'string' },
7574
'sentry.release': { value: '1.0', type: 'string' },
7675
'sentry.sdk.name': { value: 'sentry.javascript.node', type: 'string' },
77-
}),
76+
},
7877
},
7978
{
8079
timestamp: expect.any(Number),
8180
level: 'error',
8281
body: 'oh no',
8382
trace_id: expect.any(String),
8483
severity_number: 17,
85-
attributes: expect.objectContaining({
86-
'pino.logger.name': { value: 'myapp', type: 'string' },
84+
attributes: {
85+
name: { value: 'myapp', type: 'string' },
86+
module: { value: 'authentication', type: 'string' },
8787
'pino.logger.level': { value: 50, type: 'integer' },
88-
err: { value: '{}', type: 'string' },
8988
'sentry.origin': { value: 'auto.logging.pino', type: 'string' },
9089
'sentry.release': { value: '1.0', type: 'string' },
9190
'sentry.sdk.name': { value: 'sentry.javascript.node', type: 'string' },
92-
}),
91+
},
9392
},
9493
],
9594
},
@@ -139,8 +138,8 @@ conditionalTest({ min: 20 })('Pino integration', () => {
139138
body: 'hello world',
140139
trace_id: expect.any(String),
141140
severity_number: 9,
142-
attributes: expect.objectContaining({
143-
'pino.logger.name': { value: 'myapp', type: 'string' },
141+
attributes: {
142+
name: { value: 'myapp', type: 'string' },
144143
'pino.logger.level': { value: 30, type: 'integer' },
145144
user: { value: 'user-id', type: 'string' },
146145
something: {
@@ -150,22 +149,21 @@ conditionalTest({ min: 20 })('Pino integration', () => {
150149
'sentry.origin': { value: 'auto.logging.pino', type: 'string' },
151150
'sentry.release': { value: '1.0', type: 'string' },
152151
'sentry.sdk.name': { value: 'sentry.javascript.node', type: 'string' },
153-
}),
152+
},
154153
},
155154
{
156155
timestamp: expect.any(Number),
157156
level: 'error',
158157
body: 'oh no',
159158
trace_id: expect.any(String),
160159
severity_number: 17,
161-
attributes: expect.objectContaining({
162-
'pino.logger.name': { value: 'myapp', type: 'string' },
160+
attributes: {
161+
name: { value: 'myapp', type: 'string' },
163162
'pino.logger.level': { value: 50, type: 'integer' },
164-
err: { value: '{}', type: 'string' },
165163
'sentry.origin': { value: 'auto.logging.pino', type: 'string' },
166164
'sentry.release': { value: '1.0', type: 'string' },
167165
'sentry.sdk.name': { value: 'sentry.javascript.node', type: 'string' },
168-
}),
166+
},
169167
},
170168
],
171169
},
@@ -189,33 +187,35 @@ conditionalTest({ min: 20 })('Pino integration', () => {
189187
body: 'hello world',
190188
trace_id: expect.any(String),
191189
severity_number: 9,
192-
attributes: expect.objectContaining({
193-
'pino.logger.name': { value: 'myapp', type: 'string' },
190+
attributes: {
191+
name: { value: 'myapp', type: 'string' },
194192
'pino.logger.level': { value: 30, type: 'integer' },
195193
user: { value: 'user-id', type: 'string' },
196194
something: {
197195
type: 'string',
198196
value: '{"more":3,"complex":"nope"}',
199197
},
198+
msg: { value: 'hello world', type: 'string' },
200199
'sentry.origin': { value: 'auto.logging.pino', type: 'string' },
201200
'sentry.release': { value: '1.0', type: 'string' },
202201
'sentry.sdk.name': { value: 'sentry.javascript.node', type: 'string' },
203-
}),
202+
},
204203
},
205204
{
206205
timestamp: expect.any(Number),
207206
level: 'error',
208207
body: 'oh no',
209208
trace_id: expect.any(String),
210209
severity_number: 17,
211-
attributes: expect.objectContaining({
212-
'pino.logger.name': { value: 'myapp', type: 'string' },
210+
attributes: {
211+
name: { value: 'myapp', type: 'string' },
212+
module: { value: 'authentication', type: 'string' },
213+
msg: { value: 'oh no', type: 'string' },
213214
'pino.logger.level': { value: 50, type: 'integer' },
214-
err: { value: '{}', type: 'string' },
215215
'sentry.origin': { value: 'auto.logging.pino', type: 'string' },
216216
'sentry.release': { value: '1.0', type: 'string' },
217217
'sentry.sdk.name': { value: 'sentry.javascript.node', type: 'string' },
218-
}),
218+
},
219219
},
220220
],
221221
},

‎packages/node-core/src/integrations/pino.ts‎

Lines changed: 24 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -81,9 +81,23 @@ type DeepPartial<T> = {
8181
[P in keyof T]?: T[P] extends object ? Partial<T[P]> : T[P];
8282
};
8383

84+
type PinoResult = {
85+
level?: string;
86+
time?: string;
87+
pid?: number;
88+
hostname?: string;
89+
err?: Error;
90+
} & Record<string, unknown>;
91+
92+
function stripIgnoredFields(result: PinoResult): PinoResult {
93+
// eslint-disable-next-line @typescript-eslint/no-unused-vars
94+
const { level, time, pid, hostname, err, ...rest } = result;
95+
return rest;
96+
}
97+
8498
const _pinoIntegration = defineIntegration((userOptions: DeepPartial<PinoOptions> = {}) => {
8599
const options: PinoOptions = {
86-
autoInstrument: userOptions.autoInstrument === false ? userOptions.autoInstrument : DEFAULT_OPTIONS.autoInstrument,
100+
autoInstrument: userOptions.autoInstrument !== false,
87101
error: { ...DEFAULT_OPTIONS.error, ...userOptions.error },
88102
log: { ...DEFAULT_OPTIONS.log, ...userOptions.log },
89103
};
@@ -112,27 +126,23 @@ const _pinoIntegration = defineIntegration((userOptions: DeepPartial<PinoOptions
112126
const injectedChannel = tracingChannel('orchestrion:pino:pino-log');
113127
const integratedChannel = tracingChannel('pino_asJson');
114128

115-
function onPinoStart(self: Pino, args: PinoHookArgs, result: string): void {
129+
function onPinoStart(self: Pino, args: PinoHookArgs, result: PinoResult): void {
116130
if (!shouldTrackLogger(self)) {
117131
return;
118132
}
119133

120-
const [obj, message, levelNumber] = args;
134+
const resultObj = stripIgnoredFields(result);
135+
136+
const [captureObj, message, levelNumber] = args;
121137
const level = self?.levels?.labels?.[levelNumber] || 'info';
122138

123139
if (enableLogs && options.log.levels.includes(level)) {
124140
const attributes: Record<string, unknown> = {
125-
...obj,
141+
...resultObj,
126142
'sentry.origin': 'auto.logging.pino',
127143
'pino.logger.level': levelNumber,
128144
};
129145

130-
const parsedResult = JSON.parse(result) as { name?: string };
131-
132-
if (parsedResult.name) {
133-
attributes['pino.logger.name'] = parsedResult.name;
134-
}
135-
136146
_INTERNAL_captureLog({ level, message, attributes });
137147
}
138148

@@ -153,8 +163,8 @@ const _pinoIntegration = defineIntegration((userOptions: DeepPartial<PinoOptions
153163
return event;
154164
});
155165

156-
if (obj.err) {
157-
captureException(obj.err, captureContext);
166+
if (captureObj.err) {
167+
captureException(captureObj.err, captureContext);
158168
return;
159169
}
160170

@@ -165,7 +175,7 @@ const _pinoIntegration = defineIntegration((userOptions: DeepPartial<PinoOptions
165175

166176
injectedChannel.end.subscribe(data => {
167177
const { self, arguments: args, result } = data as { self: Pino; arguments: PinoHookArgs; result: string };
168-
onPinoStart(self, args, result);
178+
onPinoStart(self, args, JSON.parse(result));
169179
});
170180

171181
integratedChannel.end.subscribe(data => {
@@ -174,7 +184,7 @@ const _pinoIntegration = defineIntegration((userOptions: DeepPartial<PinoOptions
174184
arguments: args,
175185
result,
176186
} = data as { instance: Pino; arguments: PinoHookArgs; result: string };
177-
onPinoStart(instance, args, result);
187+
onPinoStart(instance, args, JSON.parse(result));
178188
});
179189
},
180190
};

0 commit comments

Comments
 (0)