Closed Bug 1554093 Opened 6 years ago Closed 2 years ago

Intermittent netwerk/test/unit/test_proxyconnect.js | application crashed [@ mozilla::net::nsHttpConnection::OnOutputStreamReady]

Categories

(Core :: Networking: HTTP, defect, P5)

Product:
Core
Component:
Networking: HTTP
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: crash, intermittent-failure, regression, Whiteboard: [necko-triaged])

Crash Data

Filed by: opoprus [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=248121371&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/e7ojQzC9RB6s6nqBFrggfQ/runs/0/artifacts/public/logs/live_backing.log

[task 2019-05-24T04:43:38.007Z] 04:43:38 INFO - TEST-PASS | netwerk/test/unit/test_proxyconnect.js | dataAvailable - [dataAvailable : 149] alpn header found - 187 != -1
[task 2019-05-24T04:43:38.007Z] 04:43:38 INFO - netwerk/test/unit/test_proxyconnect.js | [2929, Main Thread] WARNING: NS_ENSURE_TRUE(mSecurityInfo) failed: file /builds/worker/workspace/build/src/netwerk/protocol/http/nsHttpChannel.cpp, line 2188
[task 2019-05-24T04:43:38.007Z] 04:43:38 INFO - netwerk/test/unit/test_proxyconnect.js | Segmentation fault
[task 2019-05-24T04:43:38.007Z] 04:43:38 INFO - <<<<<<<
[task 2019-05-24T04:43:38.313Z] 04:43:38 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmp4e_lnF/7af2dff3-e25e-da4b-8c7b-70511bc83b3b.dmp /builds/worker/workspace/build/symbols
[task 2019-05-24T04:43:43.370Z] 04:43:43 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/7af2dff3-e25e-da4b-8c7b-70511bc83b3b.dmp
[task 2019-05-24T04:43:43.370Z] 04:43:43 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/7af2dff3-e25e-da4b-8c7b-70511bc83b3b.extra
[task 2019-05-24T04:43:43.371Z] 04:43:43 WARNING - PROCESS-CRASH | netwerk/test/unit/test_proxyconnect.js | application crashed [@ mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*)]
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - Crash dump filename: /tmp/tmp4e_lnF/7af2dff3-e25e-da4b-8c7b-70511bc83b3b.dmp
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - Operating system: Android
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - 0.0.0 Linux 3.10.0+ #1 PREEMPT Thu Jan 5 00:46:30 UTC 2017 x86_64
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - CPU: amd64
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - family 6 model 2 stepping 3
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - 1 CPU
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - GPU: UNKNOWN
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-05-24T04:43:43.371Z] 04:43:43 INFO - Crash address: 0x0
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - Process uptime: not available
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - Thread 5 (crashed)
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - 0 libxul.so!mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*) [nsHttpConnection.cpp:c87317c4190283cc4352331417babef3d3f9546d : 2457 + 0x29]
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - rax = 0x0000799162932c95 rdx = 0x0000000000000004
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - rcx = 0x0000799168253a88 rbx = 0x00007991579c0c00
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - rsi = 0x0000799169d12460 rdi = 0x0000000000000003
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - rbp = 0x0000799169d12b20 rsp = 0x0000799169d12b10
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - r8 = 0x0000000000000000 r9 = 0x0000799169dc5090
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - r10 = 0x00000000ffffff00 r11 = 0x0000000000000246
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - r12 = 0x000079915c82e018 r13 = 0x0000000000000018
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - r14 = 0x00007991579bf2c8 r15 = 0x0000799169d12b40
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - rip = 0x000079915dfde2c7
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - Found by: given as instruction pointer in context
[task 2019-05-24T04:43:43.372Z] 04:43:43 INFO - 1 libxul.so!non-virtual thunk to mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*) [nsHttpConnection.cpp:c87317c4190283cc4352331417babef3d3f9546d : 0 + 0xd]
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - rbx = 0x00007991579bf2c8 rbp = 0x0000799169d12b30
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - rsp = 0x0000799169d12b30 r12 = 0x000079915c82e018
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - r13 = 0x0000000000000018 r14 = 0x0000799169d12b40
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - r15 = 0x0000799169d12b40 rip = 0x000079915dfe228b
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - 2 libxul.so!mozilla::net::nsSocketOutputStream::OnSocketReady(nsresult) [nsSocketTransport2.cpp:c87317c4190283cc4352331417babef3d3f9546d : 516 + 0x11]
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - rbx = 0x00007991579bf2c8 rbp = 0x0000799169d12b80
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - rsp = 0x0000799169d12b40 r12 = 0x000079915c82e018
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - r13 = 0x0000000000000018 r14 = 0x0000799169d12b40
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - r15 = 0x0000799169d12b40 rip = 0x000079915dd3a945
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - 3 libxul.so!mozilla::net::nsSocketTransport::OnSocketReady(PRFileDesc*, short) [nsSocketTransport2.cpp:c87317c4190283cc4352331417babef3d3f9546d : 2243 + 0xe]
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - rbx = 0x0000000000000002 rbp = 0x0000799169d12bb0
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - rsp = 0x0000799169d12b90 r12 = 0x000079915c82e018
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - r13 = 0x0000000000000018 r14 = 0x00007991579bf000
[task 2019-05-24T04:43:43.373Z] 04:43:43 INFO - r15 = 0x00007991579b99d0 rip = 0x000079915dd3f33f
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - 4 libxul.so!mozilla::net::nsSocketTransportService::DoPollIteration(mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>) [nsSocketTransportService2.cpp:c87317c4190283cc4352331417babef3d3f9546d : 0 + 0x3]
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - rbx = 0x000079915c82e000 rbp = 0x0000799169d12c40
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - rsp = 0x0000799169d12bc0 r12 = 0x000079915c82e018
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - r13 = 0x0000000000000018 r14 = 0x000000000000002a
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - r15 = 0x000079915c895c00 rip = 0x000079915dd44ff9
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - 5 libxul.so!mozilla::net::nsSocketTransportService::Run() [nsSocketTransportService2.cpp:c87317c4190283cc4352331417babef3d3f9546d : 973 + 0xb]
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - rbx = 0x000079915c8a5190 rbp = 0x0000799169d12d00
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - rsp = 0x0000799169d12c50 r12 = 0x0000799169d12cc0
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - r13 = 0x0000000000000000 r14 = 0x0000799169d12ca8
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - r15 = 0x0000000000000000 rip = 0x000079915dd448cd
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - 6 libxul.so!non-virtual thunk to mozilla::net::nsSocketTransportService::Run() [nsSocketTransportService2.cpp:c87317c4190283cc4352331417babef3d3f9546d : 0 + 0xd]
[task 2019-05-24T04:43:43.374Z] 04:43:43 INFO - rbx = 0x0000799169d12d80 rbp = 0x0000799169d12d10
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - rsp = 0x0000799169d12d10 r12 = 0x0000799169d12d68
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - r13 = 0x000079915c8a31d8 r14 = 0x000079915c8a3120
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - r15 = 0x0000799169d12e08 rip = 0x000079915dd45305
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - 7 libxul.so!nsThread::ProcessNextEvent(bool, bool) [nsThread.cpp:c87317c4190283cc4352331417babef3d3f9546d : 1176 + 0x11]
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - rbx = 0x0000799169d12d80 rbp = 0x0000799169d13240
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - rsp = 0x0000799169d12d20 r12 = 0x0000799169d12d68
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - r13 = 0x000079915c8a31d8 r14 = 0x000079915c8a3120
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - r15 = 0x0000799169d12e08 rip = 0x000079915dc55bf1
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - 8 libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:c87317c4190283cc4352331417babef3d3f9546d : 486 + 0x14]
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - rbx = 0x000079915c8a3120 rbp = 0x0000799169d13270
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - rsp = 0x0000799169d13250 r12 = 0x0000000000000000
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - r13 = 0x000079915c8fe6e0 r14 = 0x0000799169d13257
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - r15 = 0x000079915c8a3120 rip = 0x000079915dc58051
[task 2019-05-24T04:43:43.375Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - 9 libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:c87317c4190283cc4352331417babef3d3f9546d : 333 + 0xb]
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - rbx = 0x000079915c89d680 rbp = 0x0000799169d132c0
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - rsp = 0x0000799169d13280 r12 = 0x0000000000000000
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - r13 = 0x000079915c8fe6e0 r14 = 0x000079915c8fe6c0
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - r15 = 0x000079915c8a3120 rip = 0x000079915e0f0fc8
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - 10 libxul.so!MessageLoop::RunInternal() [message_loop.cc:c87317c4190283cc4352331417babef3d3f9546d : 315 + 0x17]
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - rbx = 0x000079915c89d680 rbp = 0x0000799169d13300
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - rsp = 0x0000799169d132d0 r12 = 0x000079915c8a3120
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - r13 = 0x0000799169d13358 r14 = 0x0000799169d13310
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - r15 = 0x0000799169d13368 rip = 0x000079915e0aee94
[task 2019-05-24T04:43:43.376Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - 11 libxul.so!MessageLoop::Run() [message_loop.cc:c87317c4190283cc4352331417babef3d3f9546d : 290 + 0x8]
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - rbx = 0x000079915c89d680 rbp = 0x0000799169d13340
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - rsp = 0x0000799169d13310 r12 = 0x000079915c8a3120
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - r13 = 0x0000799169d13358 r14 = 0x0000799169d13310
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - r15 = 0x0000799169d13368 rip = 0x000079915e0aedfe
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - 12 libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:c87317c4190283cc4352331417babef3d3f9546d : 455 + 0xd]
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - rbx = 0x000079915c89d680 rbp = 0x0000799169d133a0
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - rsp = 0x0000799169d13350 r12 = 0x000079915c8a3120
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - r13 = 0x0000799169d13358 r14 = 0x000079915c8a3160
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - r15 = 0x0000799169d13368 rip = 0x000079915dc53937
[task 2019-05-24T04:43:43.377Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - 13 libnss3.so!_pt_root [ptthread.c:c87317c4190283cc4352331417babef3d3f9546d : 201 + 0xa]
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - rbx = 0x0000799169d134f8 rbp = 0x0000799169d133e0
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - rsp = 0x0000799169d133b0 r12 = 0x000079915c821570
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000b77
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - r15 = 0x0000000000000002 rip = 0x0000799165e68bb2
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - 14 libc.so + 0x89772
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - rbx = 0x0000799169d134d0 rbp = 0x0000000000000b71
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - rsp = 0x0000799169d133f0 r12 = 0x0000799169d13450
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - r13 = 0x0000799165e68a5d r14 = 0x0000799169d13450
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - r15 = 0x0000799169d134e8 rip = 0x0000799168c02772
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - Found by: call frame info
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - 15 libnss3.so!pt_recvfrom_cont [ptio.c:c87317c4190283cc4352331417babef3d3f9546d : 0 + 0x5]
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - rsp = 0x0000799169d13428 rip = 0x0000799165e68a5d
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - Found by: stack scanning
[task 2019-05-24T04:43:43.378Z] 04:43:43 INFO - 16 libc.so + 0x299ec
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - rsp = 0x0000799169d13440 rip = 0x0000799168ba29ec
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - Found by: stack scanning
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - 17 libc.so + 0x896c0
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - rsp = 0x0000799169d13448 rip = 0x0000799168c026c0
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - Found by: stack scanning
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - 18 libc.so + 0x1ca66
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - rsp = 0x0000799169d13450 rip = 0x0000799168b95a66
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - Found by: stack scanning
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - 19 libnss3.so!pt_recvfrom_cont [ptio.c:c87317c4190283cc4352331417babef3d3f9546d : 0 + 0x5]
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - rsp = 0x0000799169d134b8 rip = 0x0000799165e68a5d
[task 2019-05-24T04:43:43.379Z] 04:43:43 INFO - Found by: stack scanning

Honza, can you take a look if this is important for the proxy project?

Flags: needinfo?(honzab.moz)

Failing at [1]. As the caller nsSocketTransport2.cpp - mozsearch checks the callback for being non-null I bet we mismatch the sockets. These crashes are android only, which may report assertion failures as simple null dereferences. I have to verify that.

I'm --verifying the test on my android device, but I don't expect to be able to reproduce.

Based on this being only an assertion failure and having a very low crash rate, I don't think that this is necessary to be fixed for the secure proxy.

[1] https://hg.mozilla.org/mozilla-central/file/c87317c4190283cc4352331417babef3d3f9546d/netwerk/protocol/http/nsHttpConnection.cpp#l2457

Flags: needinfo?(honzab.moz)
Priority: -- → P5
Whiteboard: [necko-triaged]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=391209891&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Severity: critical → S2

Since the crash volume is low (less than 5 per week), the severity is downgraded to S3. Feel free to change it back if you think the bug is still critical.

For more information, please visit auto_nag documentation.

Severity: S2 → S3

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 3 years ago → 3 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=402850425&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 3 years ago → 3 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=408239947&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Crash Signature: [@ mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*)] → [@ mozilla::net::nsHttpConnection::OnOutputStreamReady]
Summary: Intermittent netwerk/test/unit/test_proxyconnect.js | application crashed [@ mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*)] → Intermittent netwerk/test/unit/test_proxyconnect.js | application crashed [@ mozilla::net::nsHttpConnection::OnOutputStreamReady]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 3 years ago → 2 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.