1753703 - Intermittent netwerk/test/unit/test_httpssvc_retry_with_ech.js | testConnectWithECH - [testConnectWithECH : 188] 6 == 3 | after xpcshell return code: 0

Status: RESOLVED FIXED

(Core :: Networking, defect, P2)

Description

[Treeherder Bug Filer]

Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=366746419&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FgOxAcGNSD2eopCZoi_ZvA/runs/0/artifacts/public/logs/live_backing.log

---

TEST-PASS | netwerk/test/unit/test_httpssvc_retry_with_ech.js | testConnectWithECH - [testConnectWithECH : 179] This host should have accepted ECH - true == true
[task 2022-02-04T16:58:29.508Z] 16:58:29     INFO -  PID 21472 | *** Connection Activity 0x3 0x5008 .........[tlsflags0x00000000]127.0.0.1:37605
[task 2022-02-04T16:58:29.509Z] 16:58:29     INFO -  PID 21472 | *** Connection Activity 0x3 0x500b .........[tlsflags0x00000000]127.0.0.1:37605
[task 2022-02-04T16:58:29.509Z] 16:58:29  WARNING -  TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_httpssvc_retry_with_ech.js | testConnectWithECH - [testConnectWithECH : 188] 6 == 3
[task 2022-02-04T16:58:29.510Z] 16:58:29     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_httpssvc_retry_with_ech.js:testConnectWithECH:188
[task 2022-02-04T16:58:29.510Z] 16:58:29     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:240
[task 2022-02-04T16:58:29.511Z] 16:58:29     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:604
[task 2022-02-04T16:58:29.512Z] 16:58:29     INFO -  -e:null:1
[task 2022-02-04T16:58:29.513Z] 16:58:29     INFO -  exiting test
[task 2022-02-04T16:58:29.514Z] 16:58:29     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2022-02-04T16:58:29.514Z] 16:58:29     INFO -  _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:875:20
[task 2022-02-04T16:58:29.515Z] 16:58:29     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:976:5
[task 2022-02-04T16:58:29.515Z] 16:58:29     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:75:21
[task 2022-02-04T16:58:29.516Z] 16:58:29     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2022-02-04T16:58:29.518Z] 16:58:29     INFO -  equal@resource://testing-common/Assert.jsm:270:8
[task 2022-02-04T16:58:29.519Z] 16:58:29     INFO -  testConnectWithECH@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_httpssvc_retry_with_ech.js:188:10
[task 2022-02-04T16:58:29.521Z] 16:58:29     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-02-04T16:58:29.522Z] 16:58:29     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:604:5
[task 2022-02-04T16:58:29.522Z] 16:58:29     INFO -  @-e:1:1
[task 2022-02-04T16:58:29.523Z] 16:58:29     INFO -  exiting test
[task 2022-02-04T16:58:29.524Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:198
[task 2022-02-04T16:58:29.525Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:198
[task 2022-02-04T16:58:29.526Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:198
[task 2022-02-04T16:58:29.527Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:198
[task 2022-02-04T16:58:29.527Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:198
[task 2022-02-04T16:58:29.528Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: idb: '0.000001s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.529Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: cache: '0.000034s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.530Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: sdb: '0.000041s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.531Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: ls: '0.000047s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.532Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: idb: '0.000059s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.533Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: cache: '0.000087s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.534Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: sdb: '0.000094s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.535Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, IPDL Background] WARNING: ls: '0.000099s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3789
[task 2022-02-04T16:58:29.536Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3351
[task 2022-02-04T16:58:29.537Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Main Thread] WARNING: OOPDeinit() without successful OOPInit(): file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp:3421
[task 2022-02-04T16:58:29.538Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4448
[task 2022-02-04T16:58:29.539Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Main Thread] WARNING: XPCOM object PerThreadData destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:206
[task 2022-02-04T16:58:29.540Z] 16:58:29     INFO -  PID 21472 | [Parent 21472, Main Thread] WARNING: XPCOM object MasterList destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:206
[task 2022-02-04T16:58:29.541Z] 16:58:29     INFO -  <<<<<<<
[task 2022-02-04T16:58:29.541Z] 16:58:29     INFO -  TEST-START | netwerk/test/unit/test_httpssvc_retry_without_ech.js

Comment 1

[Intermittent Failures Robot]

6 failures in 3165 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2
• comm-central: 1
• try: 3

Platform and build breakdown:

• linux1804-64-domstreams-qr: 1
  • debug: 1
• linux1804-64-qr: 2
  • debug: 2
• linux1804-64-devedition-qr: 2
  • opt: 2
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753703&startday=2022-01-31&endday=2022-02-06&tree=all

Comment 2

[BugBot [:suhaib / :marco]]

Set release status flags based on info from the regressing bug 1750413

Comment 3

[Intermittent Failures Robot]

50 failures in 3711 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #20 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• try: 15
• autoland: 17
• mozilla-central: 1
• mozilla-beta: 17

Platform and build breakdown:

• linux1804-64-devedition-qr: 17
  • opt: 17
• linux1804-64-qr: 4
  • debug: 4
• linux1804-64-shippable-qr: 15
  • opt: 15
• linux1804-64-domstreams-qr: 12
  • debug: 12
• windows10-32-2004-qr: 1
  • debug: 1
• windows7-32-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753703&startday=2022-02-07&endday=2022-02-13&tree=all

Comment 4

[Kershaw Chang [:kershaw]]

Attachment: Bug 1753703 - P1: Loosen the HTTP activity check, r=#necko

The origin test assumes a very particular ordering of HTTP activities, which causes some interimentent failures.
The failed case shows that it's possible that a speculative connection completes before we dispatch the real transaction, so we got 6 http activites.

Comment 5

[Kershaw Chang [:kershaw]]

Attachment: Bug 1753703 - P2: Move HttpActivityDistributor to nsHttpHandler, r=#necko

Since both DnsAndConnectSocket and nsHttpTransaction use HttpActivityDistributor, let's refactor this a bit by moving some duplicate code to nsHttpHandler.
This patch also makes it possible to test ECH activity for Http3 case.

Depends on D138892

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/1c1324708e2c
P1: Loosen the HTTP activity check, r=necko-reviewers,dragana
https://hg.mozilla.org/integration/autoland/rev/192cda8fb4dd
P2: Move HttpActivityDistributor to nsHttpHandler, r=necko-reviewers,dragana

Comment 7

[Cristian Tuns]

Backed out for causing Bp-hybrid bustages on Http3Session.cpp

• Backout link
• Push with failures
• Failure Log
• Failure line:/builds/worker/checkouts/gecko/netwerk/protocol/http/Http3Session.cpp:168:19: error: use of undeclared identifier 'NS_ACTIVITY_TYPE_HTTP_CONNECTION'

Comment 8

[Iulian Moraru]

This mochitest remote jobs also fail from your changes.
Backfill range
Failure log

Comment 9

[Kershaw Chang [:kershaw]]

https://treeherder.mozilla.org/jobs?repo=try&revision=fbf59b3243d7e66c9e3d9a739a3231a8690afd20

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3e2a14f02683
P1: Loosen the HTTP activity check, r=necko-reviewers,dragana
https://hg.mozilla.org/integration/autoland/rev/2c092e335ae0
P2: Move HttpActivityDistributor to nsHttpHandler, r=necko-reviewers,dragana

Comment 11

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/3e2a14f02683
https://hg.mozilla.org/mozilla-central/rev/2c092e335ae0

Comment 12

[Intermittent Failures Robot]

38 failures in 3281 pushes (0.012 failures/push) were associated with this bug in the last 7 days.

This is the #21 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-beta: 16
• autoland: 15
• mozilla-central: 3
• try: 4

Platform and build breakdown:

• linux1804-64-devedition-qr: 11
  • opt: 11
• linux1804-64-shippable-qr: 9
  • opt: 9
• linux1804-64-qr: 9
  • debug: 9
• windows7-32-shippable-qr: 2
  • opt: 2
• linux1804-64-domstreams-qr: 7
  • debug: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753703&startday=2022-02-14&endday=2022-02-20&tree=all

Comment 13

[BugBot [:suhaib / :marco]]

The patch landed in nightly and beta is affected.
:kershaw, is this bug important enough to require an uplift?
If not please set status_beta to wontfix.

For more information, please visit auto_nag documentation.

Comment 14

[Kershaw Chang [:kershaw]]

This is about fixing the intermittent test failure, so no need to uplift.

Comment 15

[Intermittent Failures Robot]

2 failures in 2992 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 2

Platform and build breakdown:

• linux1804-64-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753703&startday=2022-02-21&endday=2022-02-27&tree=all