Closed Bug 1594348 Opened 5 years ago Closed 4 years ago

Intermittent netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 358] Just one new session seen after changing the isolation key - 4 == 2

Categories

(Core :: Networking: HTTP, defect, P3)

Product:
Core
Component:
Networking: HTTP
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [necko-triaged])

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

[task 2019-11-06T09:58:20.742Z] 09:58:20 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 354] 0 == 0
[task 2019-11-06T09:58:20.743Z] 09:58:20 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 355] 200 == 200
[task 2019-11-06T09:58:20.743Z] 09:58:20 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 356] ["random-request-3"] == true
[task 2019-11-06T09:58:20.744Z] 09:58:20 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 357] ["You Win!"] == true
[task 2019-11-06T09:58:20.744Z] 09:58:20 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 358] Just one new session seen after changing the isolation key - 4 == 2
[task 2019-11-06T09:58:20.745Z] 09:58:20 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:proxy_success_isolated_session:358
[task 2019-11-06T09:58:20.745Z] 09:58:20 INFO - exiting test
[task 2019-11-06T09:58:20.746Z] 09:58:20 INFO - Unexpected exception NS_ERROR_ABORT:
[task 2019-11-06T09:58:20.746Z] 09:58:20 INFO - _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:791:20
[task 2019-11-06T09:58:20.747Z] 09:58:20 INFO - do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:892:5
[task 2019-11-06T09:58:20.747Z] 09:58:20 INFO - Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:67:21
[task 2019-11-06T09:58:20.748Z] 09:58:20 INFO - proto.report@resource://testing-common/Assert.jsm:233:10
[task 2019-11-06T09:58:20.748Z] 09:58:20 INFO - equal@resource://testing-common/Assert.jsm:275:8
[task 2019-11-06T09:58:20.749Z] 09:58:20 INFO - proxy_success_isolated_session@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:358:10
[task 2019-11-06T09:58:20.749Z] 09:58:20 INFO - async*run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1567:22
[task 2019-11-06T09:58:20.749Z] 09:58:20 INFO - _run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1567:38
[task 2019-11-06T09:58:20.750Z] 09:58:20 INFO - run@/builds/worker/workspace/build/tests/xpcshell/head.js:735:9
[task 2019-11-06T09:58:20.750Z] 09:58:20 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:246:6
[task 2019-11-06T09:58:20.751Z] 09:58:20 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:573:5
[task 2019-11-06T09:58:20.751Z] 09:58:20 INFO - @-e:1:1
[task 2019-11-06T09:58:20.752Z] 09:58:20 INFO - exiting test
[task 2019-11-06T09:58:20.752Z] 09:58:20 INFO - PID 13334 | JavaScript strict warning: resource://testing-common/httpd.js, line 945: ReferenceError: reference to undefined property "result"
[task 2019-11-06T09:58:20.753Z] 09:58:20 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "result"" {file: "resource://testing-common/httpd.js" line: 945}]"
[task 2019-11-06T09:58:20.753Z] 09:58:20 INFO - <<<<<<<

This seems similar to bug 1584743 but happens much less often.

Priority: P5 → P3
See Also: → 1584743
Whiteboard: [necko-triaged]

If this starts spiking the solution is to log the URLs of the connections/sessions in the test, and seeing what is causing the extra one.
I suspect it's yet another background service/addon uptater/etc.

Component: DOM: Networking → Networking: HTTP

Or we could try to change the test. The point is to see if the isolation happens (or not), so we could rather query the id of the session the tunnel stream is served on than to rely on calculation of something that seems to not be stable - this bug will probably be there forever! It's possible to add an id property on each new session, each stream can see the session that it's served through [1][2]. Problem is if the e2e request is https - then the proxy will actually proxy to the server and won't be able to response with the session id. We could link via port numbers somehow [3].

[1] https://github.com/mayhemer/node_http2_proxy/blob/6f79d96b2860e030512d50e3490a6c4d3dbb8490/proxy.js#L98
[2] https://github.com/mayhemer/node_http2_proxy/blob/6f79d96b2860e030512d50e3490a6c4d3dbb8490/proxy.js#L286
[3] https://github.com/mayhemer/node_http2_proxy/blob/6f79d96b2860e030512d50e3490a6c4d3dbb8490/proxy.js#L287-L289

Note that we can NOT simply query nsIHttpChannelInternal.localPort. Just tried and it is not available when the CONNECT response is a failure...

No recent reported failures.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.