From 2f4e0b66c26f8b339b8319d54b16046bbb327d99 Mon Sep 17 00:00:00 2001 From: rory Date: Mon, 2 Feb 2026 18:38:46 -0800 Subject: [PATCH 01/10] Add tests to cover log bug --- tests/unit/LogTest.ts | 178 ++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 178 insertions(+) create mode 100644 tests/unit/LogTest.ts diff --git a/tests/unit/LogTest.ts b/tests/unit/LogTest.ts new file mode 100644 index 0000000000000..dedfbbf3338db --- /dev/null +++ b/tests/unit/LogTest.ts @@ -0,0 +1,178 @@ +/** + * Tests for the Log module, including verification that logs correctly + * include user context when sent to the server. + */ +import MockedOnyx from 'react-native-onyx'; +import HttpUtils from '@src/libs/HttpUtils'; +import Log from '@src/libs/Log'; +import * as Network from '@src/libs/Network'; +import * as MainQueue from '@src/libs/Network/MainQueue'; +import * as NetworkStore from '@src/libs/Network/NetworkStore'; +import * as SequentialQueue from '@src/libs/Network/SequentialQueue'; +import ONYXKEYS from '@src/ONYXKEYS'; +import type ReactNativeOnyxMock from '../../__mocks__/react-native-onyx'; +import * as TestHelper from '../utils/TestHelper'; +import waitForBatchedUpdates from '../utils/waitForBatchedUpdates'; + +const Onyx = MockedOnyx as typeof ReactNativeOnyxMock; + +// We need to NOT mock Log so we can test its actual behavior +jest.unmock('@src/libs/Log'); + +Onyx.init({ + keys: ONYXKEYS, +}); + +/** + * Helper to process the network queue and wait for updates. + * Log commands have shouldProcessImmediately=false, so we need to manually trigger processing. + */ +async function processNetworkQueue() { + MainQueue.process(); + await waitForBatchedUpdates(); +} + +type CapturedLogData = { + email: string | null | undefined; + logPacket: string | undefined; +}; + +/** + * Sets up a mock for HttpUtils.xhr that captures Log command data. + * Returns an object that will be populated with captured values when the mock is called. + */ +function mockHttpUtilsXhr(): CapturedLogData { + const captured: CapturedLogData = { + email: undefined, + logPacket: undefined, + }; + + HttpUtils.xhr = jest.fn().mockImplementation((command: string, data: Record) => { + if (command === 'Log') { + captured.email = data.email as string | null | undefined; + captured.logPacket = data.logPacket as string | undefined; + } + return Promise.resolve({jsonCode: 200, requestID: '123'}); + }); + + return captured; +} + +describe('LogTest', () => { + const TEST_USER_EMAIL = 'test@testguy.com'; + const TEST_USER_ACCOUNT_ID = 1; + const originalXhr = HttpUtils.xhr; + + beforeEach(async () => { + global.fetch = TestHelper.getGlobalFetchMock(); + HttpUtils.xhr = originalXhr; + MainQueue.clear(); + HttpUtils.cancelPendingRequests(); + NetworkStore.checkRequiredData(); + NetworkStore.setIsAuthenticating(false); + Network.clearProcessQueueInterval(); + SequentialQueue.resetQueue(); + + await Onyx.clear(); + await waitForBatchedUpdates(); + }); + + afterEach(() => { + NetworkStore.resetHasReadRequiredDataFromStorage(); + jest.clearAllMocks(); + jest.clearAllTimers(); + }); + + test('logs include user email when sent while user is signed in', async () => { + // Given a signed-in user + await TestHelper.signInWithTestUser(TEST_USER_ACCOUNT_ID, TEST_USER_EMAIL); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBe(TEST_USER_EMAIL); + + const captured = mockHttpUtilsXhr(); + + // When we log a message and force it to be sent immediately + Log.info('Test log message while signed in', true); + await waitForBatchedUpdates(); + await processNetworkQueue(); + + // Then the log request should include the user's email + expect(captured.email).toBe(TEST_USER_EMAIL); + }); + + test('logs queued while signed in retain user email after session is cleared', async () => { + // Given a signed-in user + await TestHelper.signInWithTestUser(TEST_USER_ACCOUNT_ID, TEST_USER_EMAIL); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBe(TEST_USER_EMAIL); + + // When multiple log messages are queued + Log.info('User performed action A'); + Log.info('User performed action B'); + Log.info('User performed action C'); + Log.hmmm('Something suspicious happened'); + + // And then Onyx is cleared (sign out) + await Onyx.clear(); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBeNull(); + + const captured = mockHttpUtilsXhr(); + + // And then logs are flushed + Log.info('Final trigger to flush', true); + await waitForBatchedUpdates(); + await processNetworkQueue(); + + // Then the logs should have been sent + expect(captured.logPacket).toBeDefined(); + + // And contain all the queued messages + const logs = JSON.parse(captured.logPacket ?? '[]'); + expect(logs.length).toBeGreaterThanOrEqual(4); + + const messages = logs.map((log: {message: string}) => log.message); + expect(messages.some((m: string) => m.includes('User performed action A'))).toBe(true); + expect(messages.some((m: string) => m.includes('User performed action B'))).toBe(true); + expect(messages.some((m: string) => m.includes('User performed action C'))).toBe(true); + expect(messages.some((m: string) => m.includes('Something suspicious happened'))).toBe(true); + + // And the email should still be the original user's email + // BUG: Currently fails because email is captured at send time + expect(captured.email).toBe(TEST_USER_EMAIL); + }); + + test('logs during reauthentication flow retain user context', async () => { + // This replicates the scenario from Authentication.ts where logs are + // created during reauthentication but sent after Onyx is cleared + + // Given a signed-in user + await TestHelper.signInWithTestUser(TEST_USER_ACCOUNT_ID, TEST_USER_EMAIL); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBe(TEST_USER_EMAIL); + + // When a log is created (simulating Authentication.ts line 135) + Log.info('Reauthenticate - No credentials available, redirecting to sign in'); + + // And then Onyx is cleared (simulating redirectToSignIn) + await Onyx.clear(); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBeNull(); + + const captured = mockHttpUtilsXhr(); + + // And then logs are flushed + Log.info('Trigger flush', true); + await waitForBatchedUpdates(); + await processNetworkQueue(); + + // Then the log about "No credentials" should be in the packet + const logs = JSON.parse(captured.logPacket ?? '[]'); + const hasNoCredentialsLog = logs.some((log: {message: string}) => log.message.includes('No credentials available, redirecting to sign in')); + expect(hasNoCredentialsLog).toBe(true); + + // And the email should be the original user's email + // BUG: Currently fails because email is captured at send time + expect(captured.email).toBe(TEST_USER_EMAIL); + }); +}); From 4dab0b166b73b2aa8c5fcb292a50cdeb87689707 Mon Sep 17 00:00:00 2001 From: rory Date: Mon, 2 Feb 2026 22:31:47 -0800 Subject: [PATCH 02/10] Clean up test --- tests/unit/LogTest.ts | 35 ++++++++++++++++++++++++++--------- 1 file changed, 26 insertions(+), 9 deletions(-) diff --git a/tests/unit/LogTest.ts b/tests/unit/LogTest.ts index dedfbbf3338db..66a5a1c336919 100644 --- a/tests/unit/LogTest.ts +++ b/tests/unit/LogTest.ts @@ -32,11 +32,24 @@ async function processNetworkQueue() { await waitForBatchedUpdates(); } +type LogLine = { + message: string; + parameters: unknown; + timestamp: string; +}; + type CapturedLogData = { email: string | null | undefined; logPacket: string | undefined; }; +function parseLogPacket(logPacket: string | undefined): LogLine[] { + if (!logPacket) { + return []; + } + return JSON.parse(logPacket) as LogLine[]; +} + /** * Sets up a mock for HttpUtils.xhr that captures Log command data. * Returns an object that will be populated with captured values when the mock is called. @@ -128,14 +141,18 @@ describe('LogTest', () => { expect(captured.logPacket).toBeDefined(); // And contain all the queued messages - const logs = JSON.parse(captured.logPacket ?? '[]'); + const logs = parseLogPacket(captured.logPacket); expect(logs.length).toBeGreaterThanOrEqual(4); - const messages = logs.map((log: {message: string}) => log.message); - expect(messages.some((m: string) => m.includes('User performed action A'))).toBe(true); - expect(messages.some((m: string) => m.includes('User performed action B'))).toBe(true); - expect(messages.some((m: string) => m.includes('User performed action C'))).toBe(true); - expect(messages.some((m: string) => m.includes('Something suspicious happened'))).toBe(true); + const messages = logs.map((log) => log.message); + expect(messages).toEqual( + expect.arrayContaining([ + expect.stringContaining('User performed action A'), + expect.stringContaining('User performed action B'), + expect.stringContaining('User performed action C'), + expect.stringContaining('Something suspicious happened'), + ]), + ); // And the email should still be the original user's email // BUG: Currently fails because email is captured at send time @@ -167,9 +184,9 @@ describe('LogTest', () => { await processNetworkQueue(); // Then the log about "No credentials" should be in the packet - const logs = JSON.parse(captured.logPacket ?? '[]'); - const hasNoCredentialsLog = logs.some((log: {message: string}) => log.message.includes('No credentials available, redirecting to sign in')); - expect(hasNoCredentialsLog).toBe(true); + const logs = parseLogPacket(captured.logPacket); + const messages = logs.map((log) => log.message); + expect(messages).toEqual(expect.arrayContaining([expect.stringContaining('No credentials available, redirecting to sign in')])); // And the email should be the original user's email // BUG: Currently fails because email is captured at send time From 2a6c5295a04f717e4a4a3bc32cf3344517369268 Mon Sep 17 00:00:00 2001 From: rory Date: Mon, 2 Feb 2026 22:57:03 -0800 Subject: [PATCH 03/10] Fix log email race condition by capturing email per log line Co-authored-by: Cursor --- package-lock.json | 166 +++++++++++++++------------------------------- package.json | 2 +- src/libs/Log.ts | 14 +++- 3 files changed, 68 insertions(+), 114 deletions(-) diff --git a/package-lock.json b/package-lock.json index 4d6288eaf2a14..3a94fc9698493 100644 --- a/package-lock.json +++ b/package-lock.json @@ -64,7 +64,7 @@ "date-fns-tz": "^3.2.0", "dom-serializer": "^0.2.2", "domhandler": "^5.0.3", - "expensify-common": "2.0.169", + "expensify-common": "file:../expensify-common", "expo": "54.0.10", "expo-asset": "12.0.8", "expo-audio": "1.1.1", @@ -308,6 +308,55 @@ "npm": "10.8.2" } }, + "../expensify-common": { + "version": "2.0.170", + "license": "MIT", + "dependencies": { + "awesome-phonenumber": "^5.4.0", + "classnames": "2.5.0", + "clipboard": "2.0.11", + "html-entities": "^2.5.2", + "jquery": "3.6.0", + "localforage": "^1.10.0", + "lodash": "4.17.23", + "prop-types": "15.8.1", + "punycode": "^2.3.1", + "react": "16.12.0", + "react-dom": "16.12.0", + "semver": "^7.6.3", + "simply-deferred": "git+https://github.com/Expensify/simply-deferred.git#77a08a95754660c7bd6e0b6979fdf84e8e831bf5", + "ua-parser-js": "^1.0.38" + }, + "devDependencies": { + "@babel/preset-env": "^7.26.0", + "@babel/preset-typescript": "^7.24.7", + "@lwc/eslint-plugin-lwc": "^1.8.2", + "@types/jest": "^29.5.13", + "@types/jquery": "^3.5.30", + "@types/lodash": "^4.17.10", + "@types/punycode": "^2.1.4", + "@types/react-dom": "^18.3.5", + "@types/ua-parser-js": "^0.7.39", + "@typescript-eslint/eslint-plugin": "^8.26.1", + "@typescript-eslint/parser": "^8.24.1", + "babel-jest": "^29.0.0", + "babelify": "10.0.0", + "eslint": "^8.57.1", + "eslint-config-expensify": "^2.0.35", + "eslint-config-prettier": "^8.10.0", + "eslint-plugin-jest": "^28.8.2", + "eslint-plugin-prettier": "^5.2.1", + "eslint-plugin-you-dont-need-lodash-underscore": "^6.14.0", + "grunt": "1.6.1", + "grunt-chokidar": "1.0.2", + "grunt-eslint": "25.0.0", + "jest": "^29.0.0", + "jest-environment-jsdom": "^29.7.0", + "jit-grunt": "^0.10.0", + "prettier": "^3.3.3", + "typescript": "^5.7.2" + } + }, "modules/background-task": { "name": "@expensify/react-native-background-task", "version": "0.0.0", @@ -19518,13 +19567,6 @@ "dev": true, "license": "MIT" }, - "node_modules/classnames": { - "version": "2.5.0", - "license": "MIT", - "workspaces": [ - "benchmarks" - ] - }, "node_modules/clean-css": { "version": "5.3.2", "dev": true, @@ -19709,15 +19751,6 @@ "url": "https://github.com/sponsors/sindresorhus" } }, - "node_modules/clipboard": { - "version": "2.0.11", - "license": "MIT", - "dependencies": { - "good-listener": "^1.2.2", - "select": "^1.1.2", - "tiny-emitter": "^2.0.0" - } - }, "node_modules/cliui": { "version": "8.0.1", "license": "ISC", @@ -21615,10 +21648,6 @@ "node": ">=0.4.0" } }, - "node_modules/delegate": { - "version": "3.2.0", - "license": "MIT" - }, "node_modules/depd": { "version": "2.0.0", "license": "MIT", @@ -23476,60 +23505,8 @@ } }, "node_modules/expensify-common": { - "version": "2.0.169", - "resolved": "https://registry.npmjs.org/expensify-common/-/expensify-common-2.0.169.tgz", - "integrity": "sha512-0AimE2f+0vR0fGyCRaffqlaNOUQnlZFuDzoi6n7Pl4Hrr9WoRltYZwM9gSKnV9yv1K3uV7xjZodiHT0yuQFvqw==", - "license": "MIT", - "dependencies": { - "awesome-phonenumber": "^5.4.0", - "classnames": "2.5.0", - "clipboard": "2.0.11", - "html-entities": "^2.5.2", - "jquery": "3.6.0", - "localforage": "^1.10.0", - "lodash": "4.17.21", - "prop-types": "15.8.1", - "punycode": "^2.3.1", - "react": "16.12.0", - "react-dom": "16.12.0", - "semver": "^7.6.3", - "simply-deferred": "git+https://github.com/Expensify/simply-deferred.git#77a08a95754660c7bd6e0b6979fdf84e8e831bf5", - "ua-parser-js": "^1.0.38" - } - }, - "node_modules/expensify-common/node_modules/semver": { - "version": "7.6.3", - "license": "ISC", - "bin": { - "semver": "bin/semver.js" - }, - "engines": { - "node": ">=10" - } - }, - "node_modules/expensify-common/node_modules/ua-parser-js": { - "version": "1.0.39", - "funding": [ - { - "type": "opencollective", - "url": "https://opencollective.com/ua-parser-js" - }, - { - "type": "paypal", - "url": "https://paypal.me/faisalman" - }, - { - "type": "github", - "url": "https://github.com/sponsors/faisalman" - } - ], - "license": "MIT", - "bin": { - "ua-parser-js": "script/cli.js" - }, - "engines": { - "node": "*" - } + "resolved": "../expensify-common", + "link": true }, "node_modules/expo": { "version": "54.0.10", @@ -25777,13 +25754,6 @@ "url": "https://github.com/sponsors/ljharb" } }, - "node_modules/good-listener": { - "version": "1.2.2", - "license": "MIT", - "dependencies": { - "delegate": "^3.1.2" - } - }, "node_modules/google-auth-library": { "version": "9.14.2", "dev": true, @@ -26075,6 +26045,7 @@ }, "node_modules/html-entities": { "version": "2.5.2", + "dev": true, "funding": [ { "type": "github", @@ -29609,10 +29580,6 @@ "@sideway/pinpoint": "^2.0.0" } }, - "node_modules/jquery": { - "version": "3.6.0", - "license": "MIT" - }, "node_modules/js-base64": { "version": "3.7.5", "license": "BSD-3-Clause" @@ -29997,13 +29964,6 @@ "node": ">= 0.8.0" } }, - "node_modules/lie": { - "version": "3.1.1", - "license": "MIT", - "dependencies": { - "immediate": "~3.0.5" - } - }, "node_modules/lighthouse-logger": { "version": "1.4.2", "license": "Apache-2.0", @@ -30279,13 +30239,6 @@ "node": ">=8.9.0" } }, - "node_modules/localforage": { - "version": "1.10.0", - "license": "Apache-2.0", - "dependencies": { - "lie": "3.1.1" - } - }, "node_modules/locate-path": { "version": "6.0.0", "license": "MIT", @@ -35554,10 +35507,6 @@ "dev": true, "license": "MIT" }, - "node_modules/select": { - "version": "1.1.2", - "license": "MIT" - }, "node_modules/select-hose": { "version": "2.0.0", "dev": true, @@ -36107,14 +36056,6 @@ "version": "0.3.2", "license": "MIT" }, - "node_modules/simply-deferred": { - "version": "3.0.0", - "resolved": "git+ssh://git@github.com/Expensify/simply-deferred.git#77a08a95754660c7bd6e0b6979fdf84e8e831bf5", - "integrity": "sha512-Nn5fsm554ecJunvy1ypMmGb7KksTi8W3ET3lKKnH/V1elXJck0OH6f9E/9Cu19n7DMuGvHOcrLmIAImR9WYAGg==", - "engines": { - "node": "*" - } - }, "node_modules/sirv": { "version": "2.0.4", "dev": true, @@ -37375,6 +37316,7 @@ }, "node_modules/tiny-emitter": { "version": "2.1.0", + "dev": true, "license": "MIT" }, "node_modules/tiny-invariant": { diff --git a/package.json b/package.json index b65dbdce514fd..287ae794bc101 100644 --- a/package.json +++ b/package.json @@ -133,7 +133,7 @@ "date-fns-tz": "^3.2.0", "dom-serializer": "^0.2.2", "domhandler": "^5.0.3", - "expensify-common": "2.0.169", + "expensify-common": "file:../expensify-common", "expo": "54.0.10", "expo-asset": "12.0.8", "expo-audio": "1.1.1", diff --git a/src/libs/Log.ts b/src/libs/Log.ts index 41d35841eecb3..828314516e6d8 100644 --- a/src/libs/Log.ts +++ b/src/libs/Log.ts @@ -13,6 +13,7 @@ import {addLog, flushAllLogsOnAppLaunch} from './actions/Console'; import {shouldAttachLog} from './Console'; import getPlatform from './getPlatform'; import {post} from './Network'; +import {getCurrentUserEmail} from './Network/NetworkStore'; import requireParameters from './requireParameters'; import forwardLogsToSentry from './telemetry/forwardLogsToSentry'; @@ -46,7 +47,10 @@ function LogCommand(parameters: LogCommandParameters): Promise<{requestID: strin // eslint-disable-next-line type ServerLoggingCallbackOptions = {api_setCookie: boolean; logPacket: string}; -type RequestParams = Merge; +type RequestParams = Merge< + ServerLoggingCallbackOptions, + {shouldProcessImmediately: boolean; shouldRetry: boolean; expensifyCashAppVersion: string; parameters: string; email?: string | null} +>; /** * Network interface for logger. @@ -56,6 +60,13 @@ function serverLoggingCallback(logger: Logger, params: ServerLoggingCallbackOpti requestParams.shouldProcessImmediately = false; requestParams.shouldRetry = false; requestParams.expensifyCashAppVersion = `expensifyCash[${getPlatform()}]${pkg.version}`; + + // Extract email from the log lines - use the first non-null email found + // Each log line captures the user's email at the time it was created + const logLines = JSON.parse(params.logPacket) as Array<{email?: string | null}>; + const email = logLines.find((line) => line.email)?.email ?? null; + requestParams.email = email; + if (requestParams.parameters) { requestParams.parameters = JSON.stringify(requestParams.parameters); } @@ -84,6 +95,7 @@ const Log = new Logger({ }, maxLogLinesBeforeFlush: 150, isDebug: true, + getContextEmail: getCurrentUserEmail, }); timeout = setTimeout(() => Log.info('Flushing logs older than 10 minutes', true, {}, true), 10 * 60 * 1000); From b202071bc1a8d31206d658837207a0b13ef449c0 Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 15:10:37 -0800 Subject: [PATCH 04/10] Bump expensify-common to 2.0.171 This version includes the fix for capturing email per log line. Co-authored-by: Cursor --- package-lock.json | 190 ++++++++++++++++++++++++++++++++-------------- package.json | 2 +- 2 files changed, 136 insertions(+), 56 deletions(-) diff --git a/package-lock.json b/package-lock.json index c35bc33161d77..d73c750ed1519 100644 --- a/package-lock.json +++ b/package-lock.json @@ -64,7 +64,7 @@ "date-fns-tz": "^3.2.0", "dom-serializer": "^0.2.2", "domhandler": "^5.0.3", - "expensify-common": "file:../expensify-common", + "expensify-common": "^2.0.171", "expo": "54.0.10", "expo-asset": "12.0.8", "expo-audio": "1.1.1", @@ -308,55 +308,6 @@ "npm": "10.8.2" } }, - "../expensify-common": { - "version": "2.0.170", - "license": "MIT", - "dependencies": { - "awesome-phonenumber": "^5.4.0", - "classnames": "2.5.0", - "clipboard": "2.0.11", - "html-entities": "^2.5.2", - "jquery": "3.6.0", - "localforage": "^1.10.0", - "lodash": "4.17.23", - "prop-types": "15.8.1", - "punycode": "^2.3.1", - "react": "16.12.0", - "react-dom": "16.12.0", - "semver": "^7.6.3", - "simply-deferred": "git+https://github.com/Expensify/simply-deferred.git#77a08a95754660c7bd6e0b6979fdf84e8e831bf5", - "ua-parser-js": "^1.0.38" - }, - "devDependencies": { - "@babel/preset-env": "^7.26.0", - "@babel/preset-typescript": "^7.24.7", - "@lwc/eslint-plugin-lwc": "^1.8.2", - "@types/jest": "^29.5.13", - "@types/jquery": "^3.5.30", - "@types/lodash": "^4.17.10", - "@types/punycode": "^2.1.4", - "@types/react-dom": "^18.3.5", - "@types/ua-parser-js": "^0.7.39", - "@typescript-eslint/eslint-plugin": "^8.26.1", - "@typescript-eslint/parser": "^8.24.1", - "babel-jest": "^29.0.0", - "babelify": "10.0.0", - "eslint": "^8.57.1", - "eslint-config-expensify": "^2.0.35", - "eslint-config-prettier": "^8.10.0", - "eslint-plugin-jest": "^28.8.2", - "eslint-plugin-prettier": "^5.2.1", - "eslint-plugin-you-dont-need-lodash-underscore": "^6.14.0", - "grunt": "1.6.1", - "grunt-chokidar": "1.0.2", - "grunt-eslint": "25.0.0", - "jest": "^29.0.0", - "jest-environment-jsdom": "^29.7.0", - "jit-grunt": "^0.10.0", - "prettier": "^3.3.3", - "typescript": "^5.7.2" - } - }, "modules/background-task": { "name": "@expensify/react-native-background-task", "version": "0.0.0", @@ -19520,6 +19471,15 @@ "dev": true, "license": "MIT" }, + "node_modules/classnames": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/classnames/-/classnames-2.5.0.tgz", + "integrity": "sha512-FQuRlyKinxrb5gwJlfVASbSrDlikDJ07426TrfPsdGLvtochowmkbnSFdQGJ2aoXrSetq5KqGV9emvWpy+91xA==", + "license": "MIT", + "workspaces": [ + "benchmarks" + ] + }, "node_modules/clean-css": { "version": "5.3.2", "dev": true, @@ -19704,6 +19664,17 @@ "url": "https://github.com/sponsors/sindresorhus" } }, + "node_modules/clipboard": { + "version": "2.0.11", + "resolved": "https://registry.npmjs.org/clipboard/-/clipboard-2.0.11.tgz", + "integrity": "sha512-C+0bbOqkezLIsmWSvlsXS0Q0bmkugu7jcfMIACB+RDEntIzQIkdr148we28AfSloQLRdZlYL/QYyrq05j/3Faw==", + "license": "MIT", + "dependencies": { + "good-listener": "^1.2.2", + "select": "^1.1.2", + "tiny-emitter": "^2.0.0" + } + }, "node_modules/cliui": { "version": "8.0.1", "license": "ISC", @@ -21601,6 +21572,12 @@ "node": ">=0.4.0" } }, + "node_modules/delegate": { + "version": "3.2.0", + "resolved": "https://registry.npmjs.org/delegate/-/delegate-3.2.0.tgz", + "integrity": "sha512-IofjkYBZaZivn0V8nnsMJGBr4jVLxHDheKSW88PyxS5QC4Vo9ZbZVvhzlSxY87fVq3STR6r+4cGepyHkcWOQSw==", + "license": "MIT" + }, "node_modules/depd": { "version": "2.0.0", "license": "MIT", @@ -23458,8 +23435,64 @@ } }, "node_modules/expensify-common": { - "resolved": "../expensify-common", - "link": true + "version": "2.0.171", + "resolved": "https://registry.npmjs.org/expensify-common/-/expensify-common-2.0.171.tgz", + "integrity": "sha512-2Pvnm+VNOV0v2+5Q2NRiOQiTgStZLI4r5f8XCccg3k2fz+kgKERibAUaA3FRWZavmu1/Fydekqs35q+bklFRdA==", + "license": "MIT", + "dependencies": { + "awesome-phonenumber": "^5.4.0", + "classnames": "2.5.0", + "clipboard": "2.0.11", + "html-entities": "^2.5.2", + "jquery": "3.6.0", + "localforage": "^1.10.0", + "lodash": "4.17.23", + "prop-types": "15.8.1", + "punycode": "^2.3.1", + "react": "16.12.0", + "react-dom": "16.12.0", + "semver": "^7.6.3", + "simply-deferred": "git+https://github.com/Expensify/simply-deferred.git#77a08a95754660c7bd6e0b6979fdf84e8e831bf5", + "ua-parser-js": "^1.0.38" + } + }, + "node_modules/expensify-common/node_modules/semver": { + "version": "7.7.3", + "resolved": "https://registry.npmjs.org/semver/-/semver-7.7.3.tgz", + "integrity": "sha512-SdsKMrI9TdgjdweUSR9MweHA4EJ8YxHn8DFaDisvhVlUOe4BF1tLD7GAj0lIqWVl+dPb/rExr0Btby5loQm20Q==", + "license": "ISC", + "bin": { + "semver": "bin/semver.js" + }, + "engines": { + "node": ">=10" + } + }, + "node_modules/expensify-common/node_modules/ua-parser-js": { + "version": "1.0.41", + "resolved": "https://registry.npmjs.org/ua-parser-js/-/ua-parser-js-1.0.41.tgz", + "integrity": "sha512-LbBDqdIC5s8iROCUjMbW1f5dJQTEFB1+KO9ogbvlb3nm9n4YHa5p4KTvFPWvh2Hs8gZMBuiB1/8+pdfe/tDPug==", + "funding": [ + { + "type": "opencollective", + "url": "https://opencollective.com/ua-parser-js" + }, + { + "type": "paypal", + "url": "https://paypal.me/faisalman" + }, + { + "type": "github", + "url": "https://github.com/sponsors/faisalman" + } + ], + "license": "MIT", + "bin": { + "ua-parser-js": "script/cli.js" + }, + "engines": { + "node": "*" + } }, "node_modules/expo": { "version": "54.0.10", @@ -25645,6 +25678,15 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/good-listener": { + "version": "1.2.2", + "resolved": "https://registry.npmjs.org/good-listener/-/good-listener-1.2.2.tgz", + "integrity": "sha512-goW1b+d9q/HIwbVYZzZ6SsTr4IgE+WA44A0GmPIQstuOrgsFcT7VEJ48nmr9GaRtNu0XTKacFLGnBPAM6Afouw==", + "license": "MIT", + "dependencies": { + "delegate": "^3.1.2" + } + }, "node_modules/google-auth-library": { "version": "9.14.2", "dev": true, @@ -25936,7 +25978,6 @@ }, "node_modules/html-entities": { "version": "2.5.2", - "dev": true, "funding": [ { "type": "github", @@ -29471,6 +29512,12 @@ "@sideway/pinpoint": "^2.0.0" } }, + "node_modules/jquery": { + "version": "3.6.0", + "resolved": "https://registry.npmjs.org/jquery/-/jquery-3.6.0.tgz", + "integrity": "sha512-JVzAR/AjBvVt2BmYhxRCSYysDsPcssdmTFnzyLEts9qNwmjmu4JTAMYubEfwVOSwpQ1I1sKKFcxhZCI2buerfw==", + "license": "MIT" + }, "node_modules/js-base64": { "version": "3.7.5", "license": "BSD-3-Clause" @@ -29855,6 +29902,15 @@ "node": ">= 0.8.0" } }, + "node_modules/lie": { + "version": "3.1.1", + "resolved": "https://registry.npmjs.org/lie/-/lie-3.1.1.tgz", + "integrity": "sha512-RiNhHysUjhrDQntfYSfY4MU24coXXdEOgw9WGcKHNeEwffDYbF//u87M1EWaMGzuFoSbqW0C9C6lEEhDOAswfw==", + "license": "MIT", + "dependencies": { + "immediate": "~3.0.5" + } + }, "node_modules/lighthouse-logger": { "version": "1.4.2", "license": "Apache-2.0", @@ -30130,6 +30186,15 @@ "node": ">=8.9.0" } }, + "node_modules/localforage": { + "version": "1.10.0", + "resolved": "https://registry.npmjs.org/localforage/-/localforage-1.10.0.tgz", + "integrity": "sha512-14/H1aX7hzBBmmh7sGPd+AOMkkIrHM3Z1PAyGgZigA1H1p5O5ANnMyWzvpAETtG68/dC4pC0ncy3+PPGzXZHPg==", + "license": "Apache-2.0", + "dependencies": { + "lie": "3.1.1" + } + }, "node_modules/locate-path": { "version": "6.0.0", "license": "MIT", @@ -30144,7 +30209,9 @@ } }, "node_modules/lodash": { - "version": "4.17.21", + "version": "4.17.23", + "resolved": "https://registry.npmjs.org/lodash/-/lodash-4.17.23.tgz", + "integrity": "sha512-LgVTMpQtIopCi79SJeDiP0TfWi5CNEc/L/aRdTh3yIvmZXTnheWpKjSZhnvMl8iXbC1tFg9gdHHDMLoV7CnG+w==", "license": "MIT" }, "node_modules/lodash-es": { @@ -35351,6 +35418,12 @@ "dev": true, "license": "MIT" }, + "node_modules/select": { + "version": "1.1.2", + "resolved": "https://registry.npmjs.org/select/-/select-1.1.2.tgz", + "integrity": "sha512-OwpTSOfy6xSs1+pwcNrv0RBMOzI39Lp3qQKUTPVVPRjCdNa5JH/oPRiqsesIskK8TVgmRiHwO4KXlV2Li9dANA==", + "license": "MIT" + }, "node_modules/select-hose": { "version": "2.0.0", "dev": true, @@ -35900,6 +35973,14 @@ "version": "0.3.2", "license": "MIT" }, + "node_modules/simply-deferred": { + "version": "3.0.0", + "resolved": "git+ssh://git@github.com/Expensify/simply-deferred.git#77a08a95754660c7bd6e0b6979fdf84e8e831bf5", + "integrity": "sha512-Nn5fsm554ecJunvy1ypMmGb7KksTi8W3ET3lKKnH/V1elXJck0OH6f9E/9Cu19n7DMuGvHOcrLmIAImR9WYAGg==", + "engines": { + "node": "*" + } + }, "node_modules/sirv": { "version": "2.0.4", "dev": true, @@ -37185,7 +37266,6 @@ }, "node_modules/tiny-emitter": { "version": "2.1.0", - "dev": true, "license": "MIT" }, "node_modules/tiny-invariant": { diff --git a/package.json b/package.json index 69c624e4aa597..d4ece89bb1841 100644 --- a/package.json +++ b/package.json @@ -133,7 +133,7 @@ "date-fns-tz": "^3.2.0", "dom-serializer": "^0.2.2", "domhandler": "^5.0.3", - "expensify-common": "file:../expensify-common", + "expensify-common": "^2.0.171", "expo": "54.0.10", "expo-asset": "12.0.8", "expo-audio": "1.1.1", From d0ee00ecd93bcdb731310e6ed00ed17ff9a8c603 Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 15:11:48 -0800 Subject: [PATCH 05/10] Don't use a caret for versions in package.json --- package-lock.json | 2 +- package.json | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/package-lock.json b/package-lock.json index d73c750ed1519..972b21991bfac 100644 --- a/package-lock.json +++ b/package-lock.json @@ -64,7 +64,7 @@ "date-fns-tz": "^3.2.0", "dom-serializer": "^0.2.2", "domhandler": "^5.0.3", - "expensify-common": "^2.0.171", + "expensify-common": "2.0.171", "expo": "54.0.10", "expo-asset": "12.0.8", "expo-audio": "1.1.1", diff --git a/package.json b/package.json index d4ece89bb1841..66e983480f420 100644 --- a/package.json +++ b/package.json @@ -133,7 +133,7 @@ "date-fns-tz": "^3.2.0", "dom-serializer": "^0.2.2", "domhandler": "^5.0.3", - "expensify-common": "^2.0.171", + "expensify-common": "2.0.171", "expo": "54.0.10", "expo-asset": "12.0.8", "expo-audio": "1.1.1", From 2c78f8a08ab98257deba8fa4c8dc3eb255218f49 Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 16:01:18 -0800 Subject: [PATCH 06/10] Batch requests by email --- src/libs/Log.ts | 58 +++++++++++++----- tests/unit/LogTest.ts | 139 +++++++++++++++++++++++++++++++----------- 2 files changed, 147 insertions(+), 50 deletions(-) diff --git a/src/libs/Log.ts b/src/libs/Log.ts index 828314516e6d8..759fa1133792e 100644 --- a/src/libs/Log.ts +++ b/src/libs/Log.ts @@ -49,32 +49,58 @@ function LogCommand(parameters: LogCommandParameters): Promise<{requestID: strin type ServerLoggingCallbackOptions = {api_setCookie: boolean; logPacket: string}; type RequestParams = Merge< ServerLoggingCallbackOptions, - {shouldProcessImmediately: boolean; shouldRetry: boolean; expensifyCashAppVersion: string; parameters: string; email?: string | null} + {shouldProcessImmediately: boolean; shouldRetry: boolean; expensifyCashAppVersion: string; parameters?: string; email?: string | null} >; +type LogLine = {email?: string | null; [key: string]: unknown}; + /** * Network interface for logger. + * Splits log packets by email to ensure logs are attributed to the correct user, + * even when multiple users' logs are queued before flushing. */ function serverLoggingCallback(logger: Logger, params: ServerLoggingCallbackOptions): Promise<{requestID: string}> { - const requestParams = params as RequestParams; - requestParams.shouldProcessImmediately = false; - requestParams.shouldRetry = false; - requestParams.expensifyCashAppVersion = `expensifyCash[${getPlatform()}]${pkg.version}`; - - // Extract email from the log lines - use the first non-null email found - // Each log line captures the user's email at the time it was created - const logLines = JSON.parse(params.logPacket) as Array<{email?: string | null}>; - const email = logLines.find((line) => line.email)?.email ?? null; - requestParams.email = email; - - if (requestParams.parameters) { - requestParams.parameters = JSON.stringify(requestParams.parameters); + const baseParams = { + shouldProcessImmediately: false, + shouldRetry: false, + expensifyCashAppVersion: `expensifyCash[${getPlatform()}]${pkg.version}`, + }; + + // Parse log lines and group by email to handle multi-user scenarios + // (e.g., user signs out and another signs in before logs flush) + const logLines = JSON.parse(params.logPacket) as LogLine[]; + const logsByEmail = new Map(); + for (const line of logLines) { + const email = line.email ?? null; + const existing = logsByEmail.get(email) ?? []; + existing.push(line); + logsByEmail.set(email, existing); } + + // Create a request for each email group + const requests: Array> = []; + for (const [email, lines] of logsByEmail) { + const requestParams: RequestParams = { + ...params, + ...baseParams, + logPacket: JSON.stringify(lines), + email, + }; + + if (requestParams.parameters) { + requestParams.parameters = JSON.stringify(requestParams.parameters); + } + + requests.push(LogCommand(requestParams)); + } + // Mirror backend log payload into Telemetry logger for better context - forwardLogsToSentry(requestParams.logPacket); + forwardLogsToSentry(params.logPacket); clearTimeout(timeout); timeout = setTimeout(() => logger.info('Flushing logs older than 10 minutes', true, {}, true), 10 * 60 * 1000); - return LogCommand(requestParams); + + // Return the first request's result (all requests will be sent in parallel) + return Promise.all(requests).then((results) => results.at(0) ?? {requestID: ''}); } // Note: We are importing Logger from expensify-common because it is used by other platforms. The server and client logging diff --git a/tests/unit/LogTest.ts b/tests/unit/LogTest.ts index 66a5a1c336919..d4fc7d93b8a72 100644 --- a/tests/unit/LogTest.ts +++ b/tests/unit/LogTest.ts @@ -38,7 +38,7 @@ type LogLine = { timestamp: string; }; -type CapturedLogData = { +type CapturedLogRequest = { email: string | null | undefined; logPacket: string | undefined; }; @@ -51,24 +51,23 @@ function parseLogPacket(logPacket: string | undefined): LogLine[] { } /** - * Sets up a mock for HttpUtils.xhr that captures Log command data. - * Returns an object that will be populated with captured values when the mock is called. + * Sets up a mock for HttpUtils.xhr that captures all Log command requests. + * Returns an array that will be populated with captured requests when the mock is called. */ -function mockHttpUtilsXhr(): CapturedLogData { - const captured: CapturedLogData = { - email: undefined, - logPacket: undefined, - }; +function mockHttpUtilsXhr(): CapturedLogRequest[] { + const capturedRequests: CapturedLogRequest[] = []; HttpUtils.xhr = jest.fn().mockImplementation((command: string, data: Record) => { if (command === 'Log') { - captured.email = data.email as string | null | undefined; - captured.logPacket = data.logPacket as string | undefined; + capturedRequests.push({ + email: data.email as string | null | undefined, + logPacket: data.logPacket as string | undefined, + }); } return Promise.resolve({jsonCode: 200, requestID: '123'}); }); - return captured; + return capturedRequests; } describe('LogTest', () => { @@ -102,15 +101,19 @@ describe('LogTest', () => { await waitForBatchedUpdates(); expect(NetworkStore.getCurrentUserEmail()).toBe(TEST_USER_EMAIL); - const captured = mockHttpUtilsXhr(); + const capturedRequests = mockHttpUtilsXhr(); // When we log a message and force it to be sent immediately Log.info('Test log message while signed in', true); await waitForBatchedUpdates(); await processNetworkQueue(); - // Then the log request should include the user's email - expect(captured.email).toBe(TEST_USER_EMAIL); + // Then a log request should have been made + expect(capturedRequests.length).toBeGreaterThanOrEqual(1); + + // And the request for this user's logs should include their email + const userRequest = capturedRequests.find((req) => req.email === TEST_USER_EMAIL); + expect(userRequest).toBeDefined(); }); test('logs queued while signed in retain user email after session is cleared', async () => { @@ -130,21 +133,25 @@ describe('LogTest', () => { await waitForBatchedUpdates(); expect(NetworkStore.getCurrentUserEmail()).toBeNull(); - const captured = mockHttpUtilsXhr(); + const capturedRequests = mockHttpUtilsXhr(); - // And then logs are flushed + // And then logs are flushed (this log has null email since user is signed out) Log.info('Final trigger to flush', true); await waitForBatchedUpdates(); await processNetworkQueue(); - // Then the logs should have been sent - expect(captured.logPacket).toBeDefined(); + // Then multiple requests should have been made (split by email) + expect(capturedRequests.length).toBeGreaterThanOrEqual(1); + + // And a request with the original user's email should contain their logs + const userRequest = capturedRequests.find((req) => req.email === TEST_USER_EMAIL); + expect(userRequest).toBeDefined(); + expect(userRequest?.logPacket).toBeDefined(); - // And contain all the queued messages - const logs = parseLogPacket(captured.logPacket); - expect(logs.length).toBeGreaterThanOrEqual(4); + const userLogs = parseLogPacket(userRequest?.logPacket); + expect(userLogs.length).toBeGreaterThanOrEqual(4); - const messages = logs.map((log) => log.message); + const messages = userLogs.map((log) => log.message); expect(messages).toEqual( expect.arrayContaining([ expect.stringContaining('User performed action A'), @@ -153,10 +160,6 @@ describe('LogTest', () => { expect.stringContaining('Something suspicious happened'), ]), ); - - // And the email should still be the original user's email - // BUG: Currently fails because email is captured at send time - expect(captured.email).toBe(TEST_USER_EMAIL); }); test('logs during reauthentication flow retain user context', async () => { @@ -176,20 +179,88 @@ describe('LogTest', () => { await waitForBatchedUpdates(); expect(NetworkStore.getCurrentUserEmail()).toBeNull(); - const captured = mockHttpUtilsXhr(); + const capturedRequests = mockHttpUtilsXhr(); - // And then logs are flushed + // And then logs are flushed (this log has null email since user is signed out) Log.info('Trigger flush', true); await waitForBatchedUpdates(); await processNetworkQueue(); - // Then the log about "No credentials" should be in the packet - const logs = parseLogPacket(captured.logPacket); - const messages = logs.map((log) => log.message); + // Then a request with the original user's email should be made + const userRequest = capturedRequests.find((req) => req.email === TEST_USER_EMAIL); + expect(userRequest).toBeDefined(); + + // And the log about "No credentials" should be in that user's packet + const userLogs = parseLogPacket(userRequest?.logPacket); + const messages = userLogs.map((log) => log.message); expect(messages).toEqual(expect.arrayContaining([expect.stringContaining('No credentials available, redirecting to sign in')])); + }); + + test('logs from multiple users in same flush are split into separate requests', async () => { + // This tests the scenario where user A signs out and user B signs in + // before the queued logs flush + + const USER_A_EMAIL = 'userA@test.com'; + const USER_B_EMAIL = 'userB@test.com'; + + // Given user A is signed in + await TestHelper.signInWithTestUser(1, USER_A_EMAIL); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBe(USER_A_EMAIL); + + // Set up mock to capture all requests + const capturedRequests = mockHttpUtilsXhr(); + + // And user A creates some logs + Log.info('User A action 1'); + Log.info('User A action 2'); + + // When user A signs out (using merge to avoid triggering extra logs) + await Onyx.merge(ONYXKEYS.SESSION, {email: null, authToken: null}); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBeNull(); - // And the email should be the original user's email - // BUG: Currently fails because email is captured at send time - expect(captured.email).toBe(TEST_USER_EMAIL); + // And user B "signs in" (just set the email directly to avoid system logs) + await Onyx.merge(ONYXKEYS.SESSION, {email: USER_B_EMAIL, authToken: 'token123'}); + await waitForBatchedUpdates(); + expect(NetworkStore.getCurrentUserEmail()).toBe(USER_B_EMAIL); + + // And user B creates some logs + Log.info('User B action 1'); + Log.info('User B action 2'); + + // And then all logs are flushed + Log.info('Trigger flush', true); + await waitForBatchedUpdates(); + await processNetworkQueue(); + + // Helper to collect all messages from all requests for a given email + const getAllMessagesForEmail = (email: string): string[] => { + return capturedRequests + .filter((req) => req.email === email) + .flatMap((req) => parseLogPacket(req.logPacket)) + .map((log) => log.message); + }; + + // Then requests should have been made for each user + const userAMessages = getAllMessagesForEmail(USER_A_EMAIL); + const userBMessages = getAllMessagesForEmail(USER_B_EMAIL); + + expect(userAMessages.length).toBeGreaterThan(0); + expect(userBMessages.length).toBeGreaterThan(0); + + // And user A's explicit logs should be in requests with their email + expect(userAMessages).toEqual( + expect.arrayContaining([expect.stringContaining('User A action 1'), expect.stringContaining('User A action 2')]), + ); + // User B's explicit logs should NOT be in user A's requests + expect(userAMessages.join()).not.toContain('User B action'); + + // And user B's explicit logs should be in requests with their email + expect(userBMessages).toEqual( + expect.arrayContaining([expect.stringContaining('User B action 1'), expect.stringContaining('User B action 2')]), + ); + // User A's explicit logs should NOT be in user B's requests + expect(userBMessages.join()).not.toContain('User A action'); }); }); From c11878eb6ec9dfdfe35c5d5725f50a6048a3e7a8 Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 16:22:34 -0800 Subject: [PATCH 07/10] Only retry log command if ALL requests fail --- src/libs/Log.ts | 24 +++++++++++-- tests/unit/LogTest.ts | 81 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 103 insertions(+), 2 deletions(-) diff --git a/src/libs/Log.ts b/src/libs/Log.ts index 759fa1133792e..773aac3707a24 100644 --- a/src/libs/Log.ts +++ b/src/libs/Log.ts @@ -99,8 +99,28 @@ function serverLoggingCallback(logger: Logger, params: ServerLoggingCallbackOpti clearTimeout(timeout); timeout = setTimeout(() => logger.info('Flushing logs older than 10 minutes', true, {}, true), 10 * 60 * 1000); - // Return the first request's result (all requests will be sent in parallel) - return Promise.all(requests).then((results) => results.at(0) ?? {requestID: ''}); + // Use allSettled to handle partial failures gracefully. + // If we used Promise.all, a single failed group would reject and cause the Logger + // to retry the entire original packet, duplicating already-uploaded groups. + // With allSettled: if ANY succeed we resolve (preventing duplicates), only rejecting + // if ALL fail (allowing the Logger to retry). This trades potential log loss on + // partial failure for guaranteed no duplicates. + return Promise.allSettled(requests).then((results) => { + const fulfilled = results.filter((r): r is PromiseFulfilledResult<{requestID: string}> => r.status === 'fulfilled'); + const rejected = results.filter((r): r is PromiseRejectedResult => r.status === 'rejected'); + + if (fulfilled.length > 0) { + // At least one group succeeded - resolve to prevent retry/duplicates + if (rejected.length > 0) { + // Log warning about lost logs (rare: partial failure + multiple email groups) + console.warn(`[Log] ${rejected.length} of ${results.length} log groups failed to upload and will not be retried`); + } + return fulfilled[0].value; + } + + // All requests failed - reject so Logger can retry the whole batch + throw rejected[0]?.reason ?? new Error('All log requests failed'); + }); } // Note: We are importing Logger from expensify-common because it is used by other platforms. The server and client logging diff --git a/tests/unit/LogTest.ts b/tests/unit/LogTest.ts index d4fc7d93b8a72..9f2599caff928 100644 --- a/tests/unit/LogTest.ts +++ b/tests/unit/LogTest.ts @@ -263,4 +263,85 @@ describe('LogTest', () => { // User A's explicit logs should NOT be in user B's requests expect(userBMessages.join()).not.toContain('User A action'); }); + + test('partial upload failure does not cause duplicates on retry', async () => { + // This tests that if one email group fails while others succeed, + // we resolve (to prevent retry/duplicates) rather than reject + + const USER_A_EMAIL = 'userA@test.com'; + const USER_B_EMAIL = 'userB@test.com'; + + // Given user A is signed in + await TestHelper.signInWithTestUser(1, USER_A_EMAIL); + await waitForBatchedUpdates(); + + // Set up mock that fails for USER_A but succeeds for others + const capturedRequests: CapturedLogRequest[] = []; + HttpUtils.xhr = jest.fn().mockImplementation((command: string, data: Record) => { + if (command === 'Log') { + capturedRequests.push({ + email: data.email as string | null | undefined, + logPacket: data.logPacket as string | undefined, + }); + + // Fail requests for USER_A_EMAIL + if (data.email === USER_A_EMAIL) { + return Promise.reject(new Error('Simulated network failure')); + } + } + return Promise.resolve({jsonCode: 200, requestID: '123'}); + }); + + // User A creates logs + Log.info('User A log'); + + // Switch to user B + await Onyx.merge(ONYXKEYS.SESSION, {email: USER_B_EMAIL, authToken: 'token123'}); + await waitForBatchedUpdates(); + + // User B creates logs + Log.info('User B log'); + + // Flush logs - this should NOT throw even though USER_A's request failed + Log.info('Trigger flush', true); + await waitForBatchedUpdates(); + + // The network queue should process without throwing + await expect(processNetworkQueue()).resolves.not.toThrow(); + + // Both requests should have been attempted + expect(capturedRequests.some((req) => req.email === USER_A_EMAIL)).toBe(true); + expect(capturedRequests.some((req) => req.email === USER_B_EMAIL)).toBe(true); + }); + + test('all requests failing causes rejection for retry', async () => { + // This tests that if ALL email groups fail, we reject so the Logger can retry + + // Given a signed-in user + await TestHelper.signInWithTestUser(TEST_USER_ACCOUNT_ID, TEST_USER_EMAIL); + await waitForBatchedUpdates(); + + // Set up mock that always fails for Log commands + let logCallCount = 0; + HttpUtils.xhr = jest.fn().mockImplementation((command: string) => { + if (command === 'Log') { + logCallCount++; + return Promise.reject(new Error('Simulated network failure')); + } + return Promise.resolve({jsonCode: 200, requestID: '123'}); + }); + + // Create a log + Log.info('Test log'); + + // Flush logs + Log.info('Trigger flush', true); + await waitForBatchedUpdates(); + + // The network queue processing should eventually reject (though the queue handles this internally) + await processNetworkQueue(); + + // Verify Log command was attempted + expect(logCallCount).toBeGreaterThan(0); + }); }); From d297eecf3b13967ef29ce5810f8dfb3fd665963b Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 16:31:10 -0800 Subject: [PATCH 08/10] Fix lint and prettier --- src/libs/Log.ts | 6 +++--- tests/unit/LogTest.ts | 8 ++------ 2 files changed, 5 insertions(+), 9 deletions(-) diff --git a/src/libs/Log.ts b/src/libs/Log.ts index 773aac3707a24..0abfa31483af3 100644 --- a/src/libs/Log.ts +++ b/src/libs/Log.ts @@ -113,13 +113,13 @@ function serverLoggingCallback(logger: Logger, params: ServerLoggingCallbackOpti // At least one group succeeded - resolve to prevent retry/duplicates if (rejected.length > 0) { // Log warning about lost logs (rare: partial failure + multiple email groups) - console.warn(`[Log] ${rejected.length} of ${results.length} log groups failed to upload and will not be retried`); + console.error(`[Log] ${rejected.length} of ${results.length} log groups failed to upload and will not be retried`); } - return fulfilled[0].value; + return fulfilled.at(0)?.value ?? {requestID: ''}; } // All requests failed - reject so Logger can retry the whole batch - throw rejected[0]?.reason ?? new Error('All log requests failed'); + throw rejected.at(0)?.reason ?? new Error('All log requests failed'); }); } diff --git a/tests/unit/LogTest.ts b/tests/unit/LogTest.ts index 9f2599caff928..1a505a662b809 100644 --- a/tests/unit/LogTest.ts +++ b/tests/unit/LogTest.ts @@ -250,16 +250,12 @@ describe('LogTest', () => { expect(userBMessages.length).toBeGreaterThan(0); // And user A's explicit logs should be in requests with their email - expect(userAMessages).toEqual( - expect.arrayContaining([expect.stringContaining('User A action 1'), expect.stringContaining('User A action 2')]), - ); + expect(userAMessages).toEqual(expect.arrayContaining([expect.stringContaining('User A action 1'), expect.stringContaining('User A action 2')])); // User B's explicit logs should NOT be in user A's requests expect(userAMessages.join()).not.toContain('User B action'); // And user B's explicit logs should be in requests with their email - expect(userBMessages).toEqual( - expect.arrayContaining([expect.stringContaining('User B action 1'), expect.stringContaining('User B action 2')]), - ); + expect(userBMessages).toEqual(expect.arrayContaining([expect.stringContaining('User B action 1'), expect.stringContaining('User B action 2')])); // User A's explicit logs should NOT be in user B's requests expect(userBMessages.join()).not.toContain('User A action'); }); From 17cecee6272747970cb8773de7426f4206960379 Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 16:51:38 -0800 Subject: [PATCH 09/10] Extract CurrentUserStore to avoid circular dependency --- src/libs/CurrentUserStore.ts | 24 ++++++++++++++++++++++++ src/libs/Log.ts | 2 +- src/libs/Network/NetworkStore.ts | 7 +------ 3 files changed, 26 insertions(+), 7 deletions(-) create mode 100644 src/libs/CurrentUserStore.ts diff --git a/src/libs/CurrentUserStore.ts b/src/libs/CurrentUserStore.ts new file mode 100644 index 0000000000000..8df4081552608 --- /dev/null +++ b/src/libs/CurrentUserStore.ts @@ -0,0 +1,24 @@ +/** + * Thin store for current user email that has no dependencies on Log. + * This avoids circular dependency: Log -> NetworkStore -> Log + * Other modules can import getCurrentUserEmail from NetworkStore for convenience, + * but Log specifically imports from here to break the cycle. + */ +import Onyx from 'react-native-onyx'; +import ONYXKEYS from '@src/ONYXKEYS'; + +let currentUserEmail: string | null = null; + +Onyx.connectWithoutView({ + key: ONYXKEYS.SESSION, + callback: (val) => { + currentUserEmail = val?.email ?? null; + }, +}); + +function getCurrentUserEmail(): string | null { + return currentUserEmail; +} + +// eslint-disable-next-line import/prefer-default-export +export {getCurrentUserEmail}; diff --git a/src/libs/Log.ts b/src/libs/Log.ts index 0abfa31483af3..67ccd95420382 100644 --- a/src/libs/Log.ts +++ b/src/libs/Log.ts @@ -13,7 +13,7 @@ import {addLog, flushAllLogsOnAppLaunch} from './actions/Console'; import {shouldAttachLog} from './Console'; import getPlatform from './getPlatform'; import {post} from './Network'; -import {getCurrentUserEmail} from './Network/NetworkStore'; +import {getCurrentUserEmail} from './CurrentUserStore'; import requireParameters from './requireParameters'; import forwardLogsToSentry from './telemetry/forwardLogsToSentry'; diff --git a/src/libs/Network/NetworkStore.ts b/src/libs/Network/NetworkStore.ts index 6e168b0beacd8..1bf4e8c80d6a5 100644 --- a/src/libs/Network/NetworkStore.ts +++ b/src/libs/Network/NetworkStore.ts @@ -4,12 +4,12 @@ import CONST from '@src/CONST'; import Log from '@src/libs/Log'; import ONYXKEYS from '@src/ONYXKEYS'; import type Credentials from '@src/types/onyx/Credentials'; +import {getCurrentUserEmail} from '@src/libs/CurrentUserStore'; let credentials: Credentials | null | undefined; let lastShortAuthToken: string | null | undefined; let authToken: string | null | undefined; let authTokenType: ValueOf | null; -let currentUserEmail: string | null = null; let offline = false; let authenticating = false; @@ -56,7 +56,6 @@ Onyx.connectWithoutView({ callback: (val) => { authToken = val?.authToken ?? null; authTokenType = val?.authTokenType ?? null; - currentUserEmail = val?.email ?? null; checkRequiredData(); }, }); @@ -118,10 +117,6 @@ function setAuthToken(newAuthToken: string | null) { authToken = newAuthToken; } -function getCurrentUserEmail(): string | null { - return currentUserEmail; -} - function hasReadRequiredDataFromStorage(): Promise { return isReadyPromise; } From e0bacf1f9214558c7cd47c6f2a5db2ba7d429426 Mon Sep 17 00:00:00 2001 From: rory Date: Wed, 4 Feb 2026 16:55:50 -0800 Subject: [PATCH 10/10] Fix prettier --- src/libs/Log.ts | 2 +- src/libs/Network/NetworkStore.ts | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/libs/Log.ts b/src/libs/Log.ts index 67ccd95420382..3635007380f25 100644 --- a/src/libs/Log.ts +++ b/src/libs/Log.ts @@ -11,9 +11,9 @@ import ONYXKEYS from '@src/ONYXKEYS'; import pkg from '../../package.json'; import {addLog, flushAllLogsOnAppLaunch} from './actions/Console'; import {shouldAttachLog} from './Console'; +import {getCurrentUserEmail} from './CurrentUserStore'; import getPlatform from './getPlatform'; import {post} from './Network'; -import {getCurrentUserEmail} from './CurrentUserStore'; import requireParameters from './requireParameters'; import forwardLogsToSentry from './telemetry/forwardLogsToSentry'; diff --git a/src/libs/Network/NetworkStore.ts b/src/libs/Network/NetworkStore.ts index 1bf4e8c80d6a5..491b9d6ae2aca 100644 --- a/src/libs/Network/NetworkStore.ts +++ b/src/libs/Network/NetworkStore.ts @@ -1,10 +1,10 @@ import Onyx from 'react-native-onyx'; import type {ValueOf} from 'type-fest'; import CONST from '@src/CONST'; +import {getCurrentUserEmail} from '@src/libs/CurrentUserStore'; import Log from '@src/libs/Log'; import ONYXKEYS from '@src/ONYXKEYS'; import type Credentials from '@src/types/onyx/Credentials'; -import {getCurrentUserEmail} from '@src/libs/CurrentUserStore'; let credentials: Credentials | null | undefined; let lastShortAuthToken: string | null | undefined;