1715414 - telemetry | High frequency Assertion failure: mThreadLocalIndex != kBadThreadLocalIndex (BackgroundChild::Startup() was never called!), at /builds/worker/checkouts/gecko/ipc/glue/BackgroundImpl.cpp:378

Status: RESOLVED FIXED

(Core :: IPC, defect, P3)

Description

[Andrew Osmond [:aosmond] (he/him)]

Attachment: live_backing.zip

+++ This bug was initially created as a clone of Bug #1644166 +++

This seems to be permafailing on https://treeherder.mozilla.org/jobs?repo=try&selectedTaskRun=YjfU3do0SzyzEiXq761CMA.0&revision=c7230b53515ec3e0552294ced049f7ee9072e128&searchStr=linux%2Cwebrender%2Cdebug%2Ctelemetry

[task 2021-06-08T23:43:57.878Z] 23:43:57     INFO -  Assertion failure: mThreadLocalIndex != kBadThreadLocalIndex (BackgroundChild::Startup() was never called!), at /builds/worker/checkouts/gecko/ipc/glue/BackgroundImpl.cpp:383

We can't move these tests over until the intermittent gets fixed (or we get a pass for creating a permafail).

Comment 1

[Intermittent Failures Robot]

49 failures in 147 pushes (0.333 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 38
• mozilla-central: 10
• try: 1

Platform and build breakdown:

• linux1804-64: 10
  • debug: 10
• macosx1015-64-qr: 24
  • debug: 24
• windows10-64: 5
  • debug: 5
• windows10-64-qr: 3
  • debug: 3
• windows10-32-qr: 7
  • debug: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-06-26&endday=2021-06-26&tree=all

Comment 2

[Intermittent Failures Robot]

91 failures in 3115 pushes (0.029 failures/push) were associated with this bug in the last 7 days.

This is the #10 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 67
• mozilla-central: 23
• try: 1

Platform and build breakdown:

• macosx1015-64-qr: 47
  • debug: 47
• windows10-32-qr: 10
  • debug: 10
• linux1804-64: 13
  • debug: 13
• windows10-64: 8
  • debug: 8
• windows10-64-qr: 13
  • debug: 13

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

Comment 3

[Intermittent Failures Robot]

33 failures in 121 pushes (0.273 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 21
• try: 1
• mozilla-central: 11

Platform and build breakdown:

• linux1804-64: 8
  • debug: 8
• macosx1015-64-qr: 14
  • debug: 14
• windows10-64: 3
  • debug: 3
• windows10-32-qr: 4
  • debug: 4
• windows10-64-qr: 3
  • debug: 3
• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-06-28&endday=2021-06-28&tree=all

Comment 4

[Andreea Pavel [:apavel]]

There are 151 total failures in the last 7 days on

• windows10-64-qr debug
• windows10-64 debug
• windows10-32-qr debug
• macosx1015-64-qr debug
• linux1804-64 debug

Retriggers: https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=OS%2CX%2C10.15%2CWebRender%2Cdebug%2Ctest-macosx1015-64-qr%2Fdebug-marionette-swr-e10s%2CMn-swr&tochange=d23b5390345dac48f1c6fc66482edbe85d1ea3ad&fromchange=c02d857cc89f0cb630535e3168f483765db90aa4

Randell, please take a look.

Comment 5

[Intermittent Failures Robot]

66 failures in 121 pushes (0.545 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 50
• mozilla-central: 16

Platform and build breakdown:

• linux1804-64: 10
  • debug: 10
• macosx1015-64-qr: 28
  • debug: 28
• windows10-32-qr: 8
  • debug: 8
• windows10-64-qr: 13
  • debug: 13
• windows10-64: 7
  • debug: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-06-29&endday=2021-06-29&tree=all

Comment 6

[Alexandru Michis [:malexandru]]

Should be fixed by the backout of Bug 1687843:
https://hg.mozilla.org/integration/autoland/rev/a0c0b00b2df9

Comment 7

[Intermittent Failures Robot]

29 failures in 153 pushes (0.19 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 22
• mozilla-central: 7

Platform and build breakdown:

• linux1804-64: 4
  • debug: 4
• windows10-64: 3
  • debug: 3
• windows10-64-qr: 4
  • debug: 4
• macosx1015-64-qr: 17
  • debug: 17
• windows10-32-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-06-30&endday=2021-06-30&tree=all

Comment 8

[Intermittent Failures Robot]

128 failures in 723 pushes (0.177 failures/push) were associated with this bug in the last 7 days.

This is the #2 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 93
• try: 1
• mozilla-central: 34

Platform and build breakdown:

• linux1804-64: 22
  • debug: 22
• macosx1015-64-qr: 59
  • debug: 59
• windows10-64: 13
  • debug: 13
• windows10-32-qr: 13
  • debug: 13
• windows10-64-qr: 20
  • debug: 20
• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-06-28&endday=2021-07-04&tree=all

Comment 9

[Alexandru Michis [:malexandru]]

Jesup, this has reappeared on esr91: https://treeherder.mozilla.org/jobs?repo=mozilla-esr91&duplicate_jobs=visible&resultStatus=testfailed%2Cbusted%2Cexception&fromchange=820004fa5e68dc6da164d9ffb5149fd901960c3f&searchStr=Linux%2C18.04%2Cx64%2CWebRender%2Cdebug%2CTelemetry%2Ctests%2Ctest-linux1804-64-qr%2Fdebug-telemetry-tests-client-e10s%2Cc

Could you please take a look?

Comment 10

[Intermittent Failures Robot]

13 failures in 3025 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 13

Platform and build breakdown:

• linux1804-64-qr: 11
  • debug: 11
• windows10-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-08-09&endday=2021-08-15&tree=all

Comment 11

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-esr91: 7

Platform and build breakdown:

• linux1804-64-qr: 7
  • debug: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-08-16&endday=2021-08-22&tree=all

Comment 12

[Intermittent Failures Robot]

8 failures in 2580 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 8

Platform and build breakdown:

• linux1804-64-qr: 8
  • debug: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-08-23&endday=2021-08-29&tree=all

Comment 13

[Ryan VanderMeulen [:RyanVM]]

Jed, this bug is failing frequently on ESR91 and we're struggling to find someone who can help move the investigation forward. Can you please take a look and redirect as needed? Thanks.

Comment 14

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

I think what's going on here is that the idle scheduler is being used (in a content process) before PBackground is initialized, because the latter happens relatively late: from ContentChild::InitXPCOM called from RecvSetXPCOMProcessAttributes. So if thread scheduling is such that receiving the message is delayed enough for the process to consider itself idle before that point, then I can see how we'd crash like this.

But it's interesting that this is happening only on ESR91 and no other branches.

Redirecting needinfo to people who might have more detailed knowledge.

Comment 15

[Olli Pettay [:smaug][[e-mail]]]

ok, so obviously the API (GetOrCreateForCurrentThread) doesn't hint that it can be called only in some cases but not in others. It should just handle the problematic case in some reasonable way.

To fix this particular issue it should be enough to return TimeStamp() or TimeStamp::Now() from
https://searchfox.org/mozilla-central/rev/ad2ffab089e4e0c0fe99a1a046ab2b1c45546bdb/xpcom/threads/IdlePeriodState.cpp#102 when PBackground isn't ready yet. What would be the easier way to check that?

Comment 16

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

I discussed this with the other IPC people and it was pointed out that the end of ContentProcess::Init should be late enough for everything in BackgroundChild::Startup to work and earlier than anything that involves event loops.

Also, the thread-local storage initialization could be separated from the rest and done much earlier if necessary, but I don't think that's the case here.

Comment 17

[Intermittent Failures Robot]

1 failures in 3084 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-08-30&endday=2021-09-05&tree=all

Comment 18

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-esr91: 5

Platform and build breakdown:

• linux1804-64-qr: 5
  • debug: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-09-06&endday=2021-09-12&tree=all

Comment 19

[Ryan VanderMeulen [:RyanVM]]

Hi Jed, who should take the next step here?

Comment 20

[Ryan VanderMeulen [:RyanVM]]

Nevermind, we'll just disable the test.

Comment 21

[Ryan VanderMeulen [:RyanVM]]

Attachment: Bug 1715414 - Skip test_search_counts_across_sessions.py on Linux debug for being nearly permafail. r=chutten

Comment 22

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr91/rev/a068798ccdf5

Comment 23

[Intermittent Failures Robot]

16 failures in 504 pushes (0.032 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-esr91: 16

Platform and build breakdown:

• linux1804-64-qr: 16
  • debug: 16

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-09-16&endday=2021-09-16&tree=all

Comment 24

[Ryan VanderMeulen [:RyanVM]]

Attachment: Bug 1715414 - Skip telemetry-tests-client on Linux debug due to frequent failures. r=chutten

Comment 25

[Ryan VanderMeulen [:RyanVM]]

Disabling the one test didn't work, so let's skip the entire job on Linux debug instead.

Comment 26

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr91/rev/3324c4932248

Comment 27

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

I'll take this. If comment 14 / comment 16 are right, it should be simple to fix.

Comment 28

[Intermittent Failures Robot]

19 failures in 3375 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 19

Platform and build breakdown:

• linux1804-64-qr: 19
  • debug: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-09-13&endday=2021-09-19&tree=all

Comment 29

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

Try run on the ESR91 branch (passes 40x), vs. the control group (fails in 8/10 test runs). I'll send this for review.

Comment 30

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

Attachment: Bug 1715414 - Start PBackground earlier in content processes.

Previously we were staring PBackground in content processes in
response to receiving the SetXPCOMProcessAttributes IPC message, which
is sent immediately after the process is launched. Meanwhile, the
idle scheduler tries to use PBackground when the main thread considers
itself idle. But if thread scheduling is such that the content process
main thread becomes idle before the IPC I/O thread has received and
dispatched that message, then we have a problem (signaled by an assertion
failure).

This patch moves content process PBackground startup earlier, to the
end of ContentProcess::Init; that point is after enough of IPC and
XPCOM is started for it to work, but before we start spinning the main
thread event loop.

Comment 31

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/671ba1530436
Start PBackground earlier in content processes. r=nika

Comment 32

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ff118c8d4a31
Backed out changeset 671ba1530436 for casuing bustages on ContentProcess.cpp. CLOSED TREE

Comment 33

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/82e09e54c635
Start PBackground earlier in content processes. r=nika

Comment 34

[Cristian Tuns]

https://hg.mozilla.org/mozilla-central/rev/82e09e54c635

Comment 35

[Intermittent Failures Robot]

1 failures in 3626 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr91: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-10-04&endday=2021-10-10&tree=all

Comment 36

[Ryan VanderMeulen [:RyanVM]]

This fix looks fantastic on Try on top of ESR91:
https://treeherder.mozilla.org/jobs?repo=try&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception%2Csuccess%2Cusercancel%2Crunning%2Cpending%2Crunnable&revision=f54ec923b5da8d80e8069d1a7ad96ccf372ae41f&searchStr=telemetry-tests

Is this something we can safely uplift there? If so, go ahead and nominate.

Comment 37

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

Comment on attachment 9242150 [details]
Bug 1715414 - Start PBackground earlier in content processes.

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: Fixes intermittent test failures.
• User impact if declined: This is relatively harmless in practice (the idle scheduler code looks like it fails gracefully, and I don't think any other PBackground users are currently affected), but the main motivation for uplift is to allow the failing tests that were disabled earlier in this bug to be re-enabled so we can catch any actual failures in those tests.
• Fix Landed on Version: 94
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): This just runs an existing small part of child process startup earlier (but still after the things it depends on; the code is simple enough to be reasonably sure of that), and it's been stable on 94 for a while.
• String or UUID changes made by this patch: none

Comment 38

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9242150 [details]
Bug 1715414 - Start PBackground earlier in content processes.

Approved for 91.3esr, thanks.

Comment 39

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr91/rev/e1a3b77fc5f3
https://hg.mozilla.org/releases/mozilla-esr91/rev/06a904f58de5

Comment 40

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2

Platform and build breakdown:

• linux1804-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1715414&startday=2021-10-11&endday=2021-10-17&tree=all