Closed Bug 1512049 Opened 6 years ago Closed 6 years ago

Intermittent TEST-UNEXPECTED-PASS | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | scheduler: javascript: URL in HREF - expected FAIL

Categories

(Core :: DOM: Core & HTML, defect, P2)

defect

Tracking

()

RESOLVED FIXED
mozilla67
Tracking Status
firefox67 --- fixed

People

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

Details

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

Attachments

(1 file)

Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=215428718&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/ZZoFHrOMQhK60NJsXq-9QQ/runs/0/artifacts/public/logs/live_backing.log [task 2018-12-04T17:12:56.495Z] 17:12:56 INFO - TEST-START | /html/semantics/scripting-1/the-script-element/execution-timing/029.html [task 2018-12-04T17:12:56.511Z] 17:12:56 INFO - Closing window 4294967385 [task 2018-12-04T17:12:56.632Z] 17:12:56 INFO - PID 8151 | ++DOCSHELL 0x7fc0d9eda800 == 10 [pid = 8248] [id = {8e2bb9cf-df46-46b1-9cb9-85fd16ec122e}] [task 2018-12-04T17:12:56.633Z] 17:12:56 INFO - PID 8151 | ++DOMWINDOW == 38 (0x7fc0d9811400) [pid = 8248] [serial = 92] [outer = (nil)] [task 2018-12-04T17:12:56.669Z] 17:12:56 INFO - PID 8151 | ++DOMWINDOW == 39 (0x7fc0d9e94800) [pid = 8248] [serial = 93] [outer = 0x7fc0d9811400] [task 2018-12-04T17:12:56.670Z] 17:12:56 INFO - PID 8151 | [Child 8248, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/base/nsContentUtils.cpp, line 8165 [task 2018-12-04T17:12:56.759Z] 17:12:56 INFO - PID 8151 | ++DOMWINDOW == 40 (0x7fc0dcea0400) [pid = 8248] [serial = 94] [outer = 0x7fc0d9811400] [task 2018-12-04T17:12:56.775Z] 17:12:56 INFO - PID 8151 | [Child 8248, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/base/nsContentUtils.cpp, line 8165 [task 2018-12-04T17:12:57.127Z] 17:12:57 INFO - [task 2018-12-04T17:12:57.128Z] 17:12:57 INFO - TEST-UNEXPECTED-PASS | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | scheduler: javascript: URL in HREF - expected FAIL [task 2018-12-04T17:12:57.128Z] 17:12:57 INFO - TEST-INFO | expected FAIL [task 2018-12-04T17:12:57.129Z] 17:12:57 INFO - TEST-OK | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | took 633ms [task 2018-12-04T17:12:57.166Z] 17:12:57 INFO - PID 8151 | 1543943577161 Marionette INFO Stopped listening on port 2828 [task 2018-12-04T17:12:57.429Z] 17:12:57 INFO - PID 8151 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost [task 2018-12-04T17:12:57.430Z] 17:12:57 INFO - PID 8151 | [Child 8226, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp, line 870 [task 2018-12-04T17:12:57.439Z] 17:12:57 INFO - PID 8151 | [Child 8248, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp, line 870 [task 2018-12-04T17:12:57.439Z] 17:12:57 INFO - PID 8151 | [Child 8226, Main Thread] WARNING: '!gThread', file /builds/worker/workspace/build/src/xpcom/threads/nsTimerImpl.cpp, line 299 [task 2018-12-04T17:12:57.441Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 39 (0x7fc0d9e9cc00) [pid = 8248] [serial = 52] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.441Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 38 (0x7fc0d9802c00) [pid = 8248] [serial = 61] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.442Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 37 (0x7fc0dce98800) [pid = 8248] [serial = 60] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.442Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 36 (0x7fc0dce97800) [pid = 8248] [serial = 58] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.442Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 35 (0x7fc0d980f400) [pid = 8248] [serial = 57] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.443Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 34 (0x7fc0d980fc00) [pid = 8248] [serial = 64] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.443Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 33 (0x7fc0d980dc00) [pid = 8248] [serial = 63] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.446Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 32 (0x7fc0d9802800) [pid = 8248] [serial = 55] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.446Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 31 (0x7fc0d9e91c00) [pid = 8248] [serial = 54] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.446Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 30 (0x7fc0d9e9e400) [pid = 8248] [serial = 67] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.446Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 29 (0x7fc0d980c800) [pid = 8248] [serial = 66] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.447Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 28 (0x7fc0d9806000) [pid = 8248] [serial = 69] [outer = (nil)] [url = about:blank] [task 2018-12-04T17:12:57.688Z] 17:12:57 INFO - PID 8151 | --DOCSHELL 0x7ffbc3a33800 == 2 [pid = 8226] [id = {b1044239-05a2-4f5a-b803-8fd9b27b3658}] [task 2018-12-04T17:12:57.688Z] 17:12:57 INFO - PID 8151 | --DOMWINDOW == 5 (0x7ffbc3bef000) [pid = 8226] [serial = 3] [outer = (nil)] [url = moz-extension://1644c718-1039-4539-9a89-0996d51694d9/_generated_background_page.html]
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=221323475&repo=try&lineNumber=4320

[task 2019-01-11T14:09:09.681Z] 14:09:09 INFO - TEST-START | /html/semantics/scripting-1/the-script-element/execution-timing/029.html
[task 2019-01-11T14:09:09.687Z] 14:09:09 INFO - Closing window 4294967388
[task 2019-01-11T14:09:09.817Z] 14:09:09 INFO -
[task 2019-01-11T14:09:09.818Z] 14:09:09 INFO - TEST-UNEXPECTED-PASS | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | scheduler: javascript: URL in HREF - expected FAIL
[task 2019-01-11T14:09:09.818Z] 14:09:09 INFO - TEST-INFO | expected FAIL
[task 2019-01-11T14:09:09.818Z] 14:09:09 INFO - TEST-OK | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | took 136ms
[task 2019-01-11T14:09:09.838Z] 14:09:09 INFO - PID 13247 | 1547215749830 Marionette INFO Stopped listening on port 2828
[task 2019-01-11T14:09:09.936Z] 14:09:09 INFO - PID 13247 | [Parent 13247, Gecko_IOThread] WARNING: pipe error (107): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 359
[task 2019-01-11T14:09:10.033Z] 14:09:10 INFO - PID 13247 | JavaScript error: resource:///modules/AsyncTabSwitcher.jsm, line 255: TypeError: browser.frameLoader is null
[task 2019-01-11T14:09:10.332Z] 14:09:10 INFO - Browser exited with return code 0
[task 2019-01-11T14:09:10.334Z] 14:09:10 INFO - PROCESS LEAKS None
[task 2019-01-11T14:09:10.335Z] 14:09:10 INFO - Closing logging queue
[task 2019-01-11T14:09:10.335Z] 14:09:10 INFO - queue closed
[task 2019-01-11T14:09:10.355Z] 14:09:10 INFO - Setting up ssl
[task 2019-01-11T14:09:10.392Z] 14:09:10 INFO - certutil |
[task 2019-01-11T14:09:10.416Z] 14:09:10 INFO - certutil |
[task 2019-01-11T14:09:10.437Z] 14:09:10 INFO - certutil |
[task 2019-01-11T14:09:10.437Z] 14:09:10 INFO - Certificate Nickname Trust Attributes
[task 2019-01-11T14:09:10.437Z] 14:09:10 INFO - SSL,S/MIME,JAR/XPI
[task 2019-01-11T14:09:10.437Z] 14:09:10 INFO -
[task 2019-01-11T14:09:10.438Z] 14:09:10 INFO - web-platform-tests CT,,
[task 2019-01-11T14:09:10.439Z] 14:09:10 INFO -
[task 2019-01-11T14:09:10.455Z] 14:09:10 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpQZz_sp.mozrunner
[task 2019-01-11T14:09:10.472Z] 14:09:10 INFO - Starting runner
[task 2019-01-11T14:09:10.936Z] 14:09:10 INFO - PID 13615 | 1547215750929 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/
[task 2019-01-11T14:09:10.937Z] 14:09:10 INFO - PID 13615 | 1547215750930 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader*
[task 2019-01-11T14:09:13.622Z] 14:09:13 INFO - PID 13615 | 1547215753609 Marionette INFO Listening on port 2828

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

There are 16 total failures in the last 7 days and 67 in the last 30 days, on windows debug.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=229870217&repo=mozilla-central&lineNumber=59831

11:16:48 INFO - TEST-START | /html/semantics/scripting-1/the-script-element/execution-timing/029.html
11:16:48 INFO - Closing window 68719476737
11:16:48 INFO - PID 2924 | [Parent 4740, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [Child 10056, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [Parent 4740, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [GPU 1264, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [GPU 1264, Chrome_ChildThread] WARNING: pipe error: 109: file
11:16:48 INFO - PID 2924 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
11:16:48 INFO - PID 2924 | z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [GPU 1264, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [GPU 1264, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [Parent 4740, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [Parent 4740, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | [Parent 4740, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
11:16:48 INFO - PID 2924 | ++DOCSHELL 000002B73FB78800 == 1 [pid = 7048] [id = {2ab393a4-7c03-4181-b606-bc29b33e0e19}]
11:16:48 INFO - PID 2924 | ++DOMWINDOW == 1 (000002B743D93400) [pid = 7048] [serial = 1] [outer = 0000000000000000]
11:16:49 INFO - PID 2924 | ++DOMWINDOW == 2 (000002B743D94C00) [pid = 7048] [serial = 2] [outer = 000002B743D93400]
11:16:49 INFO - PID 2924 | DLL blocklist was unable to intercept AppInit DLLs.
11:16:49 INFO - PID 2924 | --DOMWINDOW == 2 (000002708C4A0000) [pid = 10056] [serial = 3] [outer = 0000000000000000] [url = http://web-platform.test:8000/html/semantics/scripting-1/the-script-element/execution-timing/028.html]
11:16:49 INFO - PID 2924 | --DOCSHELL 0000027086478800 == 0 [pid = 10056] [id = {a391579d-c2d0-4476-bcbd-aabdeb9c7da3}]
11:16:49 INFO - PID 2924 | --DOMWINDOW == 1 (000002708A58E800) [pid = 10056] [serial = 1] [outer = 0000000000000000] [url = http://web-platform.test:8000/html/semantics/scripting-1/the-script-element/execution-timing/028.html]
11:16:49 INFO - PID 2924 | --DOMWINDOW == 0 (000002708A590000) [pid = 10056] [serial = 2] [outer = 0000000000000000] [url = about:blank]
11:16:49 INFO - PID 2924 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1550829085\appdata\local\temp\tmpmkiqjg.mozrunner\runtests_leaks_3212_tab_pid8280.log
11:16:49 INFO - PID 2924 | nsStringStats
11:16:49 INFO - PID 2924 | => mAllocCount: 7121
11:16:49 INFO - PID 2924 | => mReallocCount: 0
11:16:49 INFO - PID 2924 | => mFreeCount: 7121
11:16:49 INFO - PID 2924 | => mShareCount: 5637
11:16:49 INFO - PID 2924 | => mAdoptCount: 441
11:16:49 INFO - PID 2924 | => mAdoptFreeCount: 447
11:16:49 INFO - PID 2924 | => Process ID: 10056, Thread ID: 6840
11:16:49 INFO - PID 2924 | [Child 7048, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file z:/build/build/src/xpcom/base/nsSystemInfo.cpp, line 111
11:16:49 INFO - PID 2924 | [Child 7048, Main Thread] WARNING: site security information will not be persisted: file z:/build/build/src/security/manager/ssl/nsSiteSecurityService.cpp, line 506
11:16:49 INFO - PID 2924 | [Parent 4740, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/netwerk/url-classifier/UrlClassifierCommon.cpp, line 122
11:16:49 INFO - PID 2924 | ++DOMWINDOW == 3 (000002B745C9E800) [pid = 7048] [serial = 3] [outer = 000002B743D93400]
11:16:50 INFO -
11:16:50 INFO - TEST-UNEXPECTED-PASS | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | scheduler: javascript: URL in HREF - expected FAIL
11:16:50 INFO - TEST-INFO | expected FAIL
11:16:50 INFO - TEST-OK | /html/semantics/scripting-1/the-script-element/execution-timing/029.html | took 2191ms

Whiteboard: [stockwell needswork:owner]

Hsin-Yi can you assign someone here?

Flags: needinfo?(htsai)

John will be helping us investigate first, thanks John.

Assignee: nobody → jdai
Flags: needinfo?(htsai)
Priority: -- → P2

I always got scheduler: javascript: URL in HREF errors from local machines which are windows, linux and mac platforms.

assert_array_equals: lengths differ, expected 4 got 3 assert_array_equals: lengths differ, expected 4 got 3

test@http://web-platform.test:8000/html/semantics/scripting-1/the-script-element/execution-timing/029.html:29:17
Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1587:25
Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:1611:35
EventHandlerNonNull*@http://web-platform.test:8000/html/semantics/scripting-1/the-script-element/execution-timing/029.html:34:20

Per offline discussion with Olli, this test may have racy, loading <a> element is asynchronous, and load event may fire before that.

In addition, we have different event order than other browsers. Test on Chromium, Safari and Edge, their event order are [inline script #1, JS URL, end script #1, inline script #2]. Firefox event order is [inline script #1, end script #1, inline script #2, JS URL].

Since this test is buggy because it has a race condition which mentioned in comment 16. Currently, we can either fix the test or disable the test. According to comment 17, there is a spec issue need to clarify, it's nice to move out of sheriff radar. After discussing with Hsin-Yi, I'm going to disable this test.

Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: