Skip to content

Commit 00df5fc

Browse files
authored
fix(server-utils): Dedupe ioredis orchestrion span for offline-queued commands (#22279)
Offline commands that were drained on connect produced duplicated spans, which we now prevent by just deduping in a `WeakSet`. Saw this when testing locally, this was not catched by e2e before.
1 parent 943b866 commit 00df5fc

3 files changed

Lines changed: 105 additions & 26 deletions

File tree

  • dev-packages/e2e-tests/test-applications/react-router-8-orchestrion/tests
  • packages/server-utils

dev-packages/e2e-tests/test-applications/react-router-8-orchestrion/tests/db.test.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,10 @@ test('Instruments ioredis automatically via orchestrion', async ({ baseURL }) =>
3636
}),
3737
}),
3838
);
39+
40+
// Each command maps to exactly one span (no offline-queue duplicate).
41+
const setSpans = spans.filter(span => span.description === 'set test-key [1 other arguments]');
42+
expect(setSpans).toHaveLength(1);
3943
});
4044

4145
test('Instruments mysql automatically via orchestrion', async ({ baseURL }) => {

packages/server-utils/src/integrations/tracing-channel/ioredis.ts

Lines changed: 40 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,36 @@ function connectionAttributes(host: string | undefined, port: number | undefined
6767
};
6868
}
6969

70+
// ioredis re-enters `sendCommand` with the same command object when it drains
71+
// the offline queue on connect which leads to duplicate spans.
72+
// Track commands we've already traced so each logical command produces one span.
73+
const tracedCommands = new WeakSet<object>();
74+
75+
/**
76+
* Builds the db span for an `orchestrion:ioredis:command` payload, or returns `undefined` to skip
77+
* it: for a non-command payload, or the offline-queue re-send of an already-traced command.
78+
*
79+
* Exported for unit testing.
80+
*/
81+
export function startIORedisCommandSpan(data: IORedisCommandContext): Span | undefined {
82+
const command = data.arguments?.[0] as RedisCommand | undefined;
83+
if (!command || typeof command !== 'object') {
84+
return undefined;
85+
}
86+
// guard against duplicate spans
87+
if (tracedCommands.has(command)) {
88+
return undefined;
89+
}
90+
tracedCommands.add(command);
91+
const { host, port } = getConnectionOptions(data.self);
92+
const statement = defaultDbStatementSerializer(command.name, command.args ?? []);
93+
return startInactiveSpan({
94+
name: statement,
95+
op: 'db',
96+
attributes: { ...connectionAttributes(host, port), [DB_STATEMENT]: statement },
97+
});
98+
}
99+
70100
const _ioredisChannelIntegration = ((options: IORedisChannelIntegrationOptions = {}) => {
71101
const responseHook = options.responseHook;
72102

@@ -92,35 +122,19 @@ const _ioredisChannelIntegration = ((options: IORedisChannelIntegrationOptions =
92122
// binding that `initOpenTelemetry()` registers after integration `setupOnce` —
93123
// defer until it's available (matches the native redis diagnostics-channel subscriber).
94124
waitForTracingChannelBinding(() => {
95-
bindTracingChannelToSpan(
96-
commandChannel,
97-
data => {
125+
bindTracingChannelToSpan(commandChannel, startIORedisCommandSpan, {
126+
// ioredis' `requireParentSpan` default: only create a span under an active span.
127+
requiresParentSpan: true,
128+
beforeSpanEnd(span, data) {
129+
if ('error' in data || !responseHook) {
130+
return;
131+
}
98132
const command = data.arguments?.[0] as RedisCommand | undefined;
99-
if (!command || typeof command !== 'object') {
100-
return undefined;
133+
if (command) {
134+
runResponseHook(responseHook, span, command, data.result);
101135
}
102-
const { host, port } = getConnectionOptions(data.self);
103-
const statement = defaultDbStatementSerializer(command.name, command.args ?? []);
104-
return startInactiveSpan({
105-
name: statement,
106-
op: 'db',
107-
attributes: { ...connectionAttributes(host, port), [DB_STATEMENT]: statement },
108-
});
109136
},
110-
{
111-
// ioredis' `requireParentSpan` default: only create a span under an active span.
112-
requiresParentSpan: true,
113-
beforeSpanEnd(span, data) {
114-
if ('error' in data || !responseHook) {
115-
return;
116-
}
117-
const command = data.arguments?.[0] as RedisCommand | undefined;
118-
if (command) {
119-
runResponseHook(responseHook, span, command, data.result);
120-
}
121-
},
122-
},
123-
);
137+
});
124138

125139
bindTracingChannelToSpan(
126140
connectChannel,
Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,61 @@
1+
import type { Span } from '@sentry/core';
2+
import * as SentryCore from '@sentry/core';
3+
import { afterEach, beforeEach, describe, expect, it, type MockInstance, vi } from 'vitest';
4+
import { startIORedisCommandSpan } from '../../../src/integrations/tracing-channel/ioredis';
5+
6+
const CONNECTION = { host: 'localhost', port: 6379 };
7+
8+
function ctx(command: unknown): { arguments: unknown[]; self: { options: typeof CONNECTION } } {
9+
return { arguments: [command], self: { options: CONNECTION } };
10+
}
11+
12+
describe('startIORedisCommandSpan', () => {
13+
let startInactiveSpanSpy: MockInstance;
14+
15+
beforeEach(() => {
16+
startInactiveSpanSpy = vi.spyOn(SentryCore, 'startInactiveSpan').mockReturnValue({} as Span);
17+
});
18+
19+
afterEach(() => {
20+
vi.restoreAllMocks();
21+
});
22+
23+
it('builds a db span with the orchestrion origin and stable db/net attributes', () => {
24+
startIORedisCommandSpan(ctx({ name: 'set', args: ['test-key', 'test-value'] }));
25+
26+
expect(startInactiveSpanSpy).toHaveBeenCalledWith(
27+
expect.objectContaining({
28+
name: 'set test-key [1 other arguments]',
29+
op: 'db',
30+
attributes: expect.objectContaining({
31+
'db.system': 'redis',
32+
'db.connection_string': 'redis://localhost:6379',
33+
'net.peer.name': 'localhost',
34+
'net.peer.port': 6379,
35+
'db.statement': 'set test-key [1 other arguments]',
36+
'sentry.origin': 'auto.db.orchestrion.redis',
37+
}),
38+
}),
39+
);
40+
});
41+
42+
it('emits a single span when the same command is re-sent from the offline queue', () => {
43+
const command = { name: 'set', args: ['test-key', 'test-value'] };
44+
45+
expect(startIORedisCommandSpan(ctx(command))).toBeDefined();
46+
expect(startIORedisCommandSpan(ctx(command))).toBeUndefined();
47+
expect(startInactiveSpanSpy).toHaveBeenCalledTimes(1);
48+
});
49+
50+
it('spans distinct command objects with the same statement', () => {
51+
startIORedisCommandSpan(ctx({ name: 'get', args: ['k'] }));
52+
startIORedisCommandSpan(ctx({ name: 'get', args: ['k'] }));
53+
54+
expect(startInactiveSpanSpy).toHaveBeenCalledTimes(2);
55+
});
56+
57+
it('skips payloads without a command object', () => {
58+
expect(startIORedisCommandSpan({ arguments: [], self: { options: CONNECTION } })).toBeUndefined();
59+
expect(startInactiveSpanSpy).not.toHaveBeenCalled();
60+
});
61+
});

0 commit comments

Comments
 (0)