Closed Bug 1794435 Opened 2 years ago Closed 1 year ago

Intermittent browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | single tracking bug

Categories

(Firefox :: Firefox View, defect, P3)

defect

Tracking

()

RESOLVED FIXED
113 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox105 --- unaffected
firefox106 --- unaffected
firefox107 --- wontfix
firefox108 --- wontfix
firefox111 --- wontfix
firefox112 --- wontfix
firefox113 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: sfoster)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled][fidefe-firefox-view][stockwell unknown])

Attachments

(3 files)

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=392791219&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HHHuOCyQSZavamShyjWBqQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HHHuOCyQSZavamShyjWBqQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2022-10-10T15:45:31.663Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Got element with selector: #tabpickup-tabs-container - 
[task 2022-10-10T15:45:31.663Z] 15:45:31     INFO - Buffered messages finished
[task 2022-10-10T15:45:31.664Z] 15:45:31     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | synced-tab-li-time text is 'Just now' - "2 min. ago" includes "Just now" - JS frame :: chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js :: test_time_updates_correctly/< :: line 339
[task 2022-10-10T15:45:31.664Z] 15:45:31     INFO - Stack trace:
[task 2022-10-10T15:45:31.664Z] 15:45:31     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js:test_time_updates_correctly/<:339
[task 2022-10-10T15:45:31.665Z] 15:45:31     INFO - Console message: 1665416731445	FirefoxView.TabsSetup	DEBUG	Handling UIState update
[task 2022-10-10T15:45:31.665Z] 15:45:31     INFO - Console message: 1665416731449	FirefoxView.TabsSetup	DEBUG	onSignedInChange, fxaSignedIn:: true
[task 2022-10-10T15:45:31.665Z] 15:45:31     INFO - Console message: 1665416731452	FirefoxView.TabsSetup	DEBUG	maybeUpdateUI, conditions not met to exit state: : synced-tabs-loaded
[task 2022-10-10T15:45:31.666Z] 15:45:31     INFO - Console message: 1665416731458	FirefoxView.TabsSetup	DEBUG	maybeUpdateUI, will notify update?:: true
[task 2022-10-10T15:45:31.666Z] 15:45:31     INFO - Console message: 1665416731469	FirefoxView.TabsSetup	DEBUG	refreshDevices, mobileDeviceConnected: true, : secondaryDeviceConnected: true
[task 2022-10-10T15:45:31.667Z] 15:45:31     INFO - Console message: 1665416731470	FirefoxView.TabsSetup	DEBUG	refreshDevices: no device state change
[task 2022-10-10T15:45:31.667Z] 15:45:31     INFO - Console message: 1665416731470	FirefoxView.TabsSetup	DEBUG	onSignedInChange, tabSyncNeeded:: false
[task 2022-10-10T15:45:31.668Z] 15:45:31     INFO - Console message: 1665416731471	FirefoxView.TabsSetup	DEBUG	Handling weave:service:sync:finish
[task 2022-10-10T15:45:31.668Z] 15:45:31     INFO - Console message: 1665416731473	FirefoxView.TabsSetup	DEBUG	maybeUpdateUI, conditions not met to exit state: : synced-tabs-loaded
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - Console message: 1665416731475	FirefoxView.TabsSetup	DEBUG	maybeUpdateUI, will notify update?:: false
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - Console message: [JavaScript Error: "TypeError: can't access property "status", state is null" {file: "resource://services-sync/UIState.jsm" line: 199}]
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - _setLastSyncTime@resource://services-sync/UIState.jsm:199:9
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - toggleSyncActivity@resource://services-sync/UIState.jsm:134:10
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - observe@resource://services-sync/UIState.jsm:102:14
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - setupListState@chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/head.js:312:16
[task 2022-10-10T15:45:31.669Z] 15:45:31     INFO - 
[task 2022-10-10T15:45:31.670Z] 15:45:31     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-10-10T15:45:31.670Z] 15:45:31     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | synced-tab-li-time text has updated - Didn't expect "2 min. ago", but got it
[task 2022-10-10T15:45:31.670Z] 15:45:31     INFO - Stack trace:
[task 2022-10-10T15:45:31.670Z] 15:45:31     INFO - chrome://mochikit/content/browser-test.js:test_isnot:1505
[task 2022-10-10T15:45:31.670Z] 15:45:31     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js:test_time_updates_correctly/<:356
[task 2022-10-10T15:45:31.868Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | parent must be in snapshot. Has [parent]. - true == true - 
[task 2022-10-10T15:45:31.868Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | After filtering we must have the expected number of events. - 3 == 3 - 
[task 2022-10-10T15:45:31.869Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | category in event firefoxview#entered#firefoxview must match. - "firefoxview" matches "firefoxview" - 
[task 2022-10-10T15:45:31.870Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | method in event firefoxview#entered#firefoxview must match. - "entered" matches "entered" - 
[task 2022-10-10T15:45:31.871Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | object in event firefoxview#entered#firefoxview must match. - "firefoxview" matches "firefoxview" - 
[task 2022-10-10T15:45:31.872Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | category in event firefoxview#synced_tabs#tabs must match. - "firefoxview" matches "firefoxview" - 
[task 2022-10-10T15:45:31.873Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | method in event firefoxview#synced_tabs#tabs must match. - "synced_tabs" matches "synced_tabs" - 
[task 2022-10-10T15:45:31.874Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | object in event firefoxview#synced_tabs#tabs must match. - "tabs" matches "tabs" - 
[task 2022-10-10T15:45:31.875Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Actual event firefoxview#synced_tabs#tabs expected to have extra. - true == true - 
[task 2022-10-10T15:45:31.875Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Expected key count must be in actual extra. Actual keys: [count]. - true == true - 
[task 2022-10-10T15:45:31.876Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | extra[count] must match in event firefoxview#synced_tabs#tabs. - "1" matches "1" - 
[task 2022-10-10T15:45:31.876Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | category in event firefoxview#tab_pickup#tabs must match. - "firefoxview" matches "firefoxview" - 
[task 2022-10-10T15:45:31.877Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | method in event firefoxview#tab_pickup#tabs must match. - "tab_pickup" matches "tab_pickup" - 
[task 2022-10-10T15:45:31.877Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | object in event firefoxview#tab_pickup#tabs must match. - "tabs" matches "tabs" - 
[task 2022-10-10T15:45:31.878Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Actual event firefoxview#tab_pickup#tabs expected to have extra. - true == true - 
[task 2022-10-10T15:45:31.878Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Expected key position must be in actual extra. Actual keys: [position,deviceType]. - true == true - 
[task 2022-10-10T15:45:31.878Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | extra[position] must match in event firefoxview#tab_pickup#tabs. - "1" matches "1" - 
[task 2022-10-10T15:45:31.879Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Expected key deviceType must be in actual extra. Actual keys: [position,deviceType]. - true == true - 
[task 2022-10-10T15:45:31.879Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | extra[deviceType] must match in event firefoxview#tab_pickup#tabs. - "desktop" matches "desktop" - 
[task 2022-10-10T15:45:31.880Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Tab opened at the beginning of the tab strip - 
[task 2022-10-10T15:45:31.918Z] 15:45:31     INFO - Waiting for the tab pickup summary to be visible
[task 2022-10-10T15:45:31.919Z] 15:45:31     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Got element with selector: #tab-pickup-container > summary - 
[task 2022-10-10T15:45:32.673Z] 15:45:32     INFO - clicking the summary to collapse it
[task 2022-10-10T15:45:33.319Z] 15:45:33     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | parent must be in snapshot. Has [parent]. - true == true - 
[task 2022-10-10T15:45:33.319Z] 15:45:33     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | After filtering we must have the expected number of events. - 1 == 1 - 
[task 2022-10-10T15:45:33.320Z] 15:45:33     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | category in event firefoxview#tab_pickup_open#tabs must match. - "firefoxview" matches "firefoxview" - 
[task 2022-10-10T15:45:33.321Z] 15:45:33     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | method in event firefoxview#tab_pickup_open#tabs must match. - "tab_pickup_open" matches "tab_pickup_open" - 
[task 2022-10-10T15:45:33.321Z] 15:45:33     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | object in event firefoxview#tab_pickup_open#tabs must match. - "tabs" matches "tabs" - 
[task 2022-10-10T15:45:33.322Z] 15:45:33     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | value in event firefoxview#tab_pickup_open#tabs must match. - "false" matches "false" - 
[task 2022-10-10T15:45:35.096Z] 15:45:35     INFO - Leaving test bound test_time_updates_correctly
[task 2022-10-10T15:45:35.269Z] 15:45:35     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-10-10T15:45:35.270Z] 15:45:35     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 
[task 2022-10-10T15:45:35.270Z] 15:45:35     INFO - GECKO(1489) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-10-10T15:45:35.271Z] 15:45:35     INFO - GECKO(1489) | MEMORY STAT | vsize 16334MB | residentFast 364MB | heapAllocated 175MB
[task 2022-10-10T15:45:35.271Z] 15:45:35     INFO - TEST-OK | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | took 48736ms
[task 2022-10-10T15:45:35.347Z] 15:45:35     INFO - checking window state
[task 2022-10-10T15:45:35.561Z] 15:45:35     INFO - GECKO(1489) | Completed ShutdownLeaks collections in process 1489
[task 2022-10-10T15:45:35.562Z] 15:45:35     INFO - TEST-START | Shutdown
Regressed by: 1792503

Set release status flags based on info from the regressing bug 1792503

:tgiles, since you are the author of the regressor, bug 1792503, could you take a look?

For more information, please visit auto_nag documentation.

This appeared as tier 1 failure here

Summary: Intermittent TV browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | single tracking bug → Intermittent browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | single tracking bug

I won't be able to look at this until later next week. Keeping NI open as a reminder.

Set release status flags based on info from the regressing bug 1792503

Update:
There have been 109 failures within the last 7 days:
• 107 failures on Linux 18.04 x64 WebRender debug
• 2 failures on OS X 10.15 WebRender opt
All failure lines that were classified with this bug, except 2, are: TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Test timed out -
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=394044259&repo=mozilla-central&lineNumber=23429

[task 2022-10-23T10:48:42.726Z] 10:48:42     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | waitingForTabs is false - 
[task 2022-10-23T10:48:42.726Z] 10:48:42     INFO - Buffered messages logged at 10:47:55
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - Console message: [JavaScript Error: "Invalid ETag value "undefined"" {file: "resource://services-settings/SyncHistory.jsm" line: 52}]
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - store@resource://services-settings/SyncHistory.jsm:52:13
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - 
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - Buffered messages finished
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Test timed out - 
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.733Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.734Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.735Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.735Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.736Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.808Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.810Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.908Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.909Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.971Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.972Z] 10:48:42     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:42.995Z] 10:48:42     INFO - GECKO(8893) | MEMORY STAT | vsize 3625MB | residentFast 720MB | heapAllocated 373MB
[task 2022-10-23T10:48:42.997Z] 10:48:42     INFO - TEST-OK | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | took 90629ms
[task 2022-10-23T10:48:43.020Z] 10:48:43     INFO - GECKO(8893) | [Child 9250: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7ff23d736c00 == 1 [pid = 9250] [id = 4]
[task 2022-10-23T10:48:43.020Z] 10:48:43     INFO - GECKO(8893) | [Child 9250: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7ff258c919f0) [pid = 9250] [serial = 13] [outer = 0]
[task 2022-10-23T10:48:43.023Z] 10:48:43     INFO - GECKO(8893) | [Child 9250: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7ff23d73ac00) [pid = 9250] [serial = 14] [outer = 7ff258c919f0]
[task 2022-10-23T10:48:43.104Z] 10:48:43     INFO - checking window state
[task 2022-10-23T10:48:43.106Z] 10:48:43     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-10-23T10:48:43.107Z] 10:48:43     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Found a browser window after previous test timed out - 
[task 2022-10-23T10:48:43.110Z] 10:48:43     INFO - GECKO(8893) | must wait for focus
[task 2022-10-23T10:48:43.205Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: '!CanHandleWith(aPresContext)', file /builds/worker/checkouts/gecko/dom/events/IMEStateManager.cpp:500
[task 2022-10-23T10:48:43.229Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:43.235Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:43.305Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:43.307Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:955
[task 2022-10-23T10:48:43.586Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2022-10-23T10:48:43.587Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2022-10-23T10:48:43.609Z] 10:48:43     INFO - GECKO(8893) | [Parent 8893, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:371
[task 2022-10-23T10:48:43.615Z] 10:48:43     INFO - TEST-START | browser/components/firefoxview/tests/browser/browser_ui_state.js
Whiteboard: [stockwell needswork:owner]

Yeah, I'm not sure when I'm going to have time to look at this. It's still in my queue to look at, but unfortunately have some higher priority work to get at first. Feel free to disable the test on Linux.

Assignee: nobody → aryx.bugmail
Status: NEW → ASSIGNED
Pushed by archaeopteryx@coole-files.de:
https://hg.mozilla.org/integration/autoland/rev/256fc6f1f72e
disable browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js on Linux debug r=intermittent-reviewers,jmaher DONTBUILD
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]

I've tried to reproduce this locally on an Ubuntu 22.04 machine using a full (non-artifact) debug build in order to match the failing CI job configuration. I'm able to get other tests to fail, at least when using --verify on the entire firefox view test suite, but I am not able to get this test to reproduce. Given the original failure in Comment #0 where "INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | synced-tab-li-time text is 'Just now' - "2 min. ago" includes "Just now", this seems to imply that something hung during the test just long enough to cause the synced time to be two minutes out of sync.

This error in Comment #0 seems to be the outlier though, most of the fails seem to do with a simple test timeout and then unexpected windows being present due to the previous time out. It does seem like it has something to due with the fact that we dynamically generate the "last used" time for the "test_tabs_sync_on_user_page_reload()". Switching this data to a different static list seems to cause the test to not timeout on Try, although there are other failures in the bc14 suite. I could have probably just not checked the time label instead of using different mocked tabs, but either way.

If this new Try run passes (or at least this particular test doesn't intermittent), then we should be able to re-enable this test and resolve the bug.

(Keeping NI open to follow up on the Try run next week)

Flags: needinfo?(tgiles)
Pushed by tgiles@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c5cc0f31aaff
Fix intermittent tab pickup test. r=sfoster
Assignee: aryx.bugmail → nobody
Status: ASSIGNED → NEW

There have been 34 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-asan-qr
  • linux1804-64-qr
  • windows10-64-2004-asan-qr
[task 2023-02-11T10:42:34.222Z] 10:42:34     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | Third item in Tab Pickup list is Sandboxes - Sinon.JS - true == true - 
[task 2023-02-11T10:42:34.223Z] 10:42:34     INFO - Console message: 1676112153484	FirefoxView.TabsSetup	DEBUG	Handling UIState update
[task 2023-02-11T10:42:34.223Z] 10:42:34     INFO - Console message: 1676112153485	FirefoxView.TabsSetup	DEBUG	onSignedInChange, fxaSignedIn:: true
[task 2023-02-11T10:42:34.223Z] 10:42:34     INFO - Console message: 1676112153486	FirefoxView.TabsSetup	DEBUG	maybeUpdateUI, conditions not met to exit state: : synced-tabs-loaded
[task 2023-02-11T10:42:34.224Z] 10:42:34     INFO - Console message: 1676112153486	FirefoxView.TabsSetup	DEBUG	maybeUpdateUI, will notify update?:: true
[task 2023-02-11T10:42:34.224Z] 10:42:34     INFO - Console message: 1676112153527	FirefoxView.TabsSetup	DEBUG	refreshDevices, mobileDeviceConnected: true, : secondaryDeviceConnected: true
[task 2023-02-11T10:42:34.225Z] 10:42:34     INFO - Console message: 1676112153527	FirefoxView.TabsSetup	DEBUG	refreshDevices: no device state change
[task 2023-02-11T10:42:34.226Z] 10:42:34     INFO - Console message: 1676112153552	FirefoxView.TabsSetup	DEBUG	onSignedInChange, tabSyncNeeded:: false
[task 2023-02-11T10:42:34.227Z] 10:42:34     INFO - Buffered messages finished
[task 2023-02-11T10:42:34.227Z] 10:42:34     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | The synced tabs list was not mutated - false == true - {"filename":"chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js","name":"test_tabs_dont_update_unnecessarily/<","sourceId":2957,"lineNumber":766,"columnNumber":12,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"test_tabs_dont_update_unnecessarily/<@chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js:766:12\n","nativeSavedFrame":{}}
[task 2023-02-11T10:42:34.230Z] 10:42:34     INFO - Stack trace:
[task 2023-02-11T10:42:34.230Z] 10:42:34     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js:test_tabs_dont_update_unnecessarily/<:766
[task 2023-02-11T10:42:34.230Z] 10:42:34     INFO - GECKO(9016) | JavaScript error: resource:///actors/ContentSearchParent.sys.mjs, line 656: TypeError: can't access property "addEventListener", browser is null
[task 2023-02-11T10:42:34.230Z] 10:42:34     INFO - GECKO(9016) | JavaScript error: resource:///actors/ContentSearchParent.sys.mjs, line 656: TypeError: can't access property "addEventListener", browser is null
[task 2023-02-11T10:42:34.313Z] 10:42:34     INFO - Console message: [JavaScript Error: "TypeError: can't access property "addEventListener", browser is null" {file: "resource:///actors/ContentSearchParent.sys.mjs" line: 656}]
[task 2023-02-11T10:42:34.314Z] 10:42:34     INFO - receiveMessage@resource:///actors/ContentSearchParent.sys.mjs:656:5
[task 2023-02-11T10:42:34.314Z] 10:42:34     INFO - 
[task 2023-02-11T10:42:34.315Z] 10:42:34     INFO - Console message: [JavaScript Error: "TypeError: can't access property "addEventListener", browser is null" {file: "resource:///actors/ContentSearchParent.sys.mjs" line: 656}]
[task 2023-02-11T10:42:34.315Z] 10:42:34     INFO - receiveMessage@resource:///actors/ContentSearchParent.sys.mjs:656:5
[task 2023-02-11T10:42:34.316Z] 10:42:34     INFO - 
[task 2023-02-11T10:42:34.320Z] 10:42:34     INFO - Leaving test bound test_tabs_dont_update_unnecessarily
[task 2023-02-11T10:42:34.561Z] 10:42:34     INFO - GECKO(9016) | MEMORY STAT | vsize 20983888MB | residentFast 1878MB
[task 2023-02-11T10:42:34.564Z] 10:42:34     INFO - TEST-OK | browser/components/firefoxview/tests/browser/browser_tab_pickup_list.js | took 16759ms

Sam, as the owner of this component, can you assign this to someone?
Thank you.

Flags: needinfo?(sfoster)
Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork:owner]

The "just now" label on these items has been an ongoing source of timing-related test failures. We should probably think of a different way to verify this functionality that doesnt involve the system clock and assumptions around how long a test should take to run. I don't have the ability to assign this bug, but as its still relatively high frequency I can make sure its in our backlog and suggest we include it in the next sprint.

Flags: needinfo?(sfoster)
Whiteboard: [stockwell disabled][stockwell needswork:owner] → [stockwell disabled][stockwell needswork:owner] [fidefe-firefox-view]
Priority: P5 → P3

Update:
There have been 44 total failures in the last 7 days.
There are:

  • 1 failure on linux1804-64-asan-qr opt
  • 25 failures on linux1804-64-qr opt and debug
  • 1 failure on linux1804-64-shippable-qr opt
  • 10 failures on linux1804-64-tsan-qr opt
  • 4 failures at macosx1015-64-qr opt and debug
  • 1 failure on windows11-32-2009-qr opt
  • 1 failure on windows11-64-2009-asan-qr opt
  • 1 failure on windows11-64-2009-qr debug

Recent failure log.

Sam, are there any updates? Thank you.

Flags: needinfo?(sfoster)
See Also: → 1822077

I think most or perhaps all of these failures are related to the updateTime function which is on a setInterval, and is used to change the label from "just now" to "1hr ago" or whatever. This sometimes happens while another test is waiting for a DOM mutation from some other operation (or asserting that none should happen.) I have a proposed fix I can land if it looks solid on try.

Assignee: nobody → sfoster
Status: NEW → ASSIGNED
Flags: needinfo?(sfoster)
See Also: → 1823805
Pushed by sfoster@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/52196a3c61ce
Make updateTime a noop when the updateTimeMs pref is 0. r=fxview-reviewers,sclements

The patch in attachment 9324312 [details] should fix this - or at least significantly reduce the rate of failure. I have a bunch of try pushes that look good. I'm going to resolve this, but please re-open and let me know if this test continues to show problems.

Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 113 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: