Intermittent dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.5170680238228297
Categories
(Core :: DOM: Core & HTML, defect)
Tracking
()
Tracking | Status | |
---|---|---|
firefox86 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: apavel)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell unknown])
Attachments
(2 files)
Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=318164364&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/W_FIdBiTSHCEKks1x6td4g/runs/0/artifacts/public/logs/live_backing.log
[task 2020-10-09T12:03:13.542Z] 12:03:13 INFO - TEST-START | dom/base/test/useractivation/test_clipboard_editor.html
[task 2020-10-09T12:03:26.871Z] 12:03:26 INFO - TEST-INFO | started process screencapture
[task 2020-10-09T12:03:26.992Z] 12:03:26 INFO - TEST-INFO | screencapture: exit 0
[task 2020-10-09T12:03:26.992Z] 12:03:26 INFO - <snipped 6 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
[task 2020-10-09T12:03:26.992Z] 12:03:26 INFO - Buffered messages logged at 12:03:14
[task 2020-10-09T12:03:26.993Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.2014797709281757"...
[task 2020-10-09T12:03:26.993Z] 12:03:26 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:26.993Z] 12:03:26 INFO - Buffered messages logged at 12:03:15
[task 2020-10-09T12:03:26.993Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.2014797709281757
[task 2020-10-09T12:03:26.994Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 0 - 2
[task 2020-10-09T12:03:26.994Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 0 - 2
[task 2020-10-09T12:03:26.994Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.571554504290182"...
[task 2020-10-09T12:03:26.994Z] 12:03:26 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:26.994Z] 12:03:26 INFO - Buffered messages logged at 12:03:16
[task 2020-10-09T12:03:26.995Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'text text'
[task 2020-10-09T12:03:26.995Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 0 - 4
[task 2020-10-09T12:03:26.995Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 0 - 4
[task 2020-10-09T12:03:26.995Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.160049676935494"...
[task 2020-10-09T12:03:26.995Z] 12:03:26 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:26.996Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'text text'
[task 2020-10-09T12:03:26.996Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 0 - 6
[task 2020-10-09T12:03:26.996Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 0 - 6
[task 2020-10-09T12:03:26.996Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.28162167164242924"...
[task 2020-10-09T12:03:26.997Z] 12:03:26 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:26.997Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.28162167164242924
[task 2020-10-09T12:03:26.997Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 0 - 8
[task 2020-10-09T12:03:26.997Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 0 - 8
[task 2020-10-09T12:03:26.997Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.12453862320072095"...
[task 2020-10-09T12:03:26.998Z] 12:03:26 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:26.998Z] 12:03:26 INFO - Buffered messages logged at 12:03:17
[task 2020-10-09T12:03:26.998Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.12453862320072095
[task 2020-10-09T12:03:26.998Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 0 - 10
[task 2020-10-09T12:03:26.998Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 0 - 10
[task 2020-10-09T12:03:26.999Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.5244679481055872"...
[task 2020-10-09T12:03:26.999Z] 12:03:26 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:26.999Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'textarea text'
[task 2020-10-09T12:03:26.999Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 0 - 12
[task 2020-10-09T12:03:26.999Z] 12:03:26 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 0 - 12
[task 2020-10-09T12:03:27.000Z] 12:03:26 INFO - Initializing clipboard with "waitForClipboard-known-value-0.7165644368995802"...
[task 2020-10-09T12:03:27.000Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.000Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'textarea text'
[task 2020-10-09T12:03:27.000Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 0 - 14
[task 2020-10-09T12:03:27.000Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 0 - 14
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.2181163892737623"...
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.2181163892737623
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 0 - 15
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 0 - 15
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.8817212973972693"...
[task 2020-10-09T12:03:27.001Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - Buffered messages logged at 12:03:18
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.8817212973972693
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 0 - 16
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 0 - 16
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.5633916543578131"...
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'contenteditable text'
[task 2020-10-09T12:03:27.002Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 0 - 18
[task 2020-10-09T12:03:27.003Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 0 - 18
[task 2020-10-09T12:03:27.003Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.22997946778426048"...
[task 2020-10-09T12:03:27.003Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.009Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'contenteditable text'
[task 2020-10-09T12:03:27.009Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 0 - 20
[task 2020-10-09T12:03:27.009Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 0 - 20
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.4857987374816608"...
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused copy invocation 0 - 1 - 0
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'span text'
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 1 - 1
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 1 - 1
[task 2020-10-09T12:03:27.010Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.6891436799085089"...
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused cut invocation 0 - 1 - 1
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.6891436799085089
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 1 - 2
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 1 - 2
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.2860865474841524"...
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.011Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused copy invocation 0 - 1 - 3
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'text text'
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 1 - 4
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 1 - 4
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.48498595253873766"...
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused cut invocation 0 - 1 - 5
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'text text'
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 1 - 6
[task 2020-10-09T12:03:27.012Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 1 - 6
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.34138331216054274"...
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused copy invocation 0 - 1 - 7
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - Buffered messages logged at 12:03:19
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.34138331216054274
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 1 - 8
[task 2020-10-09T12:03:27.013Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 1 - 8
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.8825023036191956"...
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused cut invocation 0 - 1 - 9
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.8825023036191956
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback to run 0 - 1 - 10
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback not to run 0 - 1 - 10
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.7620710883159206"...
[task 2020-10-09T12:03:27.014Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.015Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused copy invocation 0 - 1 - 11
[task 2020-10-09T12:03:27.015Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Clipboard has the given value: 'textarea text'
[task 2020-10-09T12:03:27.015Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect cut callback not to run 0 - 1 - 12
[task 2020-10-09T12:03:27.015Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Expect copy callback to run 0 - 1 - 12
[task 2020-10-09T12:03:27.015Z] 12:03:27 INFO - Initializing clipboard with "waitForClipboard-known-value-0.5170680238228297"...
[task 2020-10-09T12:03:27.025Z] 12:03:27 INFO - Succeeded initializing clipboard, start requested things...
[task 2020-10-09T12:03:27.025Z] 12:03:27 INFO - TEST-PASS | dom/base/test/useractivation/test_clipboard_editor.html | Keydown caused cut invocation 0 - 1 - 13
[task 2020-10-09T12:03:27.025Z] 12:03:27 INFO - Buffered messages finished
[task 2020-10-09T12:03:27.025Z] 12:03:27 INFO - TEST-UNEXPECTED-FAIL | dom/base/test/useractivation/test_clipboard_editor.html | Timed out while polling clipboard for requested data, got: waitForClipboard-known-value-0.5170680238228297 ```
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 17•4 years ago
|
||
There have been 69 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-01-01&endday=2021-01-08&tree=trunk&bug=1670233
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=326154124&repo=autoland&lineNumber=2351
Jens, could you assign this to someone?
Assignee | ||
Comment 18•4 years ago
|
||
Updated•4 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•4 years ago
|
Updated•4 years ago
|
Comment 20•4 years ago
|
||
Updated•4 years ago
|
Comment 21•4 years ago
|
||
Backed out changeset ed88b1f03a11 (Bug 1670233) for causing test_clipboard_noeditor.html to fail instead.
Backout link: https://hg.mozilla.org/integration/autoland/rev/1c24b564e9ebca0a1de676bedce8914efccbbbe1
Failure log: https://treeherder.mozilla.org/logviewer?job_id=326376803&repo=autoland&lineNumber=2365
Disabling test_clipboard_editor.html caused test_clipboard_noeditor.html to fail in its place, meaning that there is an underlying reason that causes these tests to fail, so no point in disabling.
Comment 22•4 years ago
|
||
Comment 23•4 years ago
|
||
Backout merged to central: https://hg.mozilla.org/mozilla-central/rev/c6d819bd39daf86acd5e0c5bce5d74c2db8b8d64
These frequent fails (almost perma) are from Bug 1676966 - https://hg.mozilla.org/integration/autoland/rev/02d875d4f7d769cd03be3175490377dc600355fe
TH link: https://treeherder.mozilla.org/jobs?repo=autoland&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&searchStr=windows%2C7%2Copt%2Cmochitests%2Ctest-windows7-32%2Fopt-mochitest-plain-e10s%2C5&tochange=02d875d4f7d769cd03be3175490377dc600355fe&fromchange=f38b3c4372aa9ab9650fcf4b94bf863f9bc44999&group_state=expanded&selectedTaskRun=FPDVwFKfTxOmz_QT7_ff0Q.0
Jonathan, please have a look over these. Thank you.
Updated•4 years ago
|
Comment 24•4 years ago
|
||
I expect an extra reflow triggered by async font fallback is upsetting the tests. We can just disable it for this test directory.
Comment 25•4 years ago
|
||
Comment 26•4 years ago
|
||
Comment 27•4 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Comment 29•4 years ago
|
||
(In reply to Jonathan Kew (:jfkthame) from comment #24)
I expect an extra reflow triggered by async font fallback is upsetting the tests. We can just disable it for this test directory.
Is this a correct fix or just a mute for those failures?
Comment 30•4 years ago
|
||
It's a reasonable workaround, if the test is sensitive to an unpredictable extra reflow happening during the run. See https://groups.google.com/g/mozilla.dev.platform/c/VBh6oLm4EbQ for background.
Ideally, I guess tests would be immune to this, but in practice for tests that are interacting with events, selection, etc., it may be impractical to be entirely robust against this. The pref change simply ensures that any font fallback search required will complete synchronously (as has historically been the case) so that it will not result in triggering reflow at an indeterminate future time, which is what's tripping up some testcases.
Description
•