Closed Bug 1648189 Opened 3 months ago Closed 3 months ago

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

Categories

(Core :: Networking, defect, P1)

defect

Tracking

()

VERIFIED FIXED
mozilla79
Tracking Status
firefox-esr68 --- unaffected
firefox-esr78 --- unaffected
firefox77 --- unaffected
firefox78 --- unaffected
firefox79 + verified

People

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

Details

(Keywords: assertion, Whiteboard: [necko-triaged])

Attachments

(1 file)

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 - <<<<<<<

Assignee: nobody → kershaw
Severity: normal → N/A
Priority: P5 → P1
Whiteboard: [necko-triaged]

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.
Attachment #9159183 - Attachment description: Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false → Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false, r=dragana
Pushed by kjang@mozilla.com:
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

Thanks for backing this out.

Flags: needinfo?(kershaw)
Attachment #9159183 - Attachment description: Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false, r=dragana → Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false
Attachment #9159183 - Attachment description: Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false → Bug 1648189 - Make sure MOZ_FORCE_USE_SOCKET_PROCESS is working when network.process.enabled is false, r=dragana
Pushed by kjang@mozilla.com:
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
Status: NEW → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla79
You need to log in before you can comment on or make changes to this bug.