diff --git a/dev-packages/node-integration-tests/suites/tracing/dataloader/test.ts b/dev-packages/node-integration-tests/suites/tracing/dataloader/test.ts index 904ca53a5fc4..dfad54dc5516 100644 --- a/dev-packages/node-integration-tests/suites/tracing/dataloader/test.ts +++ b/dev-packages/node-integration-tests/suites/tracing/dataloader/test.ts @@ -29,6 +29,7 @@ describe('dataloader auto-instrumentation', () => { expect(loadSpan?.status).toBe('ok'); expect(loadSpan?.data?.['sentry.origin']).toBe(ORIGIN); expect(loadSpan?.data?.['sentry.op']).toBe(CACHE_GET_OP); + expect(loadSpan?.data?.['cache.key']).toEqual(['user-1']); // A direct operation is a client call; the deferred `batch` below gets no kind expect(loadSpan?.data?.['otel.kind']).toBe('CLIENT'); @@ -37,6 +38,7 @@ describe('dataloader auto-instrumentation', () => { expect(batchSpan?.op).toBe(CACHE_GET_OP); expect(batchSpan?.origin).toBe(ORIGIN); expect(batchSpan?.status).toBe('ok'); + expect(batchSpan?.data?.['cache.key']).toEqual(['user-1']); expect(batchSpan?.data?.['otel.kind']).toBeUndefined(); // The batch span links back to the load span that triggered it @@ -64,6 +66,7 @@ describe('dataloader auto-instrumentation', () => { expect(loadManySpan?.status).toBe('ok'); expect(loadManySpan?.data?.['sentry.origin']).toBe(ORIGIN); expect(loadManySpan?.data?.['sentry.op']).toBe(CACHE_GET_OP); + expect(loadManySpan?.data?.['cache.key']).toEqual(['user-1', 'user-2']); }, }) .expect({ diff --git a/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-ioredis.mjs b/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-ioredis.mjs index c85e71355538..b758b0384a6a 100644 --- a/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-ioredis.mjs +++ b/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-ioredis.mjs @@ -22,6 +22,8 @@ async function run() { await redis.get('ioredis-cache:unavailable-data'); await redis.mget('test-key', 'ioredis-cache:test-key', 'ioredis-cache:unavailable-data'); + + await redis.del('ioredis-cache:test-key'); } finally { await redis.disconnect(); } diff --git a/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-4.mjs b/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-4.mjs index 55f1982016e1..592602d7222e 100644 --- a/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-4.mjs +++ b/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-4.mjs @@ -27,6 +27,8 @@ async function run() { await redisClient.mGet(['redis-test-key', 'redis-cache:test-key', 'redis-cache:unavailable-data']); + await redisClient.del('redis-cache:test-key'); + // MULTI/EXEC produces one span per queued command, all ended together on exec await redisClient.multi().set('redis-multi-key', 'multi-value').get('redis-multi-key').exec(); diff --git a/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-5.mjs b/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-5.mjs index 994dd291231b..a32aee1c3af2 100644 --- a/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-5.mjs +++ b/dev-packages/node-integration-tests/suites/tracing/redis-cache/scenario-redis-5.mjs @@ -23,6 +23,8 @@ async function run() { await redisClient.mGet(['redis-5-test-key', 'redis-5-cache:test-key', 'redis-5-cache:unavailable-data']); + await redisClient.del('redis-5-cache:test-key'); + // MULTI/EXEC produces one span per queued command, all ended together on exec await redisClient.multi().set('redis-5-multi-key', 'multi-value').get('redis-5-multi-key').exec(); diff --git a/dev-packages/node-integration-tests/suites/tracing/redis-cache/test.ts b/dev-packages/node-integration-tests/suites/tracing/redis-cache/test.ts index 8012fd9062f6..a29edf9287cf 100644 --- a/dev-packages/node-integration-tests/suites/tracing/redis-cache/test.ts +++ b/dev-packages/node-integration-tests/suites/tracing/redis-cache/test.ts @@ -136,6 +136,19 @@ describeWithDockerCompose('redis cache auto instrumentation', { workingDirectory 'network.peer.port': 6383, }), }), + // DEL + expect.objectContaining({ + description: 'ioredis-cache:test-key', + op: 'cache.remove', + origin: redisOrigin, + data: expect.objectContaining({ + 'sentry.origin': redisOrigin, + 'db.statement': 'del ioredis-cache:test-key', + 'cache.key': ['ioredis-cache:test-key'], + 'network.peer.address': 'localhost', + 'network.peer.port': 6383, + }), + }), ]), }; @@ -258,6 +271,17 @@ describeWithDockerCompose('redis cache auto instrumentation', { workingDirectory 'cache.key': ['redis-test-key', 'redis-cache:test-key', 'redis-cache:unavailable-data'], }), }), + // DEL + expect.objectContaining({ + description: 'redis-cache:test-key', + op: 'cache.remove', + origin: redisOrigin, + data: expect.objectContaining({ + 'sentry.origin': redisOrigin, + 'db.statement': 'DEL redis-cache:test-key', + 'cache.key': ['redis-cache:test-key'], + }), + }), ...batchSpans, // a failing command produces a span with an error status expect.objectContaining({ @@ -400,6 +424,17 @@ describeWithDockerCompose('redis cache auto instrumentation', { workingDirectory 'cache.key': ['redis-5-test-key', 'redis-5-cache:test-key', 'redis-5-cache:unavailable-data'], }), }), + // DEL + expect.objectContaining({ + description: 'redis-5-cache:test-key', + op: 'cache.remove', + origin: redisOrigin, + data: expect.objectContaining({ + 'sentry.origin': redisOrigin, + 'db.statement': 'DEL redis-5-cache:test-key', + 'cache.key': ['redis-5-cache:test-key'], + }), + }), ...batchSpans, // a failing command produces a span with an error status expect.objectContaining({ diff --git a/packages/node/src/integrations/tracing/dataloader/vendored/instrumentation.ts b/packages/node/src/integrations/tracing/dataloader/vendored/instrumentation.ts index 4412510a1906..9d37febcb8a1 100644 --- a/packages/node/src/integrations/tracing/dataloader/vendored/instrumentation.ts +++ b/packages/node/src/integrations/tracing/dataloader/vendored/instrumentation.ts @@ -9,6 +9,7 @@ */ import { InstrumentationBase, InstrumentationNodeModuleDefinition, isWrapped } from '@opentelemetry/instrumentation'; +import { CACHE_KEY } from '@sentry/conventions/attributes'; import type { BatchLoadFn, DataLoader, DataLoaderConstructor } from './types'; import { SDK_VERSION, @@ -59,6 +60,16 @@ function getSpanOp(operation: 'load' | 'loadMany' | 'batch' | 'prime' | 'clear' return undefined; } +// `load` receives a single key, `loadMany`/`batch` receive a key array. Normalize both to the +// `string[]` shape `cache.key` expects. +function getCacheKey(keyArg: unknown): string[] | undefined { + if (Array.isArray(keyArg)) { + return keyArg.map(key => String(key)); + } + + return keyArg == null ? undefined : [String(keyArg)]; +} + export class DataloaderInstrumentation extends InstrumentationBase { constructor(config = {}) { super(PACKAGE_NAME, SDK_VERSION, config); @@ -107,6 +118,7 @@ export class DataloaderInstrumentation extends InstrumentationBase { attributes: { [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: ORIGIN, [SEMANTIC_ATTRIBUTE_SENTRY_OP]: getSpanOp('batch'), + [CACHE_KEY]: getCacheKey(args[0]), }, onlyIfParent: true, }, @@ -161,6 +173,7 @@ export class DataloaderInstrumentation extends InstrumentationBase { attributes: { [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: ORIGIN, [SEMANTIC_ATTRIBUTE_SENTRY_OP]: getSpanOp('load'), + [CACHE_KEY]: getCacheKey(args[0]), }, onlyIfParent: true, }, @@ -199,6 +212,7 @@ export class DataloaderInstrumentation extends InstrumentationBase { attributes: { [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: ORIGIN, [SEMANTIC_ATTRIBUTE_SENTRY_OP]: getSpanOp('loadMany'), + [CACHE_KEY]: getCacheKey(args[0]), }, onlyIfParent: true, }, diff --git a/packages/node/src/integrations/tracing/redis/cache.ts b/packages/node/src/integrations/tracing/redis/cache.ts index 9d9d505fcda4..dcfae6bb5f42 100644 --- a/packages/node/src/integrations/tracing/redis/cache.ts +++ b/packages/node/src/integrations/tracing/redis/cache.ts @@ -14,6 +14,7 @@ import { getCacheKeySafely, getCacheOperation, isInCommands, + REMOVE_COMMANDS, shouldConsiderForCache, } from '../../../utils/redisCache'; import type { IORedisResponseCustomAttributeFunction } from './vendored/types'; @@ -79,7 +80,8 @@ export const cacheResponseHook: IORedisResponseCustomAttributeFunction = ( span.setAttributes({ 'network.peer.address': networkPeerAddress, 'network.peer.port': networkPeerPort }); } - const cacheItemSize = calculateCacheItemSize(response); + // A remove response is a delete-count, not a cached value, so its size is meaningless. + const cacheItemSize = isInCommands(REMOVE_COMMANDS, redisCommand) ? undefined : calculateCacheItemSize(response); if (cacheItemSize) { span.setAttribute(SEMANTIC_ATTRIBUTE_CACHE_ITEM_SIZE, cacheItemSize); diff --git a/packages/node/src/utils/redisCache.ts b/packages/node/src/utils/redisCache.ts index 60e8218efdeb..fc260575bf21 100644 --- a/packages/node/src/utils/redisCache.ts +++ b/packages/node/src/utils/redisCache.ts @@ -4,7 +4,8 @@ const SINGLE_ARG_COMMANDS = ['get', 'set', 'setex']; export const GET_COMMANDS = ['get', 'mget']; export const SET_COMMANDS = ['set', 'setex']; -// todo: del, expire +export const REMOVE_COMMANDS = ['del', 'unlink']; +// todo: expire (no matching cache convention op yet) /** Checks if a given command is in the list of redis commands. * Useful because commands can come in lowercase or uppercase (depending on the library). */ @@ -13,13 +14,13 @@ export function isInCommands(redisCommands: string[], command: string): boolean } /** Determine cache operation based on redis statement */ -export function getCacheOperation( - command: string, -): 'cache.get' | 'cache.put' | 'cache.remove' | 'cache.flush' | undefined { +export function getCacheOperation(command: string): 'cache.get' | 'cache.put' | 'cache.remove' | undefined { if (isInCommands(GET_COMMANDS, command)) { return 'cache.get'; } else if (isInCommands(SET_COMMANDS, command)) { return 'cache.put'; + } else if (isInCommands(REMOVE_COMMANDS, command)) { + return 'cache.remove'; } else { return undefined; } diff --git a/packages/node/test/integrations/tracing/redis.test.ts b/packages/node/test/integrations/tracing/redis.test.ts index 0eb31d6aea5f..eb19739d2f46 100644 --- a/packages/node/test/integrations/tracing/redis.test.ts +++ b/packages/node/test/integrations/tracing/redis.test.ts @@ -4,6 +4,7 @@ import { calculateCacheItemSize, GET_COMMANDS, getCacheKeySafely, + REMOVE_COMMANDS, SET_COMMANDS, shouldConsiderForCache, } from '../../../src/utils/redisCache'; @@ -256,7 +257,7 @@ describe('Redis', () => { expect(result).toBe(false); }); - GET_COMMANDS.concat(SET_COMMANDS).forEach(command => { + GET_COMMANDS.concat(SET_COMMANDS, REMOVE_COMMANDS).forEach(command => { it(`should return true for ${command} command with matching prefix`, () => { const key = ['cache:test-key']; const result = shouldConsiderForCache(command, key, prefixes); diff --git a/packages/server-utils/src/integrations/tracing-channel/dataloader.ts b/packages/server-utils/src/integrations/tracing-channel/dataloader.ts index 80b998ab11e5..5c951b2465c8 100644 --- a/packages/server-utils/src/integrations/tracing-channel/dataloader.ts +++ b/packages/server-utils/src/integrations/tracing-channel/dataloader.ts @@ -1,4 +1,5 @@ import * as diagnosticsChannel from 'node:diagnostics_channel'; +import { CACHE_KEY } from '@sentry/conventions/attributes'; import type { IntegrationFn, Span, StartSpanOptions } from '@sentry/core'; import { debug, @@ -61,7 +62,21 @@ function getSpanName(loader: DataLoaderInstance | undefined, operation: Operatio return name ? `${MODULE_NAME}.${operation} ${name}` : `${MODULE_NAME}.${operation}`; } -function makeSpanOptions(loader: DataLoaderInstance | undefined, operation: Operation): StartSpanOptions { +// `load` receives a single key, `loadMany`/`batch` receive a key array. Normalize both to the +// `string[]` shape `cache.key` expects. +function getCacheKey(keyArg: unknown): string[] | undefined { + if (Array.isArray(keyArg)) { + return keyArg.map(key => String(key)); + } + + return keyArg == null ? undefined : [String(keyArg)]; +} + +function makeSpanOptions( + loader: DataLoaderInstance | undefined, + operation: Operation, + keyArg?: unknown, +): StartSpanOptions { const isCacheGet = operation === 'load' || operation === 'loadMany' || operation === 'batch'; return { @@ -74,6 +89,7 @@ function makeSpanOptions(loader: DataLoaderInstance | undefined, operation: Oper onlyIfParent: true, attributes: { [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: ORIGIN, + [CACHE_KEY]: isCacheGet ? getCacheKey(keyArg) : undefined, }, }; } @@ -117,7 +133,8 @@ function subscribeConstruct(): void { const original = batchLoadFn as (...args: unknown[]) => unknown; const wrapped = function (this: DataLoaderInstance, ...args: unknown[]): unknown { - return startSpan({ ...makeSpanOptions(this, 'batch'), links: this._batch?.spanLinks }, () => + // `batchLoadFn` receives the batched keys as its first argument. + return startSpan({ ...makeSpanOptions(this, 'batch', args[0]), links: this._batch?.spanLinks }, () => original.apply(this, args), ); }; @@ -139,7 +156,9 @@ function subscribeConstruct(): void { function subscribeLoad(): void { const channel = diagnosticsChannel.tracingChannel(CHANNELS.DATALOADER_LOAD); - bindTracingChannelToSpan(channel, data => startInactiveSpanFor(data.self, 'load'), { requiresParentSpan: true }); + bindTracingChannelToSpan(channel, data => startInactiveSpanFor(data.self, 'load', data.arguments[0]), { + requiresParentSpan: true, + }); channel.end.subscribe(message => { const data = message as TracingChannelPayloadWithSpan; @@ -154,13 +173,13 @@ function subscribeLoad(): void { function subscribeSimpleOperation(channelName: ChannelName, operation: Operation): void { bindTracingChannelToSpan( diagnosticsChannel.tracingChannel(channelName), - data => startInactiveSpanFor(data.self, operation), + data => startInactiveSpanFor(data.self, operation, data.arguments[0]), { requiresParentSpan: true }, ); } -function startInactiveSpanFor(loader: DataLoaderInstance | undefined, operation: Operation): Span { - return startInactiveSpan(makeSpanOptions(loader, operation)); +function startInactiveSpanFor(loader: DataLoaderInstance | undefined, operation: Operation, keyArg?: unknown): Span { + return startInactiveSpan(makeSpanOptions(loader, operation, keyArg)); } /**