1648189 - [socket process] Perma Assertion failure: tqParent, at /builds/worker/checkouts/gecko/netwerk/protocol/http/HttpTransactionParent.cpp:173

Status: VERIFIED FIXED

(Core :: Networking, defect, P1)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=307371348&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KZ6c11rHTpGTx2I1PTEnnA/runs/0/artifacts/public/logs/live_backing.log

---

This failed 2/2 runs with socket process enabled in today's central-as-beta simulation.

central-as-beta simulation: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=d6b247f3ddd28ecd069b7c3144fbb494401c21cf&selectedTaskRun=KZ6c11rHTpGTx2I1PTEnnA.0

[task 2020-06-24T12:38:14.700Z] 12:38:14 WARNING - TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_throttling.js | xpcshell return code: -11
[task 2020-06-24T12:38:14.700Z] 12:38:14 INFO - TEST-INFO took 375ms
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - >>>>>>>
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [29782, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp, line 2924
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [29782, Main Thread] WARNING: Couldn't get the user appdata directory, crash dumps will go in an unusual location: file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp, line 2984
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [29782, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002 (NS_NOINTERFACE): file /builds/worker/checkouts/gecko/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 673
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [29796, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [29796, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [Socket 29796, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002 (NS_NOINTERFACE): file /builds/worker/checkouts/gecko/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 673
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - (xpcshell/head.js) | test pending (2)
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - running event loop
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | [29782, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp, line 379
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2020-06-24T12:38:14.702Z] 12:38:14 INFO - PID 29782 | Assertion failure: tqParent, at /builds/worker/checkouts/gecko/netwerk/protocol/http/HttpTransactionParent.cpp:173
[task 2020-06-24T12:38:14.717Z] 12:38:14 INFO - Initializing stack-fixing for the first stack frame, this may take a while...
[task 2020-06-24T12:38:23.481Z] 12:38:23 INFO - PID 29782 | #01: non-virtual thunk to mozilla::net::HttpTransactionParent::Init(unsigned int, mozilla::net::nsHttpConnectionInfo*, mozilla::net::nsHttpRequestHead*, nsIInputStream*, unsigned long, bool, nsIEventTarget*, nsIInterfaceRequestor*, nsITransportEventSink*, unsigned long, mozilla::net::HttpTrafficCategory, nsIRequestContext*, unsigned int, unsigned int, bool, unsigned long, std::function<void (mozilla::net::TransactionObserverResult&&)>&&, std::function<nsresult (unsigned int, nsTSubstring<char> const&, nsTSubstring<char> const&, mozilla::net::HttpTransactionShell*)>&&, mozilla::net::HttpTransactionShell*, unsigned int) [netwerk/protocol/http/HttpTransactionParent.cpp:0]
[task 2020-06-24T12:38:23.482Z] 12:38:23 INFO - PID 29782 | #02: mozilla::net::nsHttpChannel::SetupTransaction() [netwerk/protocol/http/nsHttpChannel.cpp:1425]
[task 2020-06-24T12:38:23.483Z] 12:38:23 INFO - PID 29782 | #03: mozilla::net::nsHttpChannel::DoConnectActual(mozilla::net::HttpTransactionShell*) [netwerk/protocol/http/nsHttpChannel.cpp:944]
[task 2020-06-24T12:38:23.484Z] 12:38:23 INFO - PID 29782 | #04: mozilla::net::nsHttpChannel::DoConnect(mozilla::net::HttpTransactionShell*) [netwerk/protocol/http/nsHttpChannel.cpp:935]
[task 2020-06-24T12:38:23.484Z] 12:38:23 INFO - PID 29782 | #05: mozilla::net::nsHttpChannel::ContinueConnect() [netwerk/protocol/http/nsHttpChannel.cpp:0]
[task 2020-06-24T12:38:23.485Z] 12:38:23 INFO - PID 29782 | #06: mozilla::net::nsHttpChannel::OnCacheEntryAvailable(nsICacheEntry*, bool, nsIApplicationCache*, nsresult) [netwerk/protocol/http/nsHttpChannel.cpp:4650]
[task 2020-06-24T12:38:23.485Z] 12:38:23 INFO - PID 29782 | #07: non-virtual thunk to mozilla::net::nsHttpChannel::OnCacheEntryAvailable(nsICacheEntry*, bool, nsIApplicationCache*, nsresult) [netwerk/protocol/http/nsHttpChannel.cpp:0]
[task 2020-06-24T12:38:23.486Z] 12:38:23 INFO - PID 29782 | #08: mozilla::net::CacheEntry::InvokeAvailableCallback(mozilla::net::CacheEntry::Callback const&) [netwerk/cache2/CacheEntry.cpp:888]
[task 2020-06-24T12:38:23.486Z] 12:38:23 INFO - PID 29782 | #09: mozilla::net::CacheEntry::AvailableCallbackRunnable::Run() [netwerk/cache2/CacheEntry.h:229]
[task 2020-06-24T12:38:23.487Z] 12:38:23 INFO - PID 29782 | #10: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1234]
[task 2020-06-24T12:38:23.488Z] 12:38:23 INFO - PID 29782 | #11: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:501]
[task 2020-06-24T12:38:23.488Z] 12:38:23 INFO - PID 29782 | #12: nsThreadManager::SpinEventLoopUntilInternal(nsINestedEventLoopCondition*, bool) [xpcom/threads/nsThreadManager.cpp:696]
[task 2020-06-24T12:38:23.489Z] 12:38:23 INFO - PID 29782 | #13: ??? [/builds/worker/workspace/build/application/firefox/libxul.so + 0x10423ae]
[task 2020-06-24T12:38:23.489Z] 12:38:23 INFO - PID 29782 | #14: CallMethodHelper::Call() [js/xpconnect/src/XPCWrappedNative.cpp:1174]
[task 2020-06-24T12:38:23.490Z] 12:38:23 INFO - PID 29782 | #15: XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1140]
[task 2020-06-24T12:38:23.491Z] 12:38:23 INFO - PID 29782 | #16: XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:946]
[task 2020-06-24T12:38:23.491Z] 12:38:23 INFO - PID 29782 | #17: CallJSNative(JSContext*, bool ()(JSContext, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) [js/src/vm/Interpreter.cpp:484]
[task 2020-06-24T12:38:23.492Z] 12:38:23 INFO - PID 29782 | #18: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [js/src/vm/Interpreter.cpp:576]
[task 2020-06-24T12:38:23.492Z] 12:38:23 INFO - PID 29782 | #19: InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) [js/src/vm/Interpreter.cpp:639]
[task 2020-06-24T12:38:23.493Z] 12:38:23 INFO - PID 29782 | #20: Interpret(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:0]
[task 2020-06-24T12:38:23.493Z] 12:38:23 INFO - PID 29782 | #21: js::RunScript(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:456]
[task 2020-06-24T12:38:23.494Z] 12:38:23 INFO - PID 29782 | #22: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [js/src/vm/Interpreter.cpp:611]
[task 2020-06-24T12:38:23.495Z] 12:38:23 INFO - PID 29782 | #23: InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) [js/src/vm/Interpreter.cpp:639]
[task 2020-06-24T12:38:23.496Z] 12:38:23 INFO - PID 29782 | #24: js::jit::DoCallFallback(JSContext*, js::jit::BaselineFrame*, js::jit::ICCall_Fallback*, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) [js/src/jit/BaselineIC.cpp:2992]
[task 2020-06-24T12:38:23.497Z] 12:38:23 INFO - PID 29782 | #25: ??? (???:???)
[task 2020-06-24T12:38:23.498Z] 12:38:23 INFO - PID 29782 | ExceptionHandler::GenerateDump cloned child 29809
[task 2020-06-24T12:38:23.499Z] 12:38:23 INFO - PID 29782 | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2020-06-24T12:38:23.499Z] 12:38:23 INFO - PID 29782 | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2020-06-24T12:38:23.500Z] 12:38:23 INFO - PID 29782 | [Socket 29796, Main Thread] WARNING: Shutting down Socket process early due to a crash!: file /builds/worker/checkouts/gecko/netwerk/ipc/SocketProcessChild.cpp, line 155
[task 2020-06-24T12:38:23.501Z] 12:38:23 INFO - <<<<<<<

Comment 1

[Kershaw Chang [:kershaw]]

Here is what happened.

1. On beta, socket process is disabled, so the default value of network.process.enabled is false.
2. We turn on network.process.enabled for socket process tests by adding --setpref=network.process.enabled=true.
3. The return value from first call to nsIOService::UseSocketProcess is false, since the default value of network.process.enabled is false.
4. The value of network.process.enabled becomes true when the profile is loaded.
5. The return value from nsIOService::UseSocketProcess is true now and we start to hit some assertions.

Comment 2

[Kershaw Chang [:kershaw]]

Attachment: Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false, r=dragana

Comment 3

[Cosmin Sabou [:CosminS]]

Patch is working in today's beta-sim: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=success%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&author=nbeleuzu%40mozilla.com&fromchange=80a5e10445b7fd7a3a3fe65f14623525f69a86e8&searchStr=spi%2Cxpc&selectedTaskRun=YSmZFJ1oRamqzpYNkIWQQw.0

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/6e0936ea7f4a
Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false, r=dragana

Comment 5

[Dorel Luca [:dluca]]

Backed out changeset 6e0936ea7f4a (bug 1648189) on dev's request, for causing mda failures on beta sims. CLOSED TREE

Log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=307649938&repo=try&lineNumber=3006

https://treeherder.mozilla.org/logviewer.html#?job_id=307650464&repo=try

https://treeherder.mozilla.org/logviewer.html#?job_id=307648150&repo=try

Early beta TH:
https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=e5d8910c8aa088b99e85b317f07bd6703f2f2e30&selectedTaskRun=DtpI0JzxSay9l4TCeoy7oQ.0

Backout:
https://hg.mozilla.org/integration/autoland/rev/785599d7c456a29f7b14eada9b6b668c0b1f4727

Comment 6

[Kershaw Chang [:kershaw]]

Thanks for backing this out.

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d71ade0fc9da
Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false, r=dragana

Comment 8

[Noemi Erli[:noemi_erli]]

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

Comment 9

[Natalia Csoregi [:nataliaCs]]

No new occurrences in today's beta-sim: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception%2Crunnable&revision=f8439875f0c6f251ee23c04f5b9547e93722a4c3

Comment 10

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform breakdown:

• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1648189&startday=2020-06-22&endday=2020-06-28&tree=all