Closed
Bug 1580976
Opened 5 years ago
Closed 5 years ago
Intermittent netwerk/test/unit/test_trr.js | test1 - [test1 : 125] "127.0.0.1" == "2.2.2.2"
Categories
(Core :: Networking, defect, P5)
Core
Networking
Tracking
()
RESOLVED
FIXED
mozilla71
| Tracking | Status | |
|---|---|---|
| firefox-esr60 | --- | unaffected |
| firefox-esr68 | --- | unaffected |
| firefox67 | --- | unaffected |
| firefox68 | --- | unaffected |
| firefox69 | --- | unaffected |
| firefox70 | --- | unaffected |
| firefox71 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: valentin)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [necko-triaged])
Attachments
(1 file)
|
(deleted),
text/x-phabricator-request
|
Details |
Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=266399457&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/bJQ1DN22SSyulnHybuGbhw/runs/0/artifacts/public/logs/live_backing.log
INFO - TEST-START | netwerk/test/unit/test_trr.js
[task 2019-09-12T21:01:54.785Z] 21:01:54 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_trr.js | xpcshell return code: 0
[task 2019-09-12T21:01:54.785Z] 21:01:54 INFO - TEST-INFO took 2293ms
[task 2019-09-12T21:01:54.786Z] 21:01:54 INFO - >>>>>>>
[task 2019-09-12T21:01:54.786Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2632
[task 2019-09-12T21:01:54.787Z] 21:01:54 INFO - PID 13318 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-12T21:01:54.787Z] 21:01:54 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-09-12T21:01:54.790Z] 21:01:54 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-09-12T21:01:54.790Z] 21:01:54 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-09-12T21:01:54.791Z] 21:01:54 INFO - running event loop
[task 2019-09-12T21:01:54.791Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/workspace/build/src/dom/media/CubebUtils.cpp, line 384
[task 2019-09-12T21:01:54.792Z] 21:01:54 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2019-09-12T21:01:54.792Z] 21:01:54 INFO - netwerk/test/unit/test_trr.js | Starting setup
[task 2019-09-12T21:01:54.793Z] 21:01:54 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2019-09-12T21:01:54.793Z] 21:01:54 INFO - PID 13318 | start!
[task 2019-09-12T21:01:54.794Z] 21:01:54 INFO - TEST-PASS | netwerk/test/unit/test_trr.js | setup - [setup : 34] "45279" != null
[task 2019-09-12T21:01:54.795Z] 21:01:54 INFO - TEST-PASS | netwerk/test/unit/test_trr.js | setup - [setup : 35] "45279" != ""
[task 2019-09-12T21:01:54.795Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /builds/worker/workspace/build/src/extensions/permissions/nsPermissionManager.cpp, line 2883
[task 2019-09-12T21:01:54.796Z] 21:01:54 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2019-09-12T21:01:54.796Z] 21:01:54 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2019-09-12T21:01:54.797Z] 21:01:54 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2019-09-12T21:01:54.797Z] 21:01:54 INFO - netwerk/test/unit/test_trr.js | Starting test1
[task 2019-09-12T21:01:54.798Z] 21:01:54 INFO - (xpcshell/head.js) | test test1 pending (2)
[task 2019-09-12T21:01:54.798Z] 21:01:54 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2019-09-12T21:01:54.799Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002: file /builds/worker/workspace/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 661
[task 2019-09-12T21:01:54.799Z] 21:01:54 INFO - TEST-PASS | netwerk/test/unit/test_trr.js | test1 - [test1 : 114] true == true
[task 2019-09-12T21:01:54.800Z] 21:01:54 INFO - TEST-PASS | netwerk/test/unit/test_trr.js | test1 - [test1 : 123] 0 == 0
[task 2019-09-12T21:01:54.802Z] 21:01:54 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_trr.js | test1 - [test1 : 125] "127.0.0.1" == "2.2.2.2"
[task 2019-09-12T21:01:54.802Z] 21:01:54 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_trr.js:onLookupComplete:125
[task 2019-09-12T21:01:54.802Z] 21:01:54 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:246
[task 2019-09-12T21:01:54.802Z] 21:01:54 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:573
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - -e:null:1
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - exiting test
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | JavaScript error: /builds/worker/workspace/build/tests/xpcshell/head.js, line 789: NS_ERROR_ABORT:
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "NS_ERROR_ABORT: " {file: "/builds/worker/workspace/build/tests/xpcshell/head.js" line: 789}]"
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: OOPDeinit() without successful OOPInit(): file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 3114
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | [13318, Main Thread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | nsStringStats
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => mAllocCount: 10811
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => mReallocCount: 0
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => mFreeCount: 10811
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => mShareCount: 8337
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => mAdoptCount: 216
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => mAdoptFreeCount: 216
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - PID 13318 | => Process ID: 13318, Thread ID: 140350973846656
[task 2019-09-12T21:01:54.803Z] 21:01:54 INFO - <<<<<<<
[task 2019-09-12T21:01:54.806Z] 21:01:54 INFO - TEST-START | netwerk/test/unit/test_esni_dns_fetch.js
[task 2019-09-12T21:01:57.092Z] 21:01:57 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_esni_dns_fetch.js | xpcshell return code: 0
[task 2019-09-12T21:01:57.093Z] 21:01:57 INFO - TEST-INFO took 2280ms
[task 2019-09-12T21:01:57.093Z] 21:01:57 INFO - >>>>>>>
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2632
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - PID 13340 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - TEST-PASS | netwerk/test/unit/test_esni_dns_fetch.js | run_test - [run_test : 20] "45279" != null
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - TEST-PASS | netwerk/test/unit/test_esni_dns_fetch.js | run_test - [run_test : 21] "45279" != ""
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /builds/worker/workspace/build/src/extensions/permissions/nsPermissionManager.cpp, line 2883
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - (xpcshell/head.js) | test pending (2)
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - PID 13340 | starting test 0
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - (xpcshell/head.js) | test pending (3)
[task 2019-09-12T21:01:57.094Z] 21:01:57 INFO - (xpcshell/head.js) | test MAIN run_test finished (3)
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - running event loop
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/workspace/build/src/dom/media/CubebUtils.cpp, line 384
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002: file /builds/worker/workspace/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 661
[task 2019-09-12T21:01:57.095Z] 21:01:57 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_esni_dns_fetch.js | onLookupByTypeComplete - [onLookupByTypeComplete : 77] false == true
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_esni_dns_fetch.js:onLookupByTypeComplete:77
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:246
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:573
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - -e:null:1
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - exiting test
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - PID 13340 | JavaScript error: /builds/worker/workspace/build/tests/xpcshell/head.js, line 789: NS_ERROR_ABORT:
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "NS_ERROR_ABORT: " {file: "/builds/worker/workspace/build/tests/xpcshell/head.js" line: 789}]"
[task 2019-09-12T21:01:57.095Z] 21:01:57 INFO - PID 13340 | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: OOPDeinit() without successful OOPInit(): file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 3114
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | [13340, Main Thread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | nsStringStats
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => mAllocCount: 10650
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => mReallocCount: 0
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => mFreeCount: 10650
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => mShareCount: 8185
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => mAdoptCount: 191
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => mAdoptFreeCount: 191
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - PID 13340 | => Process ID: 13340, Thread ID: 140477192799360
[task 2019-09-12T21:01:57.096Z] 21:01:57 INFO - <<<<<<<
[task 2019-09-12T21:01:57.103Z] 21:01:57 INFO - TEST-START | security/manager/ssl/tests/unit/test_intermediate_preloads.js
|
||
Comment 1•5 years ago
|
||
This bug most likely started when Bug 1580046 landed here:
https://hg.mozilla.org/integration/autoland/rev/43746856fea27941131e6bd9c5a770058ef74d33
Regressed by: 1580046
|
||
Comment 2•5 years ago
|
||
I think this might be related to node update.
From the log, the moz-http2 server is already dead before shutting it down.
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - Node moz-http2 server shutting down ...
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - Node server moz-http2 already dead -6
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - Process stderr
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - (node:1086) ExperimentalWarning: The http2 module is an experimental API.
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - (node:1086) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - (node:1086) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - (node:1086) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - (node:1086) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - /usr/local/bin/node[1086]: ../src/tls_wrap.cc:604:virtual int node::TLSWrap::DoWrite(node::WriteWrap*, uv_buf_t*, size_t, uv_stream_t*): Assertion `(ssl_) != (nullptr)' failed.
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 1: node::Abort() [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 2: 0x8c25db [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 3: node::TLSWrap::DoWrite(node::WriteWrap*, uv_buf_t*, unsigned long, uv_stream_s*) [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 4: node::http2::Http2Session::SendPendingData() [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 5: node::http2::Http2Stream::RstStream(v8::FunctionCallbackInfo<v8::Value> const&) [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 6: v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 7: 0xad710c [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 8: v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) [/usr/local/bin/node]
[task 2019-09-12T21:02:04.840Z] 21:02:04 INFO - 9: 0x7455a3842fd
Junior, could you take a look?
Flags: needinfo?(juhsu)
|
||
Comment 3•5 years ago
|
||
Looks like it's a known issue of v8 node.
https://github.com/nodejs/node/issues/22923
We might have some server fix for workaround since it's not expected have a node update recently.
Flags: needinfo?(juhsu)
|
|
||
Comment 4•5 years ago
|
||
test_http2-proxy.js hits a known issue of v8.11.3 node in comment 3.
However the work around doesn't work (see patch below). Maybe different issues with same syndrome.
It's a permanent issue, at least my local linux/mac. The reason of intermittent treeherder is that test_http2-proxy.js is the last test who needs node.
xpcshell is happy even if node crashes.
In this case, test_trr is going to retry, and the node crashes before the retry.
v8.13 node works for me.
--- a/testing/xpcshell/moz-http2/moz-http2.js
+++ b/testing/xpcshell/moz-http2/moz-http2.js
@@ -1193,16 +1193,26 @@ if (http2_internal) {
proxy.on('stream', (stream, headers) => {
if (headers[':method'] !== 'CONNECT') {
// Only accept CONNECT requests
stream.close(http2.constants.NGHTTP2_REFUSED_STREAM);
return;
}
+ if (stream.session && !stream.session.goawayOverritten) {
+ stream.session.goawayOverritten = true;
+ stream.session.prevGoaway = stream.session.goaway;
+ stream.session.goaway = function (errorCode, lastStreamID, opaqueData) {
+ if (!this.closed) {
+ this.prevGoaway(errorCode, lastStreamID, opaqueData);
+ }
+ }
+ }
+
const target = headers[':authority'];
const authorization_token = headers['proxy-authorization'];
if ('authorization-token' != authorization_token || target == '407.example.com:443') {
stream.respond({ ':status': 407 });
// Deliberately send no Proxy-Authenticate header
stream.end();
return;
|
|
||
Comment 5•5 years ago
|
||
Bug 1547823 is about upgrading node to 10.
node 8 is End-of-life on the end of 2019, upgrade should happen before that.
| Comment hidden (Intermittent Failures Robot) |
|
Assignee | |
Comment 7•5 years ago
|
||
Thanks for the thorough investigation Junior.
I only see a couple of failures last week. Let's see if this spikes in which case we'll have to look for a better workaround.
Hopefully we can upgrade node soon.
Depends on: 1547823
Whiteboard: [necko-triaged]
|
||
Comment 8•5 years ago
|
||
Thanks; yes, would be great to update Node again ASAP.
|
|
||
Comment 9•5 years ago
|
||
Surprisingly node v8.16.1 still crashes on linux asan in treeherder
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d60c63a3b7fdedeecefc51455367a47a2b921db7&selectedJob=266961592
(search for node::Abort() in full log)
node v10.15.3 works
https://treeherder.mozilla.org/#/jobs?repo=try&revision=585e60409668dfcbb642ae17a847d41efb98d7bd
|
|
Assignee | |
Updated•5 years ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
|
Assignee | |
Comment 14•5 years ago
|
||
|
||
Comment 15•5 years ago
|
||
Pushed by valentin.gosu@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/a6a8310a3f76
Check that moz-http2.js is working before running test_trr.js r=JuniorHsu
|
||
Comment 16•5 years ago
|
||
| bugherder | ||
Status: NEW → RESOLVED
Closed: 5 years ago
status-firefox71:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla71
|
||
Updated•5 years ago
|
Assignee: nobody → valentin.gosu
|
||
Updated•5 years ago
|
status-firefox67:
--- → unaffected
status-firefox68:
--- → unaffected
status-firefox69:
--- → unaffected
status-firefox70:
--- → unaffected
status-firefox-esr60:
--- → unaffected
status-firefox-esr68:
--- → unaffected
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Updated•3 years ago
|
Has Regression Range: --- → yes
You need to log in
before you can comment on or make changes to this bug.
Description
•