1173961 - Intermittent test_response_sw_reroute.html | application crashed [@ mozalloc_abort(char const * const)] after "FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":t"

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect, P3)

Description

[Ryan VanderMeulen [:RyanVM]]

00:12:29 INFO - 4441 INFO TEST-OK | dom/tests/mochitest/fetch/test_response_sw_reroute.html | took 1477ms
00:12:40 INFO - WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":false,"shutdownBarrier":"Complete","connectionsBarrier":"Not started"},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":684,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:684","resource://gre/modules/TelemetryController.jsm:Impl.observe:761","resource://gre/modules/TelemetryController.jsm:this.TelemetryController<.observe:162","resource://gre/components/TelemetryStartup.js:TelemetryStartup.prototype.observe:30","null:null:0"]}] Barrier: profile-before-change2
00:12:40 INFO - WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"Waiting for ping task","state":"(none)","filename":"resource://gre/modules/TelemetrySend.jsm","lineNumber":696,"stack":["resource://gre/modules/TelemetrySend.jsm:TelemetrySendImpl._trackPendingPingTask:696","resource://gre/modules/TelemetrySend.jsm:TelemetrySendImpl._sendPersistedPings<:498","self-hosted:next:623","resource://gre/modules/Task.jsm:TaskImpl_run:314","resource://gre/modules/Task.jsm:TaskImpl:275","resource://gre/modules/Task.jsm:createAsyncFunction/asyncFunction:249","resource://gre/modules/TelemetrySend.jsm:TelemetrySendImpl._reschedulePingSendTimer/this._pingSendTimer<:681","resource://gre/modules/Timer.jsm:setTimeout_timer:30","null:null:0"]}] Barrier: TelemetrySend: Waiting for pending ping activity
00:13:31 INFO - FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":false,"shutdownBarrier":"Complete","connectionsBarrier":"Not started"},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":684,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:684","resource://gre/modules/TelemetryController.jsm:Impl.observe:761","resource://gre/modules/TelemetryController.jsm:this.TelemetryController<.observe:162","resource://gre/components/TelemetryStartup.js:TelemetryStartup.prototype.observe:30","null:null:0"]}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
00:13:31 INFO - [Parent 2948] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 684
00:13:31 INFO - TEST-INFO | Main app process: exit status 1
00:13:31 INFO - 4442 INFO TEST-START | Shutdown
00:13:31 INFO - 4443 INFO Passed: 80656
00:13:31 INFO - 4444 INFO Failed: 0
00:13:31 INFO - 4445 INFO Todo: 1119
00:13:31 INFO - 4446 INFO Slowest: 20931ms - /tests/dom/security/test/mixedcontentblocker/test_main.html
00:13:31 INFO - 4447 INFO SimpleTest FINISHED
00:13:31 INFO - 4448 INFO TEST-INFO | Ran 1 Loops
00:13:31 INFO - 4449 INFO SimpleTest FINISHED
00:13:31 WARNING - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/fetch/test_response_sw_reroute.html | application terminated with exit code 1
00:13:39 WARNING - PROCESS-CRASH | dom/tests/mochitest/fetch/test_response_sw_reroute.html | application crashed [@ mozalloc_abort(char const * const)]
00:13:39 INFO - Crash dump filename: c:\users\cltbld~1.t-w\appdata\local\temp\tmp6oychp.mozrunner\minidumps\223984b4-730e-4b44-9b9c-207862b8aa9b.dmp
00:13:39 INFO - Operating system: Windows NT
00:13:39 INFO - 6.2.9200
00:13:39 INFO - CPU: amd64
00:13:39 INFO - family 6 model 30 stepping 5
00:13:39 INFO - 8 CPUs
00:13:39 INFO - Crash reason: EXCEPTION_BREAKPOINT
00:13:39 INFO - Crash address: 0x7fa3a4301eb
00:13:39 INFO - Thread 0 (crashed)
00:13:39 INFO - 0 mozglue.dll!mozalloc_abort(char const * const) [mozalloc_abort.cpp:39e638ed06bf : 33 + 0x0]
00:13:39 INFO - rbx = 0x0000008cf4083df0 r12 = 0x0000008c80045b20
00:13:39 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000001
00:13:39 INFO - r15 = 0x0000000000000000 rip = 0x000007fa3a4301eb
00:13:39 INFO - rsp = 0x0000008cf4083d60 rbp = 0x0000008cf4083e90
00:13:39 INFO - Found by: given as instruction pointer in context
00:13:39 INFO - 1 xul.dll!NS_DebugBreak [nsDebugImpl.cpp:39e638ed06bf : 425 + 0xa]
00:13:39 INFO - rbx = 0x0000008cf4083df0 r12 = 0x0000008c80045b20
00:13:39 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000001
00:13:39 INFO - r15 = 0x0000000000000000 rip = 0x000007fa2c54dc68
00:13:39 INFO - rsp = 0x0000008cf4083d90 rbp = 0x0000008cf4083e90
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 2 xul.dll!nsDebugImpl::Abort(char const *,int) [nsDebugImpl.cpp:39e638ed06bf : 147 + 0x14]
00:13:39 INFO - rbx = 0x0000008cf4083df0 r12 = 0x0000008c80045b20
00:13:39 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000001
00:13:39 INFO - r15 = 0x0000000000000000 rip = 0x000007fa2c54d285
00:13:39 INFO - rsp = 0x0000008cf4084230 rbp = 0x0000008cf4083e90
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 3 xul.dll!XPTC__InvokebyIndex [xptcinvoke_asm_x86_64.asm:39e638ed06bf : 97 + 0x3]
00:13:39 INFO - rbx = 0x0000008cf4083df0 r12 = 0x0000008c80045b20
00:13:39 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000001
00:13:39 INFO - r15 = 0x0000000000000000 rip = 0x000007fa2c54dd12
00:13:39 INFO - rsp = 0x0000008cf4084270 rbp = 0x0000008cf4083e90
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 4 0x8c80045b1f
00:13:39 INFO - rbx = 0x0000008cf4083df0 r12 = 0x0000008c80045b20
00:13:39 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000001
00:13:39 INFO - r15 = 0x0000000000000000 rip = 0x0000008c80045b20
00:13:39 INFO - rsp = 0x0000008cf4084280 rbp = 0x0000008cf4083e90
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 5 xul.dll!nsXPConnect::GetRuntimeInstance() [nsXPConnect.cpp:39e638ed06bf : 169 + 0xb]
00:13:39 INFO - rip = 0x000007fa2bf4bf20 rsp = 0x0000008cf4084290
00:13:39 INFO - Found by: stack scanning
00:13:39 INFO - 6 xul.dll!XPC_WN_CallMethod(JSContext *,unsigned int,JS::Value *) [XPCWrappedNativeJSOps.cpp:39e638ed06bf : 1144 + 0x39a]
00:13:39 INFO - rip = 0x000007fa2c13f05e rsp = 0x0000008cf40842c0
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 7 xul.dll!js::Invoke(JSContext *,JS::CallArgs,js::MaybeConstruct) [Interpreter.cpp:39e638ed06bf : 703 + 0xac]
00:13:39 INFO - rip = 0x000007fa2bf229e1 rsp = 0x0000008cf4084830
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 8 xul.dll!Interpret [Interpreter.cpp:39e638ed06bf : 2954 + 0x16]
00:13:39 INFO - rip = 0x000007fa2c04c7f5 rsp = 0x0000008cf40850b0
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 9 xul.dll!js::RunScript(JSContext *,js::RunState &) [Interpreter.cpp:39e638ed06bf : 652 + 0xa]
00:13:39 INFO - rip = 0x000007fa2bf31d82 rsp = 0x0000008cf4086b60
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 10 xul.dll!js::Invoke(JSContext *,JS::CallArgs,js::MaybeConstruct) [Interpreter.cpp:39e638ed06bf : 723 + 0xb]
00:13:39 INFO - rip = 0x000007fa2bf22aec rsp = 0x0000008cf4086be0
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 11 xul.dll!js::CallOrConstructBoundFunction(JSContext *,unsigned int,JS::Value *) [jsfun.cpp:39e638ed06bf : 1578 + 0x12]
00:13:39 INFO - rip = 0x000007fa2c3f5486 rsp = 0x0000008cf4087460
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 12 xul.dll!js::Invoke(JSContext *,JS::CallArgs,js::MaybeConstruct) [Interpreter.cpp:39e638ed06bf : 703 + 0xac]
00:13:39 INFO - rip = 0x000007fa2bf229e1 rsp = 0x0000008cf40875b0
00:13:39 INFO - Found by: call frame info
00:13:39 INFO - 13 xul.dll!js::fun_call(JSContext *,unsigned int,JS::Value *) [jsfun.cpp:39e638ed06bf : 1216 + 0x13]
00:13:39 INFO - rip = 0x000007fa2c43c0d7 rsp = 0x0000008cf4087e30
00:13:39 INFO - Found by: call frame info

Comment 1

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=10652488
repository: mozilla-inbound
start_time: 2015-06-10T23:59:14
who: rvandermeulen[at]mozilla[dot]com
machine: t-w864-ix-118
buildname: Windows 8 64-bit mozilla-inbound pgo test mochitest-3
revision: 39e638ed06bf

FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":false,"shutdownBarrier":"Complete","connectionsBarrier":"Not started"},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":684,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:684","resource://gre/modules/TelemetryController.jsm:Impl.observe:761",
[Parent 2948] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 684
TEST-UNEXPECTED-FAIL | dom/tests/mochitest/fetch/test_response_sw_reroute.html | application terminated with exit code 1
PROCESS-CRASH | dom/tests/mochitest/fetch/test_response_sw_reroute.html | application crashed [@ mozalloc_abort(char const * const)]
Return code: 1

Comment 2

[Alessio Placitelli [:Dexter]]

This is handled by bug 1173709.

Comment 3

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=3524770
repository: fx-team
start_time: 2015-06-19T01:25:22
who: tomcat[at]mozilla[dot]com
machine: panda-0142
buildname: Android 4.0 armv7 API 11+ fx-team debug test plain-reftest-2
revision: cfdfff0c6963

PROCESS-CRASH | http://10.26.128.21:30142/tests/layout/reftests/bugs/386401-1.html | application crashed [@ mozalloc_abort]
06-19 02:05:40.812 I/Gecko   ( 2092): [2092] ###!!! ABORT: file /builds/slave/fx-team-and-api-11-d-000000000/build/src/ipc/chromium/src/base/pickle.cc, line 539
06-19 02:05:40.812 E/Gecko   ( 2092): mozalloc_abort: [2092] ###!!! ABORT: file /builds/slave/fx-team-and-api-11-d-000000000/build/src/ipc/chromium/src/base/pickle.cc, line 539
Return code: 1
No tests run or test summary not found
06-19 02:05:40.812 I/Gecko   ( 2092): [2092] ###!!! ABORT: file /builds/slave/fx-team-and-api-11-d-000000000/build/src/ipc/chromium/src/base/pickle.cc, line 539
06-19 02:05:40.812 E/Gecko   ( 2092): mozalloc_abort: [2092] ###!!! ABORT: file /builds/slave/fx-team-and-api-11-d-000000000/build/src/ipc/chromium/src/base/pickle.cc, line 539

Comment 4

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=11024332
repository: mozilla-inbound
start_time: 2015-06-23T00:24:12
who: tomcat[at]mozilla[dot]com
machine: t-w864-ix-125
buildname: Windows 8 64-bit mozilla-inbound pgo test mochitest-other
revision: 733b4adb4140

FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":false,"shutdownBarrier":"Not started","connectionsBarrier":"Not started"},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":690,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:690","resource://gre/modules/TelemetryController.jsm:Impl.observe:78
[Parent 2996] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 690
TEST-UNEXPECTED-FAIL | xpfe/appshell/test/test_hiddenPrivateWindow.xul | application terminated with exit code 1
PROCESS-CRASH | xpfe/appshell/test/test_hiddenPrivateWindow.xul | application crashed [@ mozalloc_abort(char const * const)]
Return code: 1
Return code: 1
Return code: 1

Comment 5

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=11121218
repository: mozilla-inbound
start_time: 2015-06-26T00:09:27
who: tomcat[at]mozilla[dot]com
machine: t-w864-ix-003
buildname: Windows 8 64-bit mozilla-inbound opt test mochitest-other
revision: 331d60f2c42e

FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":false,"shutdownBarrier":"Not started","connectionsBarrier":"Not started"},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":690,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:690","resource://gre/modules/TelemetryController.jsm:Impl.observe:78
[Parent 76] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 690
TEST-UNEXPECTED-FAIL | xpfe/appshell/test/test_hiddenPrivateWindow.xul | application terminated with exit code 1
PROCESS-CRASH | xpfe/appshell/test/test_hiddenPrivateWindow.xul | application crashed [@ mozalloc_abort(char const * const)]
Return code: 1
Return code: 1
Return code: 1

Comment 6

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=3637788
repository: fx-team
start_time: 2015-07-02T23:52:02
who: tomcat[at]mozilla[dot]com
machine: t-xp32-ix-052
buildname: Windows XP 32-bit fx-team opt test mochitest-other
revision: 4b0bbbe52830

FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":false,"shutdownBarrier":"Not started","connectionsBarrier":"Not started"},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":690,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:690","resource://gre/modules/TelemetryController.jsm:Impl.observe:78
[Parent 2404] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 690
TEST-UNEXPECTED-FAIL | xpfe/appshell/test/test_hiddenPrivateWindow.xul | application terminated with exit code 1
PROCESS-CRASH | xpfe/appshell/test/test_hiddenPrivateWindow.xul | application crashed [@ mozalloc_abort(char const * const)]
Return code: 1
Return code: 1
Return code: 1

Comment 7

[David Burns :automatedtester]

[Mass Closure] Closing Intermittent as a one off

Comment 8

[Chris Peterson [:cpeterson]]

I can consistently reproduce this shutdown crash on Firefox 43+ on OS X if I enable the MOZ_CHAOSMODE=0 environment variable (from bug 1182516) when running Firefox from the command line:

  MOZ_CHAOSMODE=0 /Applications/Nightly.app/Contents/MacOS/firefox

FATAL ERROR: AsyncShutdown timeout in profile-before-change2 Conditions: [{"name":"TelemetryController: shutting down","state":{"initialized":true,"initStarted":true,"haveDelayedInitTask":true,"shutdownBarrier":"Not started","connectionsBarrier":"Not started","sendModule":{"sendingEnabled":true,"pendingPingRequestCount":0,"pendingPingActivityCount":0,"unpersistedPingCount":0,"persistedPingCount":96,"schedulerState":{"shutdown":false,"hasSendTask":false,"sendsFailed":false,"sendTaskState":null,"backoffDelay":60000}}},"filename":"resource://gre/modules/TelemetryController.jsm","lineNumber":772,"stack":["resource://gre/modules/TelemetryController.jsm:setupTelemetry:772","resource://gre/modules/TelemetryController.jsm:Impl.observe:868","resource://gre/modules/TelemetryController.jsm:this.TelemetryController<.observe:198","resource://gre/components/TelemetryStartup.js:TelemetryStartup.prototype.observe:30"]}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
[72438] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 772
[72438] ###!!! ABORT: file resource://gre/modules/TelemetryController.jsm, line 772

bp-e7e9e0e3-6e28-4d47-a7e8-8fcc32151124
bp-39a2d3e0-638a-4043-84ef-d9e772151124
bp-2788340c-6139-462d-b7f0-5c65b2151124
bp-cb230ba4-d034-4214-bc33-cdcfb2151124
bp-6a917010-37ac-4187-b1b0-c5fc42151124
bp-b64911a9-e295-4dd9-acc8-8483c2151124
bp-5b1f937e-5c41-4ff1-b203-69ef82151124

Comment 9

[Chris Peterson [:cpeterson]]

STR:
1. Run MOZ_CHAOSMODE=0 /Applications/Nightly.app/Contents/MacOS/firefox
2. Open about:home page!
3. Exit Firefox.

RESULT:
CRASH!

Comment 10

[BMO Automation]

Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.

Comment 11

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1173961&startday=2018-07-09&endday=2018-07-15&tree=trunk