From 8123d4d56cd3dcc190300c991db59ab9f82a46af Mon Sep 17 00:00:00 2001 From: Taras Perun Date: Tue, 10 Dec 2024 12:15:05 +0100 Subject: [PATCH 1/2] add more logs --- src/libs/E2E/tests/linkingTest.e2e.ts | 21 ++++++++++++++++----- 1 file changed, 16 insertions(+), 5 deletions(-) diff --git a/src/libs/E2E/tests/linkingTest.e2e.ts b/src/libs/E2E/tests/linkingTest.e2e.ts index 2a85a5dabe6c..383fb82ebd21 100644 --- a/src/libs/E2E/tests/linkingTest.e2e.ts +++ b/src/libs/E2E/tests/linkingTest.e2e.ts @@ -25,6 +25,9 @@ const test = (config: NativeConfig) => { const linkedReportActionID = getConfigValueOrThrow('linkedReportActionID', config); const name = getConfigValueOrThrow('name', config); + const startTestTime = Date.now(); + console.debug('[E2E] Test started at:', startTestTime); + E2ELogin().then((neededLogin) => { if (neededLogin) { return waitForAppLoaded().then(() => E2EClient.submitTestDone()); @@ -35,7 +38,8 @@ const test = (config: NativeConfig) => { Promise.all([appearMessagePromise, openReportPromise]) .then(() => { - console.debug('[E2E] Test completed successfully, exiting…'); + console.debug('[E2E] Test completed successfully at:', Date.now()); + console.debug('[E2E] Total test duration:', Date.now() - startTestTime, 'ms'); E2EClient.submitTestDone(); }) .catch((err) => { @@ -43,9 +47,11 @@ const test = (config: NativeConfig) => { }); const subscription = DeviceEventEmitter.addListener('onViewableItemsChanged', (res: ViewableItemResponse) => { - console.debug('[E2E] Viewable items retrieved, verifying correct message…', res); + console.debug('[E2E] Viewable items event triggered at:', Date.now()); + console.debug('[E2E] Event details:', res); if (!!res && res?.at(0)?.item?.reportActionID === linkedReportActionID) { + console.debug('[E2E] Viewable item matched at:', Date.now()); appearMessageResolve(); subscription.remove(); } else { @@ -54,17 +60,22 @@ const test = (config: NativeConfig) => { }); Performance.subscribeToMeasurements((entry) => { + console.debug(`[E2E] Performance entry captured: ${entry.name} at ${entry.startTime}, duration: ${entry.duration} ms`); + if (entry.name === CONST.TIMING.SIDEBAR_LOADED) { - console.debug('[E2E] Sidebar loaded, navigating to a report…'); + console.debug('[E2E] Sidebar loaded, navigating to a report at:', Date.now()); + const startNavigateTime = Date.now(); Performance.markStart(CONST.TIMING.OPEN_REPORT); Navigation.navigate(ROUTES.REPORT_WITH_ID.getRoute(reportID)); + console.debug('[E2E] Navigation to report took:', Date.now() - startNavigateTime, 'ms'); return; } if (entry.name === CONST.TIMING.OPEN_REPORT) { - console.debug('[E2E] Linking: 1'); - console.debug('[E2E] Navigating to the linked report action…'); + console.debug('[E2E] Navigating to the linked report action at:', Date.now()); + const startLinkedNavigateTime = Date.now(); Navigation.navigate(ROUTES.REPORT_WITH_ID.getRoute(linkedReportID, linkedReportActionID)); + console.debug('[E2E] Navigation to linked report took:', Date.now() - startLinkedNavigateTime, 'ms'); E2EClient.submitTestResults({ branch: Config.E2E_BRANCH, From 25967aedcdba72845cbc6c82c903d405e1a90eb8 Mon Sep 17 00:00:00 2001 From: Taras Perun Date: Tue, 10 Dec 2024 15:08:15 +0100 Subject: [PATCH 2/2] check correctness linked message after timeout --- src/libs/E2E/tests/linkingTest.e2e.ts | 51 +++++++++++++++++++-------- 1 file changed, 37 insertions(+), 14 deletions(-) diff --git a/src/libs/E2E/tests/linkingTest.e2e.ts b/src/libs/E2E/tests/linkingTest.e2e.ts index 383fb82ebd21..38c659c0efe3 100644 --- a/src/libs/E2E/tests/linkingTest.e2e.ts +++ b/src/libs/E2E/tests/linkingTest.e2e.ts @@ -35,6 +35,41 @@ const test = (config: NativeConfig) => { const [appearMessagePromise, appearMessageResolve] = getPromiseWithResolve(); const [openReportPromise, openReportResolve] = getPromiseWithResolve(); + let lastVisibleMessageId: string | undefined; + let verificationStarted = false; + let hasNavigatedToLinkedMessage = false; + + const subscription = DeviceEventEmitter.addListener('onViewableItemsChanged', (res: ViewableItemResponse) => { + console.debug('[E2E] Viewable items event triggered at:', Date.now()); + + // update the last visible message + lastVisibleMessageId = res?.at(0)?.item?.reportActionID; + console.debug('[E2E] Current visible message:', lastVisibleMessageId); + + if (!verificationStarted && lastVisibleMessageId === linkedReportActionID) { + console.debug('[E2E] Target message found, starting verification'); + verificationStarted = true; + + setTimeout(() => { + console.debug('[E2E] Verification timeout completed'); + console.debug('[E2E] Last visible message ID:', lastVisibleMessageId); + console.debug('[E2E] Expected message ID:', linkedReportActionID); + + subscription.remove(); + if (lastVisibleMessageId === linkedReportActionID) { + console.debug('[E2E] Message position verified successfully'); + appearMessageResolve(); + } else { + console.debug('[E2E] Linked message not found, failing test!'); + E2EClient.submitTestResults({ + branch: Config.E2E_BRANCH, + error: 'Linked message not found', + name: `${name} test can't find linked message`, + }).then(() => E2EClient.submitTestDone()); + } + }, 3000); + } + }); Promise.all([appearMessagePromise, openReportPromise]) .then(() => { @@ -46,19 +81,6 @@ const test = (config: NativeConfig) => { console.debug('[E2E] Error while submitting test results:', err); }); - const subscription = DeviceEventEmitter.addListener('onViewableItemsChanged', (res: ViewableItemResponse) => { - console.debug('[E2E] Viewable items event triggered at:', Date.now()); - console.debug('[E2E] Event details:', res); - - if (!!res && res?.at(0)?.item?.reportActionID === linkedReportActionID) { - console.debug('[E2E] Viewable item matched at:', Date.now()); - appearMessageResolve(); - subscription.remove(); - } else { - console.debug(`[E2E] Provided message id '${res?.at(0)?.item?.reportActionID}' doesn't match to an expected '${linkedReportActionID}'. Waiting for a next one…`); - } - }); - Performance.subscribeToMeasurements((entry) => { console.debug(`[E2E] Performance entry captured: ${entry.name} at ${entry.startTime}, duration: ${entry.duration} ms`); @@ -71,9 +93,10 @@ const test = (config: NativeConfig) => { return; } - if (entry.name === CONST.TIMING.OPEN_REPORT) { + if (entry.name === CONST.TIMING.OPEN_REPORT && !hasNavigatedToLinkedMessage) { console.debug('[E2E] Navigating to the linked report action at:', Date.now()); const startLinkedNavigateTime = Date.now(); + hasNavigatedToLinkedMessage = true; // Set flag to prevent duplicate navigation Navigation.navigate(ROUTES.REPORT_WITH_ID.getRoute(linkedReportID, linkedReportActionID)); console.debug('[E2E] Navigation to linked report took:', Date.now() - startLinkedNavigateTime, 'ms');