Closed Bug 1670979 Opened 4 years ago Closed 2 years ago

Intermittent toolkit/components/pictureinpicture/tests/browser_videoSelection.js | Test timed out -

Categories

(Toolkit :: Video/Audio Controls, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1787022

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=318496230&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/V3FtGOwuQ9e3biG7eYJN_w/runs/0/artifacts/public/logs/live_backing.log


[task 2020-10-13T16:15:11.824Z] 16:15:11 INFO - TEST-START | toolkit/components/pictureinpicture/tests/browser_videoSelection.js
[task 2020-10-13T16:16:41.890Z] 16:16:41 INFO - TEST-INFO | started process screentopng
[task 2020-10-13T16:16:42.512Z] 16:16:42 INFO - TEST-INFO | screentopng: exit 0
[task 2020-10-13T16:16:42.512Z] 16:16:42 INFO - Buffered messages logged at 16:15:11
[task 2020-10-13T16:16:42.512Z] 16:16:42 INFO - Entering test bound test_video_selection
[task 2020-10-13T16:16:42.512Z] 16:16:42 INFO - Buffered messages logged at 16:15:12
[task 2020-10-13T16:16:42.512Z] 16:16:42 INFO - Waiting for videos to be ready
[task 2020-10-13T16:16:42.512Z] 16:16:42 INFO - Buffered messages logged at 16:15:13
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - Waiting for 'canplaythrough' for 'long'
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - Buffered messages finished
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_videoSelection.js | Test timed out -
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - GECKO(2332) | MEMORY STAT | vsize 20975806MB | residentFast 1160MB
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - TEST-OK | toolkit/components/pictureinpicture/tests/browser_videoSelection.js | took 90077ms
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_videoSelection.js | Found a tab after previous test timed out: http://example.com/browser/toolkit/components/pictureinpicture/tests/test-video-selection.html -
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - checking window state
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-10-13T16:16:42.513Z] 16:16:42 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_videoSelection.js | Uncaught exception received from previously timed out test - AbortError: Actor 'SpecialPowers' destroyed before query 'Spawn' was resolved
[task 2020-10-13T16:16:42.809Z] 16:16:42 INFO - GECKO(2332) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-10-13T16:16:43.625Z] 16:16:43 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:43.786Z] 16:16:43 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:43.787Z] 16:16:43 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:43.787Z] 16:16:43 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:43.787Z] 16:16:43 INFO - GECKO(2332) | 14 448 nsComponentManagerImpl
[task 2020-10-13T16:16:43.787Z] 16:16:43 INFO - GECKO(2332) | 2 288 libfontconfig.so
[task 2020-10-13T16:16:43.787Z] 16:16:43 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:43.968Z] 16:16:43 INFO - GECKO(2332) | Completed ShutdownLeaks collections in process 2562
[task 2020-10-13T16:16:44.030Z] 16:16:44 INFO - GECKO(2332) | Completed ShutdownLeaks collections in process 2423
[task 2020-10-13T16:16:44.098Z] 16:16:44 INFO - GECKO(2332) | Completed ShutdownLeaks collections in process 2441
[task 2020-10-13T16:16:44.106Z] 16:16:44 INFO - GECKO(2332) | Completed ShutdownLeaks collections in process 2533
[task 2020-10-13T16:16:44.267Z] 16:16:44 INFO - GECKO(2332) | Completed ShutdownLeaks collections in process 2506
[task 2020-10-13T16:16:44.812Z] 16:16:44 INFO - GECKO(2332) | Completed ShutdownLeaks collections in process 2332
[task 2020-10-13T16:16:44.814Z] 16:16:44 INFO - TEST-START | Shutdown
[task 2020-10-13T16:16:44.815Z] 16:16:44 INFO - Browser Chrome Test Summary
[task 2020-10-13T16:16:44.816Z] 16:16:44 INFO - Passed: 472
[task 2020-10-13T16:16:44.817Z] 16:16:44 INFO - Failed: 3
[task 2020-10-13T16:16:44.818Z] 16:16:44 INFO - Todo: 0
[task 2020-10-13T16:16:44.818Z] 16:16:44 INFO - Mode: e10s
[task 2020-10-13T16:16:44.819Z] 16:16:44 INFO - *** End BrowserChrome Test Results ***
[task 2020-10-13T16:16:45.097Z] 16:16:45 INFO - GECKO(2332) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-10-13T16:16:45.097Z] 16:16:45 INFO - GECKO(2332) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-10-13T16:16:46.829Z] 16:16:46 INFO - GECKO(2332) | 1602605806819 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-10-13T16:16:46.829Z] 16:16:46 INFO - GECKO(2332) | 1602605806820 Marionette INFO Stopped listening on port 2828
[task 2020-10-13T16:16:46.829Z] 16:16:46 INFO - GECKO(2332) | 1602605806820 Marionette DEBUG Marionette stopped listening
[task 2020-10-13T16:16:47.373Z] 16:16:47 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:47.696Z] 16:16:47 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:48.023Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.023Z] 16:16:48 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:48.023Z] 16:16:48 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:48.023Z] 16:16:48 INFO - GECKO(2332) | 14 448 nsComponentManagerImpl
[task 2020-10-13T16:16:48.023Z] 16:16:48 INFO - GECKO(2332) | 633 18287 libfontconfig.so
[task 2020-10-13T16:16:48.023Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.124Z] 16:16:48 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:48.124Z] 16:16:48 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:48.252Z] 16:16:48 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:48.401Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.402Z] 16:16:48 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:48.403Z] 16:16:48 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:48.405Z] 16:16:48 INFO - GECKO(2332) | 14 448 nsComponentManagerImpl
[task 2020-10-13T16:16:48.406Z] 16:16:48 INFO - GECKO(2332) | 633 18287 libfontconfig.so
[task 2020-10-13T16:16:48.406Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.627Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.629Z] 16:16:48 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:48.630Z] 16:16:48 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:48.631Z] 16:16:48 INFO - GECKO(2332) | 14 448 nsComponentManagerImpl
[task 2020-10-13T16:16:48.632Z] 16:16:48 INFO - GECKO(2332) | 633 18287 libfontconfig.so
[task 2020-10-13T16:16:48.633Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.696Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.697Z] 16:16:48 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:48.698Z] 16:16:48 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:48.700Z] 16:16:48 INFO - GECKO(2332) | 14 448 nsComponentManagerImpl
[task 2020-10-13T16:16:48.700Z] 16:16:48 INFO - GECKO(2332) | 633 18287 libfontconfig.so
[task 2020-10-13T16:16:48.702Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.703Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:48.703Z] 16:16:48 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:48.707Z] 16:16:48 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:48.707Z] 16:16:48 INFO - GECKO(2332) | 14 448 nsComponentManagerImpl
[task 2020-10-13T16:16:48.707Z] 16:16:48 INFO - GECKO(2332) | 633 18287 libfontconfig.so
[task 2020-10-13T16:16:48.708Z] 16:16:48 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:49.550Z] 16:16:49 INFO - GECKO(2332) | error: address range table at offset 0x5e60 has an invalid tuple (length = 0) at offset 0x5e80
[task 2020-10-13T16:16:49.692Z] 16:16:49 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:49.693Z] 16:16:49 INFO - GECKO(2332) | Suppressions used:
[task 2020-10-13T16:16:49.693Z] 16:16:49 INFO - GECKO(2332) | count bytes template
[task 2020-10-13T16:16:49.694Z] 16:16:49 INFO - GECKO(2332) | 14 432 nsComponentManagerImpl
[task 2020-10-13T16:16:49.694Z] 16:16:49 INFO - GECKO(2332) | 633 18083 libfontconfig.so
[task 2020-10-13T16:16:49.695Z] 16:16:49 INFO - GECKO(2332) | 2 768 libcairo.so
[task 2020-10-13T16:16:49.695Z] 16:16:49 INFO - GECKO(2332) | 1 16384 libglib-2.0.so
[task 2020-10-13T16:16:49.696Z] 16:16:49 INFO - GECKO(2332) | 4 2080 libpixman-1.so
[task 2020-10-13T16:16:49.696Z] 16:16:49 INFO - GECKO(2332) | 3 624 mozJSComponentLoader
[task 2020-10-13T16:16:49.697Z] 16:16:49 INFO - GECKO(2332) | -----------------------------------------------------
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - TEST-INFO | Main app process: exit 0
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - runtests.py | Application ran for: 0:03:15.696728
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - zombiecheck | Reading PID log: /tmp/tmpRvK23Lpidlog
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - ==> process 2332 launched child process 2352
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - ==> process 2332 launched child process 2423
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - ==> process 2332 launched child process 2441
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - ==> process 2332 launched child process 2506
[task 2020-10-13T16:16:49.811Z] 16:16:49 INFO - ==> process 2332 launched child process 2533
[task 2020-10-13T16:16:49.813Z] 16:16:49 INFO - ==> process 2332 launched child process 2562
[task 2020-10-13T16:16:49.813Z] 16:16:49 INFO - ==> process 2332 launched child process 2594
[task 2020-10-13T16:16:49.814Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2562
[task 2020-10-13T16:16:49.814Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2533
[task 2020-10-13T16:16:49.814Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2441
[task 2020-10-13T16:16:49.815Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2506
[task 2020-10-13T16:16:49.815Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2594
[task 2020-10-13T16:16:49.816Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2352
[task 2020-10-13T16:16:49.816Z] 16:16:49 INFO - zombiecheck | Checking for orphan process with PID: 2423
[task 2020-10-13T16:16:49.816Z] 16:16:49 INFO - Stopping web server
[task 2020-10-13T16:16:49.817Z] 16:16:49 INFO - Stopping web socket server
[task 2020-10-13T16:16:49.827Z] 16:16:49 INFO - Stopping ssltunnel
[task 2020-10-13T16:16:49.844Z] 16:16:49 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2020-10-13T16:16:49.844Z] 16:16:49 INFO - runtests.py | Running tests: end.
[task 2020-10-13T16:16:49.865Z] 16:16:49 INFO - Buffered messages finished
[task 2020-10-13T16:16:49.866Z] 16:16:49 INFO - TEST-INFO | checking window state
[task 2020-10-13T16:16:49.866Z] 16:16:49 INFO - Browser Chrome Test Summary
[task 2020-10-13T16:16:49.867Z] 16:16:49 INFO - Passed: 1027
[task 2020-10-13T16:16:49.867Z] 16:16:49 INFO - Failed: 3
[task 2020-10-13T16:16:49.867Z] 16:16:49 INFO - Todo: 0
[task 2020-10-13T16:16:49.868Z] 16:16:49 INFO - Mode: e10s
[task 2020-10-13T16:16:49.868Z] 16:16:49 INFO - *** End BrowserChrome Test Results ***
[task 2020-10-13T16:16:49.869Z] 16:16:49 INFO - Buffered messages finished
[task 2020-10-13T16:16:49.870Z] 16:16:49 INFO - SUITE-END | took 297s
[task 2020-10-13T16:16:49.919Z] 16:16:49 ERROR - Return code: 1
[task 2020-10-13T16:16:49.920Z] 16:16:49 ERROR - Got 3 unexpected statuses

There fave been 29 failures in the last 7 days.

Happens on:

  • linux1804-64-asan-qr
  • linux1804-64-qr
  • linux1804-64-shippable-qr

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=367572665&repo=autoland&lineNumber=3400

Whiteboard: [stockwell needswork:owner]
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.