Closed Bug 1597951 Opened 5 years ago Closed 5 years ago

Intermittent TV widget/tests/browser/browser_test_clipboardcache.js | Test timed out -

Categories

(Core :: Widget, defect, P5)

Product:
Core
Component:
Widget
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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

[task 2019-11-20T11:06:24.650Z] 11:06:24 INFO - runtests.py | Waiting for browser...
[task 2019-11-20T11:06:24.658Z] 11:06:24 INFO - GECKO(12666) | 1574247984654 Marionette DEBUG Closed connection 1
[task 2019-11-20T11:06:24.969Z] 11:06:24 INFO - *** Start BrowserChrome Test Results ***
[task 2019-11-20T11:06:24.970Z] 11:06:24 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12666.
[task 2019-11-20T11:06:25.240Z] 11:06:25 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:06:26.107Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:06:26.108Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12718.
[task 2019-11-20T11:06:26.109Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12799.
[task 2019-11-20T11:06:26.110Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12739.
[task 2019-11-20T11:06:26.380Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:06:26.479Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:06:26.737Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:06:26.773Z] 11:06:26 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:06:27.036Z] 11:06:27 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:06:27.193Z] 11:06:27 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:06:27.417Z] 11:06:27 INFO - checking window state
[task 2019-11-20T11:06:27.498Z] 11:06:27 INFO - TEST-START | widget/tests/browser/browser_test_clipboardcache.js
[task 2019-11-20T11:06:29.197Z] 11:06:29 INFO - GECKO(12666) | [CodeCoverage] Setting handlers for process 12835.
[task 2019-11-20T11:06:30.244Z] 11:06:30 INFO - GECKO(12666) | [CodeCoverage] Setting handlers for process 12859.
[task 2019-11-20T11:06:31.907Z] 11:06:31 INFO - GECKO(12666) | [CodeCoverage] Setting handlers for process 12914.
[task 2019-11-20T11:07:12.554Z] 11:07:12 INFO - TEST-INFO | started process screentopng
[task 2019-11-20T11:07:12.934Z] 11:07:12 INFO - TEST-INFO | screentopng: exit 0
[task 2019-11-20T11:07:12.935Z] 11:07:12 INFO - Buffered messages logged at 11:06:27
[task 2019-11-20T11:07:12.935Z] 11:07:12 INFO - Entering test bound test_private
[task 2019-11-20T11:07:12.935Z] 11:07:12 INFO - Buffered messages logged at 11:06:31
[task 2019-11-20T11:07:12.935Z] 11:07:12 INFO - TEST-PASS | widget/tests/browser/browser_test_clipboardcache.js | Private write -
[task 2019-11-20T11:07:12.935Z] 11:07:12 INFO - Buffered messages logged at 11:06:33
[task 2019-11-20T11:07:12.935Z] 11:07:12 INFO - TEST-PASS | widget/tests/browser/browser_test_clipboardcache.js | Read what we pasted -
[task 2019-11-20T11:07:12.936Z] 11:07:12 INFO - TEST-PASS | widget/tests/browser/browser_test_clipboardcache.js | Private read -
[task 2019-11-20T11:07:12.936Z] 11:07:12 INFO - Buffered messages finished
[task 2019-11-20T11:07:12.937Z] 11:07:12 INFO - TEST-UNEXPECTED-FAIL | widget/tests/browser/browser_test_clipboardcache.js | Test timed out -
[task 2019-11-20T11:07:12.937Z] 11:07:12 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12666.
[task 2019-11-20T11:07:12.937Z] 11:07:12 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:14.385Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:14.385Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12739.
[task 2019-11-20T11:07:14.386Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12799.
[task 2019-11-20T11:07:14.388Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12835.
[task 2019-11-20T11:07:14.388Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12914.
[task 2019-11-20T11:07:14.389Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12718.
[task 2019-11-20T11:07:14.699Z] 11:07:14 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:15.042Z] 11:07:15 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:15.373Z] 11:07:15 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:15.490Z] 11:07:15 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:15.768Z] 11:07:15 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:15.905Z] 11:07:15 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:16.248Z] 11:07:16 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:16.324Z] 11:07:16 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:16.667Z] 11:07:16 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:16.831Z] 11:07:16 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:17.297Z] 11:07:17 INFO - GECKO(12666) | [CodeCoverage] Requested flush for 12859.
[task 2019-11-20T11:07:17.314Z] 11:07:17 INFO - TEST-PASS | widget/tests/browser/browser_test_clipboardcache.js | Drop clipboard cache if any -
[task 2019-11-20T11:07:17.497Z] 11:07:17 INFO - Leaving test bound test_private
[task 2019-11-20T11:07:17.498Z] 11:07:17 INFO - Entering test bound test_non_private
[task 2019-11-20T11:07:17.586Z] 11:07:17 INFO - GECKO(12666) | [CodeCoverage] flush completed.
[task 2019-11-20T11:07:17.707Z] 11:07:17 INFO - GECKO(12666) | [CodeCoverage] JS flush completed.
[task 2019-11-20T11:07:18.389Z] 11:07:18 INFO - GECKO(12666) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2019-11-20T11:07:18.389Z] 11:07:18 INFO - GECKO(12666) | MEMORY STAT | vsize 3247MB | residentFast 524MB | heapAllocated 165MB
[task 2019-11-20T11:07:18.390Z] 11:07:18 INFO - TEST-OK | widget/tests/browser/browser_test_clipboardcache.js | took 50887ms
[task 2019-11-20T11:07:18.774Z] 11:07:18 INFO - checking window state
[task 2019-11-20T11:07:18.775Z] 11:07:18 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-11-20T11:07:18.776Z] 11:07:18 INFO - TEST-UNEXPECTED-FAIL | widget/tests/browser/browser_test_clipboardcache.js | Found a browser window after previous test timed out -
[task 2019-11-20T11:07:19.606Z] 11:07:19 INFO - GECKO(12666) | [CodeCoverage] Setting handlers for process 12943.
[task 2019-11-20T11:07:22.103Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12859
[task 2019-11-20T11:07:22.119Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12943
[task 2019-11-20T11:07:22.167Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12835
[task 2019-11-20T11:07:22.224Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12799
[task 2019-11-20T11:07:22.302Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12914
[task 2019-11-20T11:07:22.342Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12718
[task 2019-11-20T11:07:22.423Z] 11:07:22 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12739
[task 2019-11-20T11:07:23.299Z] 11:07:23 INFO - GECKO(12666) | [CodeCoverage] Setting handlers for process 12967.
[task 2019-11-20T11:07:24.609Z] 11:07:24 INFO - GECKO(12666) | Completed ShutdownLeaks collections in process 12666
[task 2019-11-20T11:07:24.610Z] 11:07:24 INFO - TEST-START | Shutdown
[task 2019-11-20T11:07:24.611Z] 11:07:24 INFO - Browser Chrome Test Summary
[task 2019-11-20T11:07:24.612Z] 11:07:24 INFO - Passed: 4
[task 2019-11-20T11:07:24.613Z] 11:07:24 INFO - Failed: 2
[task 2019-11-20T11:07:24.614Z] 11:07:24 INFO - Todo: 0
[task 2019-11-20T11:07:24.614Z] 11:07:24 INFO - Mode: e10s
[task 2019-11-20T11:07:24.615Z] 11:07:24 INFO - *** End BrowserChrome Test Results ***
[task 2019-11-20T11:07:24.919Z] 11:07:24 INFO - GECKO(12666) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T11:07:25.048Z] 11:07:25 INFO - GECKO(12666) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T11:07:25.066Z] 11:07:25 INFO - GECKO(12666) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T11:07:25.172Z] 11:07:25 INFO - GECKO(12666) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T11:07:25.395Z] 11:07:25 INFO - GECKO(12666) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T11:07:25.942Z] 11:07:25 INFO - GECKO(12666) | 1574248045938 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2019-11-20T11:07:25.944Z] 11:07:25 INFO - GECKO(12666) | 1574248045938 Marionette INFO Stopped listening on port 2828
[task 2019-11-20T11:07:25.945Z] 11:07:25 INFO - GECKO(12666) | 1574248045938 Marionette DEBUG Remote service is inactive
[task 2019-11-20T11:07:31.178Z] 11:07:31 INFO - TEST-INFO | Main app process: exit 0

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.