From 9fb27eef8aff044cc80afc020a4fb78eb382f983 Mon Sep 17 00:00:00 2001 From: Test Date: Fri, 23 Oct 2026 11:45:12 +0200 Subject: [PATCH 1/4] [No QA] Add flash, capture method and time since app start to the shutter-to-confirmation span --- src/libs/telemetry/nativeAppStartTime.ts | 14 +++++++++++ .../components/Camera/index.native.tsx | 19 +++++++++++---- src/setup/telemetry/index.native.ts | 2 ++ tests/unit/telemetryStartupMarkersTest.ts | 24 +++++++++++++++++++ 4 files changed, 54 insertions(+), 5 deletions(-) create mode 100644 src/libs/telemetry/nativeAppStartTime.ts diff --git a/src/libs/telemetry/nativeAppStartTime.ts b/src/libs/telemetry/nativeAppStartTime.ts new file mode 100644 index 000000000000..01dd92e14dff --- /dev/null +++ b/src/libs/telemetry/nativeAppStartTime.ts @@ -0,0 +1,14 @@ +let nativeAppStartTimeMs: number | undefined; + +function setNativeAppStartTime(timestampMs: number | undefined) { + nativeAppStartTimeMs = timestampMs; +} + +function getMsSinceNativeAppStart(): number | undefined { + if (nativeAppStartTimeMs === undefined) { + return undefined; + } + return Math.round(Date.now() - nativeAppStartTimeMs); +} + +export {getMsSinceNativeAppStart, setNativeAppStartTime}; diff --git a/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx b/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx index bf2a16230c85..93f698e5157c 100644 --- a/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx +++ b/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx @@ -15,6 +15,7 @@ import HapticFeedback from '@libs/HapticFeedback'; import Log from '@libs/Log'; import ReceiptStorage from '@libs/ReceiptStorage'; import {cancelSpan, endSpanWithAttributes, getSpan, startSpan} from '@libs/telemetry/activeSpans'; +import {getMsSinceNativeAppStart} from '@libs/telemetry/nativeAppStartTime'; import captureReceipt, {shouldTakePhoto} from '@pages/iou/request/step/IOURequestStepScan/captureReceipt'; import CameraPermissionPrompt from '@pages/iou/request/step/IOURequestStepScan/components/CameraPermissionPrompt'; @@ -126,11 +127,22 @@ function Camera({onCapture, onPicked, shouldAcceptMultipleFiles = false, onLayou }; const capturePhoto = () => { + const isPhotoCapture = shouldTakePhoto({flash, hasFlash, isInLandscapeMode}); + const captureAttributes = { + [CONST.TELEMETRY.ATTRIBUTE_CAPTURE_METHOD]: isPhotoCapture ? CONST.TELEMETRY.CAPTURE_METHOD.PHOTO : CONST.TELEMETRY.CAPTURE_METHOD.SNAPSHOT, + [CONST.TELEMETRY.ATTRIBUTE_FLASH_USED]: flash && hasFlash, + }; + if (!isMultiScanEnabled) { + const msSinceNativeAppStart = getMsSinceNativeAppStart(); startSpan(CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION, { name: CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION, op: CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION, - attributes: {[CONST.TELEMETRY.ATTRIBUTE_PLATFORM]: CONST.TELEMETRY.SPAN_PLATFORM.NATIVE}, + attributes: { + [CONST.TELEMETRY.ATTRIBUTE_PLATFORM]: CONST.TELEMETRY.SPAN_PLATFORM.NATIVE, + ...captureAttributes, + ...(msSinceNativeAppStart !== undefined && {[CONST.TELEMETRY.ATTRIBUTE_DURATION_SINCE_NATIVE_APP_STARTUP_MS]: msSinceNativeAppStart}), + }, }); } @@ -155,16 +167,13 @@ function Camera({onCapture, onPicked, shouldAcceptMultipleFiles = false, onLayou return; } - const isPhotoCapture = shouldTakePhoto({flash, hasFlash, isInLandscapeMode}); - startSpan(CONST.TELEMETRY.SPAN_RECEIPT_CAPTURE, { name: CONST.TELEMETRY.SPAN_RECEIPT_CAPTURE, op: CONST.TELEMETRY.SPAN_RECEIPT_CAPTURE, parentSpan: getSpan(CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION), attributes: { [CONST.TELEMETRY.ATTRIBUTE_PLATFORM]: CONST.TELEMETRY.SPAN_PLATFORM.NATIVE, - [CONST.TELEMETRY.ATTRIBUTE_CAPTURE_METHOD]: isPhotoCapture ? CONST.TELEMETRY.CAPTURE_METHOD.PHOTO : CONST.TELEMETRY.CAPTURE_METHOD.SNAPSHOT, - [CONST.TELEMETRY.ATTRIBUTE_FLASH_USED]: flash && hasFlash, + ...captureAttributes, }, }); diff --git a/src/setup/telemetry/index.native.ts b/src/setup/telemetry/index.native.ts index 3dd63f122fa9..beda999a3b68 100644 --- a/src/setup/telemetry/index.native.ts +++ b/src/setup/telemetry/index.native.ts @@ -1,5 +1,6 @@ import Log from '@libs/Log'; import {startSpan} from '@libs/telemetry/activeSpans'; +import {setNativeAppStartTime} from '@libs/telemetry/nativeAppStartTime'; import CONST from '@src/CONST'; @@ -102,6 +103,7 @@ export default function (): void { Log.warn('[Telemetry] Failed to read native app start time from NitroModule', {error}); nativeAppStartTimeMs = undefined; } + setNativeAppStartTime(nativeAppStartTimeMs); const startupSpan = startSpan(CONST.TELEMETRY.SPAN_APP_STARTUP, { name: CONST.TELEMETRY.SPAN_APP_STARTUP, diff --git a/tests/unit/telemetryStartupMarkersTest.ts b/tests/unit/telemetryStartupMarkersTest.ts index d7faed936ca4..319db2507c18 100644 --- a/tests/unit/telemetryStartupMarkersTest.ts +++ b/tests/unit/telemetryStartupMarkersTest.ts @@ -1,3 +1,5 @@ +import {getMsSinceNativeAppStart} from '@libs/telemetry/nativeAppStartTime'; + import setupTelemetry from '@src/setup/telemetry/index.native'; // jest/setup.ts mocks '@src/setup/telemetry' globally; unmock (hoisted above imports) so we exercise the real native implementation. @@ -108,4 +110,26 @@ describe('telemetry startup markers (native)', () => { expect(() => setupTelemetry()).not.toThrow(); expect(startInactiveSpanMock).not.toHaveBeenCalled(); }); + + it('keeps the accepted native start time for spans that start later, such as the scan shutter span', () => { + // Given a native start time one second before telemetry setup + setupTelemetry(); + + // When a span starts 500ms after setup + jest.spyOn(Date, 'now').mockReturnValue(2_500); + + // Then it can read the time since the native app start + expect(getMsSinceNativeAppStart()).toBe(1_500); + }); + + it('drops the native start time of a prewarmed process so later spans report no duration', () => { + // Given a native start time older than the prewarm threshold, as on a prewarmed process + jest.spyOn(Date, 'now').mockReturnValue(1_000 + 60 * 1000 + 1); + + // When telemetry setup discards it + setupTelemetry(); + + // Then later spans get no duration instead of minutes or hours + expect(getMsSinceNativeAppStart()).toBeUndefined(); + }); }); From 93a8afa07b4fcd2f5f2eb03d280d3e6b3d8d91fd Mon Sep 17 00:00:00 2001 From: Test Date: Mon, 26 Oct 2026 13:45:18 +0100 Subject: [PATCH 2/4] fix:Measure time since native app start on the monotonic clock --- src/libs/telemetry/nativeAppStartTime.ts | 15 +++++++++++---- tests/unit/telemetryStartupMarkersTest.ts | 15 ++++++++++++++- 2 files changed, 25 insertions(+), 5 deletions(-) diff --git a/src/libs/telemetry/nativeAppStartTime.ts b/src/libs/telemetry/nativeAppStartTime.ts index 01dd92e14dff..26b57067ba4f 100644 --- a/src/libs/telemetry/nativeAppStartTime.ts +++ b/src/libs/telemetry/nativeAppStartTime.ts @@ -1,14 +1,21 @@ -let nativeAppStartTimeMs: number | undefined; +// Elapsed time uses performance.now() because Date.now() jumps when the device clock is corrected. +let appStartAgeAtSetupMs: number | undefined; +let performanceNowAtSetupMs = 0; function setNativeAppStartTime(timestampMs: number | undefined) { - nativeAppStartTimeMs = timestampMs; + if (timestampMs === undefined) { + appStartAgeAtSetupMs = undefined; + return; + } + appStartAgeAtSetupMs = Date.now() - timestampMs; + performanceNowAtSetupMs = performance.now(); } function getMsSinceNativeAppStart(): number | undefined { - if (nativeAppStartTimeMs === undefined) { + if (appStartAgeAtSetupMs === undefined) { return undefined; } - return Math.round(Date.now() - nativeAppStartTimeMs); + return Math.round(appStartAgeAtSetupMs + performance.now() - performanceNowAtSetupMs); } export {getMsSinceNativeAppStart, setNativeAppStartTime}; diff --git a/tests/unit/telemetryStartupMarkersTest.ts b/tests/unit/telemetryStartupMarkersTest.ts index 319db2507c18..86528cbd57a1 100644 --- a/tests/unit/telemetryStartupMarkersTest.ts +++ b/tests/unit/telemetryStartupMarkersTest.ts @@ -39,6 +39,7 @@ describe('telemetry startup markers (native)', () => { jest.clearAllMocks(); // Keep "now" close to the mocked appStartTime so the prewarm staleness guard accepts it. jest.spyOn(Date, 'now').mockReturnValue(2_000); + jest.spyOn(performance, 'now').mockReturnValue(10_000); global.requestAnimationFrame = jest.fn(); mockMarkers.mockReturnValue({}); activeSpansMock.startSpan.mockReturnValue({setAttribute: jest.fn()}); @@ -116,12 +117,24 @@ describe('telemetry startup markers (native)', () => { setupTelemetry(); // When a span starts 500ms after setup - jest.spyOn(Date, 'now').mockReturnValue(2_500); + jest.spyOn(performance, 'now').mockReturnValue(10_500); // Then it can read the time since the native app start expect(getMsSinceNativeAppStart()).toBe(1_500); }); + it('ignores wall-clock corrections after setup when reporting the time since the native app start', () => { + // Given a native start time one second before telemetry setup + setupTelemetry(); + + // When the device clock is set back an hour and a span starts 500ms after setup + jest.spyOn(Date, 'now').mockReturnValue(2_500 - 60 * 60 * 1000); + jest.spyOn(performance, 'now').mockReturnValue(10_500); + + // Then the duration follows the monotonic clock instead of going negative + expect(getMsSinceNativeAppStart()).toBe(1_500); + }); + it('drops the native start time of a prewarmed process so later spans report no duration', () => { // Given a native start time older than the prewarm threshold, as on a prewarmed process jest.spyOn(Date, 'now').mockReturnValue(1_000 + 60 * 1000 + 1); From 67c73b1c0aa9d0b5947dbdaed5c8144d38209abf Mon Sep 17 00:00:00 2001 From: Test Date: Mon, 26 Oct 2026 14:54:59 +0100 Subject: [PATCH 3/4] fix:Count device sleep in time since native app start --- src/libs/telemetry/nativeAppStartTime.ts | 11 ++++++++--- tests/unit/telemetryStartupMarkersTest.ts | 24 +++++++++++++++++++++++ 2 files changed, 32 insertions(+), 3 deletions(-) diff --git a/src/libs/telemetry/nativeAppStartTime.ts b/src/libs/telemetry/nativeAppStartTime.ts index 26b57067ba4f..61a63503b151 100644 --- a/src/libs/telemetry/nativeAppStartTime.ts +++ b/src/libs/telemetry/nativeAppStartTime.ts @@ -1,5 +1,8 @@ -// Elapsed time uses performance.now() because Date.now() jumps when the device clock is corrected. +// Elapsed time takes the larger of the Date.now() and performance.now() deltas: Date.now() goes backwards when the +// device clock is corrected, and performance.now() stops during Android deep sleep. JS cannot tell a forward clock +// correction from sleep, so a forward correction after setup inflates the value. let appStartAgeAtSetupMs: number | undefined; +let dateNowAtSetupMs = 0; let performanceNowAtSetupMs = 0; function setNativeAppStartTime(timestampMs: number | undefined) { @@ -7,15 +10,17 @@ function setNativeAppStartTime(timestampMs: number | undefined) { appStartAgeAtSetupMs = undefined; return; } - appStartAgeAtSetupMs = Date.now() - timestampMs; + dateNowAtSetupMs = Date.now(); performanceNowAtSetupMs = performance.now(); + appStartAgeAtSetupMs = dateNowAtSetupMs - timestampMs; } function getMsSinceNativeAppStart(): number | undefined { if (appStartAgeAtSetupMs === undefined) { return undefined; } - return Math.round(appStartAgeAtSetupMs + performance.now() - performanceNowAtSetupMs); + const msSinceSetup = Math.max(Date.now() - dateNowAtSetupMs, performance.now() - performanceNowAtSetupMs); + return Math.round(appStartAgeAtSetupMs + msSinceSetup); } export {getMsSinceNativeAppStart, setNativeAppStartTime}; diff --git a/tests/unit/telemetryStartupMarkersTest.ts b/tests/unit/telemetryStartupMarkersTest.ts index 86528cbd57a1..7a1bbf33aa00 100644 --- a/tests/unit/telemetryStartupMarkersTest.ts +++ b/tests/unit/telemetryStartupMarkersTest.ts @@ -135,6 +135,30 @@ describe('telemetry startup markers (native)', () => { expect(getMsSinceNativeAppStart()).toBe(1_500); }); + it('counts time the device spent in deep sleep after setup', () => { + // Given a native start time one second before telemetry setup + setupTelemetry(); + + // When the device sleeps for an hour, so performance.now() advances only 500ms while the wall clock advances an hour + jest.spyOn(Date, 'now').mockReturnValue(2_000 + 60 * 60 * 1000); + jest.spyOn(performance, 'now').mockReturnValue(10_500); + + // Then the duration includes the sleep instead of reporting a scan right after a cold launch + expect(getMsSinceNativeAppStart()).toBe(1_000 + 60 * 60 * 1000); + }); + + it('counts a forward clock correction after setup as elapsed time, an accepted limitation', () => { + // Given a native start time one second before telemetry setup + setupTelemetry(); + + // When the device clock jumps forward an hour and a span starts 500ms after setup + jest.spyOn(Date, 'now').mockReturnValue(2_500 + 60 * 60 * 1000); + jest.spyOn(performance, 'now').mockReturnValue(10_500); + + // Then the hour is included, because JS cannot tell a forward correction apart from deep sleep + expect(getMsSinceNativeAppStart()).toBe(1_500 + 60 * 60 * 1000); + }); + it('drops the native start time of a prewarmed process so later spans report no duration', () => { // Given a native start time older than the prewarm threshold, as on a prewarmed process jest.spyOn(Date, 'now').mockReturnValue(1_000 + 60 * 1000 + 1); From 550b490b936fbdceab4e1dfbc28783fa913e4cd4 Mon Sep 17 00:00:00 2001 From: Test Date: Wed, 28 Oct 2026 10:48:20 +0100 Subject: [PATCH 4/4] Add time since JS startup --- src/CONST/index.ts | 1 + src/libs/telemetry/nativeAppStartTime.ts | 28 +++++++++----- .../components/Camera/index.native.tsx | 4 +- tests/unit/telemetryStartupMarkersTest.ts | 38 ++++++++++++++++++- 4 files changed, 59 insertions(+), 12 deletions(-) diff --git a/src/CONST/index.ts b/src/CONST/index.ts index abde1d6daf5d..9dd592397826 100644 --- a/src/CONST/index.ts +++ b/src/CONST/index.ts @@ -2917,6 +2917,7 @@ const CONST = { ATTRIBUTE_NEUTRAL_ZOOM: 'neutral_zoom', ATTRIBUTE_ODOMETER_IMAGE_TYPE: 'odometer_image_type', ATTRIBUTE_DURATION_SINCE_NATIVE_APP_STARTUP_MS: 'duration_since_native_app_startup_ms', + ATTRIBUTE_DURATION_SINCE_JS_STARTUP_MS: 'duration_since_js_startup_ms', CAPTURE_METHOD: { PHOTO: 'photo', SNAPSHOT: 'snapshot', diff --git a/src/libs/telemetry/nativeAppStartTime.ts b/src/libs/telemetry/nativeAppStartTime.ts index 61a63503b151..1557c310c66f 100644 --- a/src/libs/telemetry/nativeAppStartTime.ts +++ b/src/libs/telemetry/nativeAppStartTime.ts @@ -2,25 +2,33 @@ // device clock is corrected, and performance.now() stops during Android deep sleep. JS cannot tell a forward clock // correction from sleep, so a forward correction after setup inflates the value. let appStartAgeAtSetupMs: number | undefined; -let dateNowAtSetupMs = 0; +let dateNowAtSetupMs: number | undefined; let performanceNowAtSetupMs = 0; function setNativeAppStartTime(timestampMs: number | undefined) { - if (timestampMs === undefined) { - appStartAgeAtSetupMs = undefined; - return; - } dateNowAtSetupMs = Date.now(); performanceNowAtSetupMs = performance.now(); - appStartAgeAtSetupMs = dateNowAtSetupMs - timestampMs; + appStartAgeAtSetupMs = timestampMs === undefined ? undefined : dateNowAtSetupMs - timestampMs; +} + +function getElapsedMsSinceSetup(): number | undefined { + if (dateNowAtSetupMs === undefined) { + return undefined; + } + return Math.max(Date.now() - dateNowAtSetupMs, performance.now() - performanceNowAtSetupMs); +} + +function getMsSinceJsStartup(): number | undefined { + const elapsedMs = getElapsedMsSinceSetup(); + return elapsedMs === undefined ? undefined : Math.round(elapsedMs); } function getMsSinceNativeAppStart(): number | undefined { - if (appStartAgeAtSetupMs === undefined) { + const elapsedMs = getElapsedMsSinceSetup(); + if (appStartAgeAtSetupMs === undefined || elapsedMs === undefined) { return undefined; } - const msSinceSetup = Math.max(Date.now() - dateNowAtSetupMs, performance.now() - performanceNowAtSetupMs); - return Math.round(appStartAgeAtSetupMs + msSinceSetup); + return Math.round(appStartAgeAtSetupMs + elapsedMs); } -export {getMsSinceNativeAppStart, setNativeAppStartTime}; +export {getMsSinceJsStartup, getMsSinceNativeAppStart, setNativeAppStartTime}; diff --git a/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx b/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx index 93f698e5157c..6de8565eda3f 100644 --- a/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx +++ b/src/pages/iou/request/step/IOURequestStepScan/components/Camera/index.native.tsx @@ -15,7 +15,7 @@ import HapticFeedback from '@libs/HapticFeedback'; import Log from '@libs/Log'; import ReceiptStorage from '@libs/ReceiptStorage'; import {cancelSpan, endSpanWithAttributes, getSpan, startSpan} from '@libs/telemetry/activeSpans'; -import {getMsSinceNativeAppStart} from '@libs/telemetry/nativeAppStartTime'; +import {getMsSinceJsStartup, getMsSinceNativeAppStart} from '@libs/telemetry/nativeAppStartTime'; import captureReceipt, {shouldTakePhoto} from '@pages/iou/request/step/IOURequestStepScan/captureReceipt'; import CameraPermissionPrompt from '@pages/iou/request/step/IOURequestStepScan/components/CameraPermissionPrompt'; @@ -135,6 +135,7 @@ function Camera({onCapture, onPicked, shouldAcceptMultipleFiles = false, onLayou if (!isMultiScanEnabled) { const msSinceNativeAppStart = getMsSinceNativeAppStart(); + const msSinceJsStartup = getMsSinceJsStartup(); startSpan(CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION, { name: CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION, op: CONST.TELEMETRY.SPAN_SHUTTER_TO_CONFIRMATION, @@ -142,6 +143,7 @@ function Camera({onCapture, onPicked, shouldAcceptMultipleFiles = false, onLayou [CONST.TELEMETRY.ATTRIBUTE_PLATFORM]: CONST.TELEMETRY.SPAN_PLATFORM.NATIVE, ...captureAttributes, ...(msSinceNativeAppStart !== undefined && {[CONST.TELEMETRY.ATTRIBUTE_DURATION_SINCE_NATIVE_APP_STARTUP_MS]: msSinceNativeAppStart}), + ...(msSinceJsStartup !== undefined && {[CONST.TELEMETRY.ATTRIBUTE_DURATION_SINCE_JS_STARTUP_MS]: msSinceJsStartup}), }, }); } diff --git a/tests/unit/telemetryStartupMarkersTest.ts b/tests/unit/telemetryStartupMarkersTest.ts index 7a1bbf33aa00..630aa8b0ed5a 100644 --- a/tests/unit/telemetryStartupMarkersTest.ts +++ b/tests/unit/telemetryStartupMarkersTest.ts @@ -1,4 +1,4 @@ -import {getMsSinceNativeAppStart} from '@libs/telemetry/nativeAppStartTime'; +import {getMsSinceJsStartup, getMsSinceNativeAppStart} from '@libs/telemetry/nativeAppStartTime'; import setupTelemetry from '@src/setup/telemetry/index.native'; @@ -169,4 +169,40 @@ describe('telemetry startup markers (native)', () => { // Then later spans get no duration instead of minutes or hours expect(getMsSinceNativeAppStart()).toBeUndefined(); }); + + it('reports the time since JS startup even when the native start time is discarded', () => { + // Given an old native process, as when a HybridApp user opens NewDot after more than a minute in OldDot + jest.spyOn(Date, 'now').mockReturnValue(1_000 + 60 * 1000 + 1); + setupTelemetry(); + + // When a span starts 500ms after setup + jest.spyOn(performance, 'now').mockReturnValue(10_500); + + // Then the JS-startup duration is still reported, so these sessions can be told apart from true cold launches + expect(getMsSinceNativeAppStart()).toBeUndefined(); + expect(getMsSinceJsStartup()).toBe(500); + }); + + it('counts deep sleep in the time since JS startup', () => { + // Given telemetry setup has run + setupTelemetry(); + + // When the device sleeps for an hour, so performance.now() advances only 500ms while the wall clock advances an hour + jest.spyOn(Date, 'now').mockReturnValue(2_000 + 60 * 60 * 1000); + jest.spyOn(performance, 'now').mockReturnValue(10_500); + + // Then the duration includes the sleep, like the native duration + expect(getMsSinceJsStartup()).toBe(60 * 60 * 1000); + }); + + it('reports no JS-startup duration before telemetry setup has run', () => { + // Given a fresh module that telemetry setup has not touched yet + jest.isolateModules(() => { + const {getMsSinceJsStartup: getMsSinceJsStartupBeforeSetup} = jest.requireActual<{getMsSinceJsStartup: typeof getMsSinceJsStartup}>('@libs/telemetry/nativeAppStartTime'); + + // When a span reads the duration + // Then there is no value, instead of a time measured from an unset origin + expect(getMsSinceJsStartupBeforeSetup()).toBeUndefined(); + }); + }); });