Closed Bug 1589844 Opened 10 months ago Closed 10 months ago

Perma [tier 2] remote/test/browser/browser_input_dispatchKeyEvent.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. -

Categories

(Remote Protocol :: Agent, defect, P5)

defect

Tracking

(firefox71 disabled, firefox72 fixed)

RESOLVED FIXED
Tracking Status
firefox71 --- disabled
firefox72 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=272025737&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/N34xvhJpRKiq3Kjalf3ZsQ/runs/0/artifacts/public/logs/live_backing.log


[task 2019-10-19T11:34:56.044Z] 11:34:56 INFO - TEST-START | remote/test/browser/browser_input_dispatchKeyEvent.js
[task 2019-10-19T11:34:56.103Z] 11:34:56 INFO - GECKO(2992) | DLL blocklist was unable to intercept AppInit DLLs.
[task 2019-10-19T11:34:56.122Z] 11:34:56 INFO - GECKO(2992) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1571483897\appdata\local\temp\tmpcczlsv.mozrunner\runtests_leaks_tab_pid4500.log
[task 2019-10-19T11:34:56.140Z] 11:34:56 INFO - GECKO(2992) | [Child 4500, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 732
[task 2019-10-19T11:34:56.341Z] 11:34:56 INFO - GECKO(2992) | --DOCSHELL 00000276CC3AC800 == 5 [pid = 4728] [id = {8a25a40a-8abe-4855-913f-b3e8fc19cf37}] [url = about:blank]
[task 2019-10-19T11:34:56.481Z] 11:34:56 INFO - GECKO(2992) | ++DOCSHELL 000002917CE7F800 == 1 [pid = 4500] [id = {36c0b550-e637-4548-9bc9-ba217934a18a}]
[task 2019-10-19T11:34:56.481Z] 11:34:56 INFO - GECKO(2992) | ++DOMWINDOW == 1 (0000029104203200) [pid = 4500] [serial = 1] [outer = 0000000000000000]
[task 2019-10-19T11:34:56.481Z] 11:34:56 INFO - GECKO(2992) | ++DOMWINDOW == 2 (0000029104298400) [pid = 4500] [serial = 2] [outer = 0000029104203200]
[task 2019-10-19T11:34:56.672Z] 11:34:56 INFO - GECKO(2992) | ++DOMWINDOW == 3 (000002910428CC00) [pid = 4500] [serial = 3] [outer = 0000029104203200]
[task 2019-10-19T11:34:56.682Z] 11:34:56 INFO - GECKO(2992) | [Child 4500, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/dom/base/ThirdPartyUtil.cpp, line 217
[task 2019-10-19T11:34:56.704Z] 11:34:56 INFO - GECKO(2992) | [Child 4500, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/dom/base/ThirdPartyUtil.cpp, line 217
[task 2019-10-19T11:34:56.735Z] 11:34:56 INFO - GECKO(2992) | [Child 4500, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1388
[task 2019-10-19T11:34:56.735Z] 11:34:56 INFO - GECKO(2992) | [Child 4500, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1388
[task 2019-10-19T11:34:57.407Z] 11:34:57 INFO - GECKO(2992) | DevTools listening on ws://localhost:9222/devtools/browser/ac2d0e45-f279-408e-aa50-6ba8d63d1900
[task 2019-10-19T11:34:57.407Z] 11:34:57 INFO - GECKO(2992) | ++DOCSHELL 00000276C6C3A000 == 6 [pid = 4728] [id = {a92a4f6d-9341-4532-8980-d3d3c54e2ed4}]
[task 2019-10-19T11:34:57.407Z] 11:34:57 INFO - GECKO(2992) | ++DOMWINDOW == 16 (00000276CE355C40) [pid = 4728] [serial = 18] [outer = 0000000000000000]
[task 2019-10-19T11:34:57.407Z] 11:34:57 INFO - GECKO(2992) | ++DOMWINDOW == 17 (00000276C5955C00) [pid = 4728] [serial = 19] [outer = 00000276CE355C40]
[task 2019-10-19T11:34:57.425Z] 11:34:57 INFO - GECKO(2992) | ++DOMWINDOW == 18 (00000276C5957C00) [pid = 4728] [serial = 20] [outer = 00000276CE355C40]
[task 2019-10-19T11:34:57.475Z] 11:34:57 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-10-19T11:34:57.554Z] 11:34:57 INFO - GECKO(2992) | DLL blocklist was unable to intercept AppInit DLLs.
[task 2019-10-19T11:34:57.573Z] 11:34:57 INFO - GECKO(2992) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1571483897\appdata\local\temp\tmpcczlsv.mozrunner\runtests_leaks_tab_pid6264.log
[task 2019-10-19T11:34:57.591Z] 11:34:57 INFO - GECKO(2992) | [Child 6264, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 732
[task 2019-10-19T11:34:57.978Z] 11:34:57 INFO - GECKO(2992) | --DOMWINDOW == 3 (0000020EA559D000) [pid = 4004] [serial = 2] [outer = 0000000000000000] [url = about:blank]
[task 2019-10-19T11:34:58.130Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 42
[task 2019-10-19T11:34:58.130Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: '!principal', file z:/build/build/src/netwerk/cookie/CookieSettings.cpp, line 132
[task 2019-10-19T11:34:58.130Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/toolkit/components/antitracking/StorageAccess.cpp, line 33
[task 2019-10-19T11:34:58.130Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 42
[task 2019-10-19T11:34:58.130Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: '!principal', file z:/build/build/src/netwerk/cookie/CookieSettings.cpp, line 132
[task 2019-10-19T11:34:58.130Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/toolkit/components/antitracking/StorageAccess.cpp, line 33
[task 2019-10-19T11:34:58.189Z] 11:34:58 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-10-19T11:34:59.124Z] 11:34:59 INFO - GECKO(2992) | [Parent 4728, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-10-19T11:34:59.495Z] 11:34:59 INFO - GECKO(2992) | --DOMWINDOW == 17 (00000276CE592400) [pid = 4728] [serial = 16] [outer = 0000000000000000] [url = about:blank]
[task 2019-10-19T11:35:02.084Z] 11:35:02 INFO - GECKO(2992) | --DOMWINDOW == 2 (0000020EA5591C00) [pid = 4004] [serial = 3] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page]
[task 2019-10-19T11:35:02.084Z] 11:35:02 INFO - GECKO(2992) | --DOCSHELL 0000020EA127F800 == 0 [pid = 4004] [id = {86a9826a-9408-4151-8a6f-12163b2f0a64}] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cscript%3Econsole.log(%22foo%22)%3C%2Fscript%3E]
[task 2019-10-19T11:35:02.151Z] 11:35:02 INFO - GECKO(2992) | --DOMWINDOW == 1 (0000020EA5506200) [pid = 4004] [serial = 1] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cscript%3Econsole.log(%22foo%22)%3C%2Fscript%3E]
[task 2019-10-19T11:35:03.085Z] 11:35:03 INFO - GECKO(2992) | [Child 4500, Main Thread] WARNING: SendNotifyIMEFocus got rejected.: file z:/build/build/src/widget/PuppetWidget.cpp, line 788
[task 2019-10-19T11:35:03.166Z] 11:35:03 INFO - GECKO(2992) | 1571484903158 RemoteAgent INFO Stopped listening
<...>
[task 2019-10-19T11:36:37.232Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | The client is closed -
[task 2019-10-19T11:36:37.232Z] 11:36:37 INFO - Buffered messages logged at 11:36:26
[task 2019-10-19T11:36:37.233Z] 11:36:37 INFO - Leaving test bound
[task 2019-10-19T11:36:37.233Z] 11:36:37 INFO - Entering test bound
[task 2019-10-19T11:36:37.233Z] 11:36:37 INFO - Buffered messages logged at 11:36:27
[task 2019-10-19T11:36:37.233Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | Selected tab is the target tab -
[task 2019-10-19T11:36:37.233Z] 11:36:37 INFO - Buffered messages logged at 11:36:33
[task 2019-10-19T11:36:37.233Z] 11:36:37 INFO - CDP client instantiated
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - Buffered messages logged at 11:36:35
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | List of events should be empty - 0 == 0 -
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - Send rawKeyDown for key Shift
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - Click the 'pointers' div.
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - Send keyUp for key Shift
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - Events: [{"type":"mousedown","button":0,"buttons":1,"pageX":80,"pageY":180,"ctrlKey":false,"metaKey":false,"altKey":false,"shiftKey":true,"target":"pointers"},{"type":"mouseup","button":0,"buttons":0,"pageX":80,"pageY":180,"ctrlKey":false,"metaKey":false,"altKey":false,"shiftKey":true,"target":"pointers"},{"type":"click","button":0,"buttons":0,"pageX":80,"pageY":180,"ctrlKey":false,"metaKey":false,"altKey":false,"shiftKey":true,"target":"pointers"}]
[task 2019-10-19T11:36:37.234Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | Compare objects: check type -
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | Compare objects: check shiftKey -
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | Compare objects: check button -
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - TEST-PASS | remote/test/browser/browser_input_dispatchKeyEvent.js | The client is closed -
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - Buffered messages logged at 11:36:37
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - Leaving test bound
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - Buffered messages finished
[task 2019-10-19T11:36:37.235Z] 11:36:37 INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/browser_input_dispatchKeyEvent.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 2019-10-19T11:36:37.235Z] 11:36:37 INFO - GECKO(2992) | MEMORY STAT | vsize 2104644MB | vsizeMaxContiguous 65748349MB | residentFast 465MB | heapAllocated 154MB
[task 2019-10-19T11:36:37.236Z] 11:36:37 INFO - TEST-OK | remote/test/browser/browser_input_dispatchKeyEvent.js | took 101098ms

Maja,
this looks to be caused by Bug 1563206, could you please take a look at it?

Flags: needinfo?(mjzffr)
Regressed by: 1563206

This also fixes the intermittent timeout on Windows debug by
moving the event checks to a separate test.

Attachment #9103104 - Attachment description: Bug 1589844 - Move Input browser-chrome tests to their down directory; r=#remote! → Bug 1589844 - Move Input browser-chrome tests to their own directory; r=#remote!
Pushed by mjzffr@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/79a88a2631b2
Move Input browser-chrome tests to their own directory; r=remote-protocol-reviewers,whimboo,ato
Status: NEW → RESOLVED
Closed: 10 months ago
Resolution: --- → FIXED
Assignee: nobody → mjzffr
You need to log in before you can comment on or make changes to this bug.