Closed Bug 1584743 Opened 5 years ago Closed 5 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 - 3 == 2

Categories

(Core :: Networking, defect, P2)

Product:
Core
Component:
Networking
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla72
Tracking Flags:
Tracking Status
firefox-esr68 --- unaffected
firefox70 --- unaffected
firefox71 --- fixed
firefox72 --- fixed

People

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

References

(Regression)

Details

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

Attachments

(1 file)

Bug 1584743 - Use data URL for services.settings.server in test_http2-proxy.js r=mayhemer
47 bytes, text/x-phabricator-request
Details | Review

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

[task 2019-09-28T12:57:58.063Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_captive_portal_service.js | took 3385ms
[task 2019-09-28T12:57:58.063Z] 12:57:58 INFO - TEST-START | netwerk/test/unit/test_http2-proxy.js
[task 2019-09-28T12:57:58.775Z] 12:57:58 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_http2-proxy.js | xpcshell return code: 0
[task 2019-09-28T12:57:58.777Z] 12:57:58 INFO - TEST-INFO took 711ms
[task 2019-09-28T12:57:58.778Z] 12:57:58 INFO - >>>>>>>
[task 2019-09-28T12:57:58.778Z] 12:57:58 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-09-28T12:57:58.779Z] 12:57:58 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-09-28T12:57:58.780Z] 12:57:58 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-09-28T12:57:58.781Z] 12:57:58 INFO - running event loop
[task 2019-09-28T12:57:58.782Z] 12:57:58 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2019-09-28T12:57:58.783Z] 12:57:58 INFO - netwerk/test/unit/test_http2-proxy.js | Starting setup
[task 2019-09-28T12:57:58.784Z] 12:57:58 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2019-09-28T12:57:58.790Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | setup - [setup : 140] "33927" != null
[task 2019-09-28T12:57:58.790Z] 12:57:58 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2019-09-28T12:57:58.791Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | setup - [setup : 144] 43750 != null
[task 2019-09-28T12:57:58.792Z] 12:57:58 INFO - "Initial proxy session count = 0"
[task 2019-09-28T12:57:58.793Z] 12:57:58 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2019-09-28T12:57:58.794Z] 12:57:58 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2019-09-28T12:57:58.795Z] 12:57:58 INFO - netwerk/test/unit/test_http2-proxy.js | Starting proxy_success_one_session
[task 2019-09-28T12:57:58.795Z] 12:57:58 INFO - (xpcshell/head.js) | test proxy_success_one_session pending (2)
[task 2019-09-28T12:57:58.796Z] 12:57:58 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2019-09-28T12:57:58.797Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 191] 0 == 0
[task 2019-09-28T12:57:58.798Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 192] 200 == 200
[task 2019-09-28T12:57:58.799Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 193] ["random-request-1"] == true
[task 2019-09-28T12:57:58.799Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 194] ["You Win!"] == true
[task 2019-09-28T12:57:58.800Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 195] 0 == 0
[task 2019-09-28T12:57:58.801Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 196] 200 == 200
[task 2019-09-28T12:57:58.802Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 197] ["random-request-2"] == true
[task 2019-09-28T12:57:58.803Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 198] ["You Win!"] == true
[task 2019-09-28T12:57:58.804Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 199] Created just one session with the proxy - 1 == 1
[task 2019-09-28T12:57:58.805Z] 12:57:58 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)

[task 2019-09-28T12:57:58.827Z] 12:57:58 INFO - "
[task 2019-09-28T12:57:58.827Z] 12:57:58 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Unexpected content-type "null"" {file: "resource://services-settings/Utils.jsm" line: 120}]
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - fetchLatestChanges@resource://services-settings/Utils.jsm:120:15
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - asyncsync@resource://services-settings/RemoteSettingsClient.jsm:372:37
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - get@resource://services-settings/RemoteSettingsClient.jsm:325:22
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - asyncaddObserver@resource://gre/modules/UrlClassifierSkipListService.jsm:39:63
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - registerAndRunSkipListObserver@resource://gre/modules/UrlClassifierSkipListService.jsm:126:28
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - get_response/<@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:100:13
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - get_response@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:99:10
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - proxy_success_one_session@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:184:21
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1565:22
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - _run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1565:38
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - run@/builds/worker/workspace/build/tests/xpcshell/head.js:733:9
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:246:6
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:573:5
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - @-e:1:1
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - "
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 346] 0 == 0
[task 2019-09-28T12:57:58.828Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 347] 200 == 200
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 348] ["random-request-1"] == true
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 349] ["You Win!"] == true
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 350] 0 == 0
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 351] 200 == 200
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 352] ["random-request-2"] == true
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 353] ["You Win!"] == true
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 354] 0 == 0
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 355] 200 == 200
[task 2019-09-28T12:57:58.829Z] 12:57:58 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-09-28T12:57:58.829Z] 12:57:58 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_isolated_session - [proxy_success_isolated_session : 357] ["You Win!"] == true
[task 2019-09-28T12:57:58.829Z] 12:57:58 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 - 3 == 2
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:proxy_success_isolated_session:358
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - exiting test
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - Unexpected exception NS_ERROR_ABORT:
[task 2019-09-28T12:57:58.829Z] 12:57:58 INFO - _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:789:20
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:890:5
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:67:21
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - proto.report@resource://testing-common/Assert.jsm:233:10
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - equal@resource://testing-common/Assert.jsm:275:8
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - proxy_success_isolated_session@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_http2-proxy.js:358:10
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - async*run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1565:22
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - _run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1565:38
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - run@/builds/worker/workspace/build/tests/xpcshell/head.js:733:9
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:246:6
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:573:5
[task 2019-09-28T12:57:58.830Z] 12:57:58 INFO - @-e:1:1
[task 2019-09-28T12:57:58.831Z] 12:57:58 INFO - exiting test
[task 2019-09-28T12:57:58.831Z] 12:57:58 INFO - PID 12786 | JavaScript strict warning: resource://testing-common/httpd.js, line 945: ReferenceError: reference to undefined property "result"
[task 2019-09-28T12:57:58.831Z] 12:57:58 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "result"" {file: "resource://testing-common/httpd.js" line: 945}]"
[task 2019-09-28T12:57:58.831Z] 12:57:58 INFO - <<<<<<<

Component: DOM: Networking → Networking
Priority: P5 → P2
Whiteboard: [necko-triaged]

There are 17 total failures in the last 7 days on linux64 asan, linux64-qr debug and windows10-64-shippable opt.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=273091679&repo=autoland&lineNumber=2659

[task 2019-10-26T16:00:27.453Z] 16:00:27 INFO - TEST-START | netwerk/test/unit/test_http2-proxy.js
[task 2019-10-26T16:00:28.138Z] 16:00:28 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_http2-proxy.js | xpcshell return code: 0
[task 2019-10-26T16:00:28.138Z] 16:00:28 INFO - TEST-INFO took 688ms
[task 2019-10-26T16:00:28.138Z] 16:00:28 INFO - >>>>>>>
[task 2019-10-26T16:00:28.139Z] 16:00:28 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-10-26T16:00:28.139Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-10-26T16:00:28.139Z] 16:00:28 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-10-26T16:00:28.139Z] 16:00:28 INFO - running event loop
[task 2019-10-26T16:00:28.141Z] 16:00:28 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2019-10-26T16:00:28.141Z] 16:00:28 INFO - netwerk/test/unit/test_http2-proxy.js | Starting setup
[task 2019-10-26T16:00:28.141Z] 16:00:28 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2019-10-26T16:00:28.141Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | setup - [setup : 140] "37823" != null
[task 2019-10-26T16:00:28.141Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2019-10-26T16:00:28.141Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | setup - [setup : 144] 41461 != null
[task 2019-10-26T16:00:28.142Z] 16:00:28 INFO - "Initial proxy session count = 0"
[task 2019-10-26T16:00:28.142Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2019-10-26T16:00:28.142Z] 16:00:28 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2019-10-26T16:00:28.142Z] 16:00:28 INFO - netwerk/test/unit/test_http2-proxy.js | Starting proxy_success_one_session
[task 2019-10-26T16:00:28.142Z] 16:00:28 INFO - (xpcshell/head.js) | test proxy_success_one_session pending (2)
[task 2019-10-26T16:00:28.143Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2019-10-26T16:00:28.143Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 191] 0 == 0
[task 2019-10-26T16:00:28.143Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 192] 200 == 200
[task 2019-10-26T16:00:28.144Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 193] ["random-request-1"] == true
[task 2019-10-26T16:00:28.144Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 194] ["You Win!"] == true
[task 2019-10-26T16:00:28.144Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 195] 0 == 0
[task 2019-10-26T16:00:28.145Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 196] 200 == 200
[task 2019-10-26T16:00:28.146Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 197] ["random-request-2"] == true
[task 2019-10-26T16:00:28.146Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 198] ["You Win!"] == true
[task 2019-10-26T16:00:28.146Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_success_one_session - [proxy_success_one_session : 199] Created just one session with the proxy - 1 == 1
[task 2019-10-26T16:00:28.147Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2019-10-26T16:00:28.147Z] 16:00:28 INFO - (xpcshell/head.js) | test proxy_success_one_session finished (2)
[task 2019-10-26T16:00:28.150Z] 16:00:28 INFO - netwerk/test/unit/test_http2-proxy.js | Starting proxy_auth_failure
[task 2019-10-26T16:00:28.151Z] 16:00:28 INFO - (xpcshell/head.js) | test proxy_auth_failure pending (2)
[task 2019-10-26T16:00:28.152Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2019-10-26T16:00:28.152Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_auth_failure - [proxy_auth_failure : 216] 2152399255 == 2152399255
[task 2019-10-26T16:00:28.153Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_auth_failure - [proxy_auth_failure : 217] "undefined" == "undefined"
[task 2019-10-26T16:00:28.154Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_auth_failure - [proxy_auth_failure : 218] Auth prompt didn't trigger - false == false
[task 2019-10-26T16:00:28.154Z] 16:00:28 INFO - TEST-PASS | netwerk/test/unit/test_http2-proxy.js | proxy_auth_failure - [proxy_auth_failure : 219] No new session created by 407 - 1 == 1
[task 2019-10-26T16:00:28.155Z] 16:00:28 INFO - (xpcshell/head.js) | test run_next_test 3 pending (2)

Hi Valentin, this seems to be a regression of bug 1582515, can you please take a look?

https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-06-30&endday=2019-10-28&tree=trunk&bug=1584743

Flags: needinfo?(valentin.gosu)
Regressed by: 1582515
Whiteboard: [necko-triaged] → [necko-triaged][stockwell needswork:owner]

Should be fixed by bug 1584397.

Depends on: 1584397
Flags: needinfo?(valentin.gosu)

Applying the patch in bug 1584397 made this reproduce every 2/3 times. I did some logging, and it seems new sessions were being created for the remote-settings requests.
I think I have a fix for this by using a data URL for the settings instead.

Assignee: nobody → valentin.gosu

Using a data URL makes the request not use the proxy and so it will not mess up the session count

Pushed by valentin.gosu@gmail.com: https://hg.mozilla.org/integration/autoland/rev/d0a0a6fe8b1c Use data URL for services.settings.server in test_http2-proxy.js r=mayhemer

https://hg.mozilla.org/mozilla-central/rev/d0a0a6fe8b1c

Status: NEW → RESOLVED
Closed: 5 years ago
status-firefox72: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla72
See Also: → 1594348
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: