1479956 - Intermittent test-verify toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Test timed out.

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Testing, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ncsoregi [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=191257427&repo=autoland

https://queue.taskcluster.net/v1/task/YYtzd1GLTuWdnQSPUPFbTg/runs/0/artifacts/public/logs/live_backing.log

[task 2018-07-31T23:06:16.978Z] 23:06:16     INFO -  114 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Read promise successfully resolved
[task 2018-07-31T23:06:16.978Z] 23:06:16     INFO -  Buffered messages logged at 23:05:55
[task 2018-07-31T23:06:16.979Z] 23:06:16     INFO -  115 INFO AddTask.js | Leaving test test_contentscript_clipboard_nocontents_read
[task 2018-07-31T23:06:16.979Z] 23:06:16     INFO -  Buffered messages finished
[task 2018-07-31T23:06:16.979Z] 23:06:16     INFO -  116 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Test timed out.
[task 2018-07-31T23:06:16.980Z] 23:06:16     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-31T23:06:16.980Z] 23:06:16     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-07-31T23:06:16.980Z] 23:06:16     INFO -  117 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Test timed out.
[task 2018-07-31T23:06:16.981Z] 23:06:16     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-31T23:06:16.981Z] 23:06:16     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-07-31T23:06:16.982Z] 23:06:16     INFO -  118 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Test timed out.
[task 2018-07-31T23:06:16.982Z] 23:06:16     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-31T23:06:16.982Z] 23:06:16     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-07-31T23:06:16.983Z] 23:06:16     INFO -  119 INFO TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | took 301098ms
[task 2018-07-31T23:06:19.428Z] 23:06:19     INFO -  120 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Test timed out.
[task 2018-07-31T23:06:19.428Z] 23:06:19     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-31T23:06:19.428Z] 23:06:19     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-07-31T23:06:19.429Z] 23:06:19     INFO -  121 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
[task 2018-07-31T23:06:19.429Z] 23:06:19     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-31T23:06:19.429Z] 23:06:19     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:150:9
[task 2018-07-31T23:06:19.429Z] 23:06:19     INFO -  122 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 1 remaining tests.
[task 2018-07-31T23:06:19.429Z] 23:06:19     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-31T23:06:19.430Z] 23:06:19     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:152:9
[task 2018-07-31T23:06:19.430Z] 23:06:19     INFO -  123 ERROR (SimpleTest/TestRunner.js) logged result after SimpleTest.finish(): Test timed out.
[task 2018-07-31T23:06:19.430Z] 23:06:19     INFO -  124 ERROR (SimpleTest/TestRunner.js) logged result after SimpleTest.finish(): Test timed out.
[task 2018-07-31T23:06:19.430Z] 23:06:19     INFO -  125 ERROR (SimpleTest/TestRunner.js) logged result after SimpleTest.finish(): Test timed out.
[task 2018-07-31T23:06:19.430Z] 23:06:19     INFO -  126 ERROR (SimpleTest/TestRunner.js) logged result after SimpleTest.finish(): Test timed out.
[task 2018-07-31T23:06:19.431Z] 23:06:19     INFO -  127 ERROR (SimpleTest/TestRunner.js) logged result after SimpleTest.finish(): 4 test timeouts, giving up.
[task 2018-07-31T23:06:19.431Z] 23:06:19     INFO -  128 ERROR (SimpleTest/TestRunner.js) logged result after SimpleTest.finish(): Skipping 1 remaining tests.

Comment 1

[Geoff Brown [:gbrown]]

On this push, test_ext_async_clipboard.html passed test-verify on Linux and OSX and was correctly skipped on Windows. On Android/opt, it passed test-verify: It only failed on Android/debug.

This test was added in bug 1461465.

On Android/debug, this is a relatively long-running test, taking about 200 seconds to complete.

In the failure log from comment 0, test-verify failed in step 1 of verification, running the test 10 times in 1 browser session; the test passed 8 times, then timed out on the 9th iteration.

The first time out happened only 21 seconds after the last buffered message:

[task 2018-07-31T23:06:16.978Z] 23:06:16     INFO -  Buffered messages logged at 23:05:55
[task 2018-07-31T23:06:16.979Z] 23:06:16     INFO -  115 INFO AddTask.js | Leaving test test_contentscript_clipboard_nocontents_read
[task 2018-07-31T23:06:16.979Z] 23:06:16     INFO -  Buffered messages finished
[task 2018-07-31T23:06:16.979Z] 23:06:16     INFO -  116 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_async_clipboard.html | Test timed out.

I am a little surprised the time out is that short: It seems too aggressive for a slow platform like Android/debug.

Comment 2

[meck93]

We are trying to build a tool to automatically classify intermittent failures, which would provide a starting point for fixing the bug, reducing the manual work for the developers.
We are collecting some feedback on the results, to see if they’re good enough and where we need to improve.
    
For this bug, the tool says that the intermittent failure is most likely a:
Assertion Failure (test vs. reference value): This includes test failures in which a (pre-) defined value was not met or the value that the test produced lies outside of the range of acceptable values. This often occurs when running reference tests (e.g. comparing images, audio, etc.). Also, this includes wrong assertion statements only leading to intermittent- and not permanent-failures.


Once you’re done investigating and/or fixing the bug, could you tell me:
- Did the tool correctly recognize the type of intermittent failure?
- Did the information from the tool help your analysis, the bug fixing process, or anything in the process? (please also let us know how the tool was useful and/or what would improve the tool's usefulness for you)

Comment 3

[Anny Gakhokidze [:annyG]]

Attachment: Bug 1479956 - Fixed async clipboard API tests, r=nika

MozReview-Commit-ID: Bjz9OI2lAyw

Comment 4

[Nika Layzell [:nika] (ni? for response)]

Comment on attachment 8998193 [details]
Bug 1479956 - Fixed async clipboard API tests, r=nika

:Nika Layzell has approved the revision.

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/01a46abce8fa
Fixed async clipboard API tests, r=nika

Comment 6

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/01a46abce8fa