diff --git a/CHANGELOG.md b/CHANGELOG.md index bee92f0e3c..8ac5cd72d7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,10 @@ ## Unreleased +### Fixes + +- Create profiles for start up transactions ([#3281](https://github.com/getsentry/sentry-react-native/pull/3281)) + ### Dependencies - Bump CLI from v2.20.5 to v2.20.7 ([#3265](https://github.com/getsentry/sentry-react-native/pull/3265), [#3273](https://github.com/getsentry/sentry-react-native/pull/3273)) diff --git a/src/js/profiling/integration.ts b/src/js/profiling/integration.ts index a129dc1bdd..aeb402ede7 100644 --- a/src/js/profiling/integration.ts +++ b/src/js/profiling/integration.ts @@ -1,4 +1,6 @@ -import type { Envelope, Event, EventProcessor, Hub, Integration, Profile, Transaction } from '@sentry/types'; +import type { Hub } from '@sentry/core'; +import { getActiveTransaction } from '@sentry/core'; +import type { Envelope, Event, EventProcessor, Integration, Profile, Transaction } from '@sentry/types'; import { logger, uuid4 } from '@sentry/utils'; import { isHermesEnabled } from '../utils/environment'; @@ -51,21 +53,10 @@ export class HermesProfiling implements Integration { return; } - client.on('startTransaction', (transaction: Transaction) => { - this._finishCurrentProfile(); + this._startCurrentProfileForActiveTransaction(); + client.on('startTransaction', this._startCurrentProfile); - const shouldStartProfiling = this._shouldStartProfiling(transaction); - if (!shouldStartProfiling) { - return; - } - - this._currentProfileTimeout = setTimeout(this._finishCurrentProfile, MAX_PROFILE_DURATION_MS); - this._startNewProfile(transaction); - }); - - client.on('finishTransaction', () => { - this._finishCurrentProfile(); - }); + client.on('finishTransaction', this._finishCurrentProfile); client.on('beforeEnvelope', (envelope: Envelope) => { if (!PROFILE_QUEUE.size()) { @@ -89,6 +80,26 @@ export class HermesProfiling implements Integration { }); } + private _startCurrentProfileForActiveTransaction = (): void => { + if (this._currentProfile) { + return; + } + const transaction = this._getCurrentHub && getActiveTransaction(this._getCurrentHub()); + transaction && this._startCurrentProfile(transaction); + }; + + private _startCurrentProfile = (transaction: Transaction): void => { + this._finishCurrentProfile(); + + const shouldStartProfiling = this._shouldStartProfiling(transaction); + if (!shouldStartProfiling) { + return; + } + + this._currentProfileTimeout = setTimeout(this._finishCurrentProfile, MAX_PROFILE_DURATION_MS); + this._startNewProfile(transaction); + }; + private _shouldStartProfiling = (transaction: Transaction): boolean => { if (!transaction.sampled) { logger.log('[Profiling] Transaction is not sampled, skipping profiling'); diff --git a/src/js/sdk.tsx b/src/js/sdk.tsx index 7893f0dfff..4cc6571c49 100644 --- a/src/js/sdk.tsx +++ b/src/js/sdk.tsx @@ -121,6 +121,9 @@ export function init(passedOptions: ReactNativeOptions): void { if (options.enableNative) { defaultIntegrations.push(new DeviceContext()); } + if (options._experiments && typeof options._experiments.profilesSampleRate === 'number') { + defaultIntegrations.push(new HermesProfiling()); + } if (hasTracingEnabled(options) && options.enableAutoPerformanceTracing) { defaultIntegrations.push(new ReactNativeTracing()); } @@ -133,9 +136,6 @@ export function init(passedOptions: ReactNativeOptions): void { if (options.enableCaptureFailedRequests) { defaultIntegrations.push(new HttpClient()); } - if (options._experiments && typeof options._experiments.profilesSampleRate === 'number') { - defaultIntegrations.push(new HermesProfiling()); - } } options.integrations = getIntegrationsToSetup({ diff --git a/test/profiling/integration.test.ts b/test/profiling/integration.test.ts index 5fc83df271..c8559feba2 100644 --- a/test/profiling/integration.test.ts +++ b/test/profiling/integration.test.ts @@ -2,6 +2,7 @@ import * as mockWrapper from '../mockWrapper'; jest.mock('../../src/js/wrapper', () => mockWrapper); jest.mock('../../src/js/utils/environment'); +import { getCurrentHub } from '@sentry/core'; import type { Envelope, Event, Profile, Transaction, Transport } from '@sentry/types'; import * as Sentry from '../../src/js'; @@ -24,9 +25,6 @@ describe('profiling integration', () => { mockWrapper.NATIVE.startProfiling.mockReturnValue(true); mockWrapper.NATIVE.stopProfiling.mockReturnValue(createMockMinimalValidHermesProfile()); jest.useFakeTimers(); - mock = initTestClient(); - jest.runAllTimers(); - jest.clearAllMocks(); }); afterEach(async () => { @@ -36,12 +34,19 @@ describe('profiling integration', () => { await Sentry.close(); }); - test('should create a new profile and add in to the transaction envelope', () => { + test('should start profile if there is a transaction running when integration is created', () => { + mock = initTestClient(false); + jest.runAllTimers(); + jest.clearAllMocks(); + const transaction: Transaction = Sentry.startTransaction({ name: 'test-name', }); - transaction.finish(); + getCurrentHub().getScope()?.setSpan(transaction); + + getCurrentHub().getClient()?.addIntegration?.(new HermesProfiling()); + transaction.finish(); jest.runAllTimers(); const envelope: Envelope | undefined = mock.transportSendMock.mock.lastCall?.[0]; @@ -60,122 +65,158 @@ describe('profiling integration', () => { ]); }); - test('should finish previous profile when a new transaction starts', () => { - const transaction1: Transaction = Sentry.startTransaction({ - name: 'test-name-1', - }); - const transaction2: Transaction = Sentry.startTransaction({ - name: 'test-name-2', + describe('with profiling enabled', () => { + beforeEach(() => { + mock = initTestClient(); + jest.runAllTimers(); + jest.clearAllMocks(); }); - transaction1.finish(); - transaction2.finish(); - jest.runAllTimers(); - - const envelopeTransaction1: Envelope | undefined = mock.transportSendMock.mock.calls[0][0]; - const transaction1EnvelopeItemPayload = envelopeTransaction1?.[envelopeItems][0][envelopeItemPayload] as Event; - const profile1EnvelopeItem = envelopeTransaction1?.[envelopeItems][1] as [{ type: 'profile' }, Profile] | undefined; - - const envelopeTransaction2: Envelope | undefined = mock.transportSendMock.mock.calls[1][0]; - const transaction2EnvelopeItemPayload = envelopeTransaction2?.[envelopeItems][0][envelopeItemPayload] as Event; - const profile2EnvelopeItem = envelopeTransaction2?.[envelopeItems][1] as [{ type: 'profile' }, Profile] | undefined; + test('should create a new profile and add in to the transaction envelope', () => { + const transaction: Transaction = Sentry.startTransaction({ + name: 'test-name', + }); + transaction.finish(); + + jest.runAllTimers(); + + const envelope: Envelope | undefined = mock.transportSendMock.mock.lastCall?.[0]; + const transactionEnvelopeItemPayload = envelope?.[envelopeItems][0][envelopeItemPayload] as Event; + const profileEnvelopeItem = envelope?.[envelopeItems][1] as [{ type: 'profile' }, Profile]; + expect(profileEnvelopeItem).toEqual([ + { type: 'profile' }, + expect.objectContaining>({ + event_id: expect.any(String), + transaction: expect.objectContaining({ + name: 'test-name', + id: transactionEnvelopeItemPayload.event_id, + trace_id: transaction.traceId, + }), + }), + ]); + }); - expect(profile1EnvelopeItem).toEqual([ - { type: 'profile' }, - expect.objectContaining>({ - event_id: expect.any(String), - transaction: expect.objectContaining({ - name: 'test-name-1', - id: transaction1EnvelopeItemPayload.event_id, - trace_id: transaction1.traceId, + test('should finish previous profile when a new transaction starts', () => { + const transaction1: Transaction = Sentry.startTransaction({ + name: 'test-name-1', + }); + const transaction2: Transaction = Sentry.startTransaction({ + name: 'test-name-2', + }); + transaction1.finish(); + transaction2.finish(); + + jest.runAllTimers(); + + const envelopeTransaction1: Envelope | undefined = mock.transportSendMock.mock.calls[0][0]; + const transaction1EnvelopeItemPayload = envelopeTransaction1?.[envelopeItems][0][envelopeItemPayload] as Event; + const profile1EnvelopeItem = envelopeTransaction1?.[envelopeItems][1] as + | [{ type: 'profile' }, Profile] + | undefined; + + const envelopeTransaction2: Envelope | undefined = mock.transportSendMock.mock.calls[1][0]; + const transaction2EnvelopeItemPayload = envelopeTransaction2?.[envelopeItems][0][envelopeItemPayload] as Event; + const profile2EnvelopeItem = envelopeTransaction2?.[envelopeItems][1] as + | [{ type: 'profile' }, Profile] + | undefined; + + expect(profile1EnvelopeItem).toEqual([ + { type: 'profile' }, + expect.objectContaining>({ + event_id: expect.any(String), + transaction: expect.objectContaining({ + name: 'test-name-1', + id: transaction1EnvelopeItemPayload.event_id, + trace_id: transaction1.traceId, + }), }), - }), - ]); - expect(profile2EnvelopeItem).toEqual([ - { type: 'profile' }, - expect.objectContaining>({ - event_id: expect.any(String), - transaction: expect.objectContaining({ - name: 'test-name-2', - id: transaction2EnvelopeItemPayload.event_id, - trace_id: transaction2.traceId, + ]); + expect(profile2EnvelopeItem).toEqual([ + { type: 'profile' }, + expect.objectContaining>({ + event_id: expect.any(String), + transaction: expect.objectContaining({ + name: 'test-name-2', + id: transaction2EnvelopeItemPayload.event_id, + trace_id: transaction2.traceId, + }), }), - }), - ]); - }); - - test('profile should start at the same time as transaction', () => { - const transaction: Transaction = Sentry.startTransaction({ - name: 'test-name', + ]); }); - transaction.finish(); - jest.runAllTimers(); + test('profile should start at the same time as transaction', () => { + const transaction: Transaction = Sentry.startTransaction({ + name: 'test-name', + }); + transaction.finish(); - const envelope: Envelope | undefined = mock.transportSendMock.mock.lastCall?.[0]; - const transactionEnvelopeItemPayload = envelope?.[envelopeItems][0][envelopeItemPayload] as Event; - const profileEnvelopeItemPayload = envelope?.[envelopeItems][1][envelopeItemPayload] as unknown as Profile; - const transactionStart = Math.floor(transactionEnvelopeItemPayload.start_timestamp! * SEC_TO_MS); - const profileStart = new Date(profileEnvelopeItemPayload.timestamp).getTime(); - expect(profileStart - transactionStart).toBeLessThan(10); - }); + jest.runAllTimers(); - test('profile is only recorded until max duration is reached', () => { - const transaction: Transaction = Sentry.startTransaction({ - name: 'test-name', + const envelope: Envelope | undefined = mock.transportSendMock.mock.lastCall?.[0]; + const transactionEnvelopeItemPayload = envelope?.[envelopeItems][0][envelopeItemPayload] as Event; + const profileEnvelopeItemPayload = envelope?.[envelopeItems][1][envelopeItemPayload] as unknown as Profile; + const transactionStart = Math.floor(transactionEnvelopeItemPayload.start_timestamp! * SEC_TO_MS); + const profileStart = new Date(profileEnvelopeItemPayload.timestamp).getTime(); + expect(profileStart - transactionStart).toBeLessThan(10); }); - jest.clearAllMocks(); - jest.advanceTimersByTime(40 * 1e6); + test('profile is only recorded until max duration is reached', () => { + const transaction: Transaction = Sentry.startTransaction({ + name: 'test-name', + }); + jest.clearAllMocks(); - expect(mockWrapper.NATIVE.stopProfiling.mock.calls.length).toEqual(1); + jest.advanceTimersByTime(40 * 1e6); - transaction.finish(); - }); + expect(mockWrapper.NATIVE.stopProfiling.mock.calls.length).toEqual(1); - test('profile that reached max duration is sent', () => { - const transaction: Transaction = Sentry.startTransaction({ - name: 'test-name', + transaction.finish(); }); - jest.advanceTimersByTime(40 * 1e6); - - transaction.finish(); - - jest.runAllTimers(); - - const envelope: Envelope | undefined = mock.transportSendMock.mock.lastCall?.[0]; - const transactionEnvelopeItemPayload = envelope?.[envelopeItems][0][envelopeItemPayload] as Event; - const profileEnvelopeItem = envelope?.[envelopeItems][1] as [{ type: 'profile' }, Profile]; - expect(profileEnvelopeItem).toEqual([ - { type: 'profile' }, - expect.objectContaining>({ - event_id: expect.any(String), - transaction: expect.objectContaining({ - name: 'test-name', - id: transactionEnvelopeItemPayload.event_id, - trace_id: transaction.traceId, + test('profile that reached max duration is sent', () => { + const transaction: Transaction = Sentry.startTransaction({ + name: 'test-name', + }); + + jest.advanceTimersByTime(40 * 1e6); + + transaction.finish(); + + jest.runAllTimers(); + + const envelope: Envelope | undefined = mock.transportSendMock.mock.lastCall?.[0]; + const transactionEnvelopeItemPayload = envelope?.[envelopeItems][0][envelopeItemPayload] as Event; + const profileEnvelopeItem = envelope?.[envelopeItems][1] as [{ type: 'profile' }, Profile]; + expect(profileEnvelopeItem).toEqual([ + { type: 'profile' }, + expect.objectContaining>({ + event_id: expect.any(String), + transaction: expect.objectContaining({ + name: 'test-name', + id: transactionEnvelopeItemPayload.event_id, + trace_id: transaction.traceId, + }), }), - }), - ]); - }); - - test('profile timeout is reset when transaction is finished', () => { - const integration = getCurrentHermesProfilingIntegration(); - const transaction: Transaction = Sentry.startTransaction({ - name: 'test-name', + ]); }); - const timeoutAfterProfileStarted = integration._currentProfileTimeout; - jest.advanceTimersByTime(40 * 1e6); + test('profile timeout is reset when transaction is finished', () => { + const integration = getCurrentHermesProfilingIntegration(); + const transaction: Transaction = Sentry.startTransaction({ + name: 'test-name', + }); + const timeoutAfterProfileStarted = integration._currentProfileTimeout; - transaction.finish(); - const timeoutAfterProfileFinished = integration._currentProfileTimeout; + jest.advanceTimersByTime(40 * 1e6); - jest.runAllTimers(); + transaction.finish(); + const timeoutAfterProfileFinished = integration._currentProfileTimeout; + + jest.runAllTimers(); - expect(timeoutAfterProfileStarted).toBeDefined(); - expect(timeoutAfterProfileFinished).toBeUndefined(); + expect(timeoutAfterProfileStarted).toBeDefined(); + expect(timeoutAfterProfileFinished).toBeUndefined(); + }); }); }); @@ -190,7 +231,7 @@ function getCurrentHermesProfilingIntegration(): TestHermesIntegration { return integration as unknown as TestHermesIntegration; } -function initTestClient(): { +function initTestClient(withProfiling: boolean = true): { transportSendMock: jest.Mock, Parameters>; } { const transportSendMock = jest.fn, Parameters>(); @@ -199,6 +240,12 @@ function initTestClient(): { _experiments: { profilesSampleRate: 1, }, + integrations: integrations => { + if (!withProfiling) { + return integrations.filter(i => i.name !== 'HermesProfiling'); + } + return integrations; + }, transport: () => ({ send: transportSendMock.mockResolvedValue(undefined), flush: jest.fn().mockResolvedValue(true),