Skip to content

fix(browser): correct timestamp on pageload profiles #9350

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 2 commits into from
Oct 24, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 8 additions & 2 deletions packages/browser/src/profiling/hubextensions.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
/* eslint-disable complexity */
import type { Transaction } from '@sentry/types';
import { logger, uuid4 } from '@sentry/utils';
import { logger, timestampInSeconds, uuid4 } from '@sentry/utils';

import { WINDOW } from '../helpers';
import type { JSSelfProfile } from './jsSelfProfiling';
import {
addProfileToGlobalCache,
isAutomatedPageLoadTransaction,
MAX_PROFILE_DURATION_MS,
shouldProfileTransaction,
startJSSelfProfile,
Expand Down Expand Up @@ -40,6 +41,11 @@ export function onProfilingStartRouteTransaction(transaction: Transaction | unde
*/
export function startProfileForTransaction(transaction: Transaction): Transaction {
// Start the profiler and get the profiler instance.
let startTimestamp: number | undefined;
if (isAutomatedPageLoadTransaction(transaction)) {
startTimestamp = timestampInSeconds() * 1000;
}

const profiler = startJSSelfProfile();

// We failed to construct the profiler, fallback to original transaction.
Expand Down Expand Up @@ -151,7 +157,7 @@ export function startProfileForTransaction(transaction: Transaction): Transactio
// Always call onProfileHandler to ensure stopProfiling is called and the timeout is cleared.
void onProfileHandler().then(
() => {
transaction.setContext('profile', { profile_id: profileId });
transaction.setContext('profile', { profile_id: profileId, start_timestamp: startTimestamp });
originalFinish();
},
() => {
Expand Down
8 changes: 7 additions & 1 deletion packages/browser/src/profiling/integration.ts
Original file line number Diff line number Diff line change
Expand Up @@ -75,6 +75,7 @@ export class BrowserProfilingIntegration implements Integration {
for (const profiledTransaction of profiledTransactionEvents) {
const context = profiledTransaction && profiledTransaction.contexts;
const profile_id = context && context['profile'] && context['profile']['profile_id'];
const start_timestamp = context && context['profile'] && context['profile']['start_timestamp'];

if (typeof profile_id !== 'string') {
__DEBUG_BUILD__ &&
Expand All @@ -99,7 +100,12 @@ export class BrowserProfilingIntegration implements Integration {
continue;
}

const profileEvent = createProfilingEvent(profile_id, profile, profiledTransaction as ProfiledEvent);
const profileEvent = createProfilingEvent(
profile_id,
start_timestamp as number | undefined,
profile,
profiledTransaction as ProfiledEvent,
);
if (profileEvent) {
profilesToAddToEnvelope.push(profileEvent);
}
Expand Down
28 changes: 19 additions & 9 deletions packages/browser/src/profiling/utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -119,25 +119,30 @@ function getTraceId(event: Event): string {
* Creates a profiling event envelope from a Sentry event.
*/
export function createProfilePayload(
event: ProfiledEvent,
processedProfile: JSSelfProfile,
profile_id: string,
start_timestamp: number | undefined,
processed_profile: JSSelfProfile,
event: ProfiledEvent,
): Profile {
if (event.type !== 'transaction') {
// createProfilingEventEnvelope should only be called for transactions,
// we type guard this behavior with isProfiledTransactionEvent.
throw new TypeError('Profiling events may only be attached to transactions, this should never occur.');
}

if (processedProfile === undefined || processedProfile === null) {
if (processed_profile === undefined || processed_profile === null) {
throw new TypeError(
`Cannot construct profiling event envelope without a valid profile. Got ${processedProfile} instead.`,
`Cannot construct profiling event envelope without a valid profile. Got ${processed_profile} instead.`,
);
}

const traceId = getTraceId(event);
const enrichedThreadProfile = enrichWithThreadInformation(processedProfile);
const transactionStartMs = typeof event.start_timestamp === 'number' ? event.start_timestamp * 1000 : Date.now();
const enrichedThreadProfile = enrichWithThreadInformation(processed_profile);
const transactionStartMs = start_timestamp
? start_timestamp
: typeof event.start_timestamp === 'number'
? event.start_timestamp * 1000
: Date.now();
const transactionEndMs = typeof event.timestamp === 'number' ? event.timestamp * 1000 : Date.now();

const profile: Profile = {
Expand All @@ -164,7 +169,7 @@ export function createProfilePayload(
is_emulator: false,
},
debug_meta: {
images: applyDebugMetadata(processedProfile.resources),
images: applyDebugMetadata(processed_profile.resources),
},
profile: enrichedThreadProfile,
transactions: [
Expand Down Expand Up @@ -575,12 +580,17 @@ export function shouldProfileTransaction(transaction: Transaction): boolean {
* @param event
* @returns {Profile | null}
*/
export function createProfilingEvent(profile_id: string, profile: JSSelfProfile, event: ProfiledEvent): Profile | null {
export function createProfilingEvent(
profile_id: string,
start_timestamp: number | undefined,
profile: JSSelfProfile,
event: ProfiledEvent,
): Profile | null {
if (!isValidProfile(profile)) {
return null;
}

return createProfilePayload(event, profile, profile_id);
return createProfilePayload(profile_id, start_timestamp, profile, event);
}

const PROFILE_MAP: Map<string, JSSelfProfile> = new Map();
Expand Down
10 changes: 5 additions & 5 deletions packages/browser/test/unit/profiling/integration.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,11 +5,6 @@ import { BrowserProfilingIntegration } from '../../../src/profiling/integration'
import type { JSSelfProfile } from '../../../src/profiling/jsSelfProfiling';

describe('BrowserProfilingIntegration', () => {
beforeEach(() => {
jest.clearAllMocks();
jest.useRealTimers();
// We will mock the carrier as if it has been initialized by the SDK, else everything is short circuited
});
it('pageload profiles follow regular transaction code path', async () => {
const stopProfile = jest.fn().mockImplementation((): Promise<JSSelfProfile> => {
return Promise.resolve({
Expand Down Expand Up @@ -63,6 +58,11 @@ describe('BrowserProfilingIntegration', () => {
expect(send).toHaveBeenCalledTimes(1);

const profile = send.mock.calls?.[0]?.[0]?.[1]?.[1]?.[1];
const transaction = send.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1];
const profile_timestamp_ms = new Date(profile.timestamp).getTime();
const transaction_timestamp_ms = new Date(transaction.start_timestamp * 1e3).getTime();

expect(profile_timestamp_ms).toBeGreaterThan(transaction_timestamp_ms);
expect(profile.profile.frames[0]).toMatchObject({ function: 'pageload_fn', lineno: 1, colno: 1 });
});
});