Closed Bug 1580375 Opened 4 months ago Closed 4 months ago

Intermittent org.mozilla.geckoview.test.ContentBlockingControllerTest.importExportExceptions | application crashed [@ mozilla::net::nsSocketTransport::InitiateSocket()]

Categories

(GeckoView :: General, defect, critical)

defect
Not set
critical

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1564920

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(4 keywords)

Crash Data

Attachments

(1 file)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=266034495&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/A7Yih2BBR6CccBlNviEUhQ/runs/0/artifacts/public/logs/live_backing.log


[task 2019-09-11T01:42:12.477Z] 01:42:12 INFO - TEST-START | org.mozilla.geckoview.test.ContentBlockingControllerTest.importExportExceptions
[task 2019-09-11T01:42:13.481Z] 01:42:13 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_RESULT: shortMsg=Process crashed.
[task 2019-09-11T01:42:13.481Z] 01:42:13 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_CODE: 0
[task 2019-09-11T01:42:13.482Z] 01:42:13 INFO - Passed: 0
[task 2019-09-11T01:42:13.482Z] 01:42:13 INFO - Failed: 0
[task 2019-09-11T01:42:13.482Z] 01:42:13 INFO - Todo: 0
[task 2019-09-11T01:42:13.482Z] 01:42:13 INFO - SUITE-END | took 2s
[task 2019-09-11T01:42:13.993Z] 01:42:13 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/be0C7DIlTwq4ojuVnpWUvw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2019-09-11T01:42:17.377Z] 01:42:17 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmpOMV9XP/3db9ddc2-a43a-fed3-9e0e-ee520bcff771.dmp /tmp/tmp0N1d55
[task 2019-09-11T01:42:21.224Z] 01:42:21 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/3db9ddc2-a43a-fed3-9e0e-ee520bcff771.dmp
[task 2019-09-11T01:42:21.224Z] 01:42:21 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/3db9ddc2-a43a-fed3-9e0e-ee520bcff771.extra
[task 2019-09-11T01:42:21.237Z] 01:42:21 WARNING - PROCESS-CRASH | org.mozilla.geckoview.test.ContentBlockingControllerTest.importExportExceptions | application crashed [@ mozilla::net::nsSocketTransport::InitiateSocket()]
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - Crash dump filename: /tmp/tmpOMV9XP/3db9ddc2-a43a-fed3-9e0e-ee520bcff771.dmp
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - Operating system: Android
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - 0.0.0 Linux 3.10.0+ #260 SMP PREEMPT Fri May 19 12:48:14 PDT 2017 x86_64
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - CPU: amd64
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - family 6 model 6 stepping 3
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - 4 CPUs
[task 2019-09-11T01:42:21.237Z] 01:42:21 INFO - GPU: UNKNOWN
[task 2019-09-11T01:42:21.238Z] 01:42:21 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-09-11T01:42:21.238Z] 01:42:21 INFO - Crash address: 0x0
[task 2019-09-11T01:42:21.238Z] 01:42:21 INFO - Process uptime: not available
[task 2019-09-11T01:42:21.238Z] 01:42:21 INFO - Thread 29 (crashed)
[task 2019-09-11T01:42:21.238Z] 01:42:21 INFO - 0 libxul.so!mozilla::net::nsSocketTransport::InitiateSocket() [nsSocketTransport2.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 1285 + 0x11]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rax = 0x00007cc1d722434e rdx = 0x0000000000000004
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rcx = 0x00007cc1d9ef84c8 rbx = 0x00007cc1da25f508
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsi = 0x00007cc1da25ebe0 rdi = 0x000000000000001b
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbp = 0x00007cc1da25f620 rsp = 0x00007cc1da25f2a0
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r8 = 0x0000000000000000 r9 = 0x00007cc1f767a090
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r10 = 0x00000000ffffff00 r11 = 0x0000000000000246
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r12 = 0x00007cc1d99c8c00 r13 = 0x00007cc1d99c8c00
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r14 = 0x0000000080004004 r15 = 0x0000000000000000
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rip = 0x00007cc1d3b281cf
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: given as instruction pointer in context
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - 1 libxul.so!mozilla::net::nsSocketEvent::Run() [nsSocketTransport2.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 92 + 0x389]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbx = 0x0000000000000001 rbp = 0x00007cc1da25f6f0
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsp = 0x00007cc1da25f630 r12 = 0x00007cc1cb813a80
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r13 = 0x00007cc1d99c8c00 r14 = 0x0000000000000000
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r15 = 0x0000000000000000 rip = 0x00007cc1d3b390b6
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - 2 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 1225 + 0xa]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbx = 0x00007cc1da25f758 rbp = 0x00007cc1da25fc30
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsp = 0x00007cc1da25f700 r12 = 0x00007cc1cb813a80
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r13 = 0x0000000000000002 r14 = 0x00000000ffffffff
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r15 = 0x00007cc1d9954740 rip = 0x00007cc1d3a8d96f
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - 3 libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 486 + 0x10]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbx = 0x00007cc1da25fc4f rbp = 0x00007cc1da25fc60
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsp = 0x00007cc1da25fc40 r12 = 0x0000000000000000
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r13 = 0x00007cc1d9429b50 r14 = 0x00007cc1d9938280
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r15 = 0x0000000000000003 rip = 0x00007cc1d3a8ee77
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - 4 libxul.so!mozilla::net::nsSocketTransportService::Run() [nsSocketTransportService2.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 1011 + 0xf]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbx = 0x00007cc1da25fce7 rbp = 0x00007cc1da25fd50
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsp = 0x00007cc1da25fc70 r12 = 0x0000000000000000
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r13 = 0x00007cc1d9429b50 r14 = 0x00007cc1d9938280
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r15 = 0x0000000000000003 rip = 0x00007cc1d3b2d2e1
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - 5 libxul.so!non-virtual thunk to mozilla::net::nsSocketTransportService::Run() [nsSocketTransportService2.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 0 + 0xd]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbx = 0x00007cc1da25fdc8 rbp = 0x00007cc1da25fd60
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsp = 0x00007cc1da25fd60 r12 = 0x00007cc1d99382a0
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r15 = 0x00007cc1d9954740 rip = 0x00007cc1d3b2d665
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - 6 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 1225 + 0xa]
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rbx = 0x00007cc1da25fdc8 rbp = 0x00007cc1da2602a0
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - rsp = 0x00007cc1da25fd70 r12 = 0x00007cc1d99382a0
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - r15 = 0x00007cc1d9954740 rip = 0x00007cc1d3a8d96f
[task 2019-09-11T01:42:21.240Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - 7 libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 486 + 0x10]
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - rbx = 0x00007cc1da2602bf rbp = 0x00007cc1da2602d0
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - rsp = 0x00007cc1da2602b0 r12 = 0x00007cc1da2604f8
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - r13 = 0x0000000000000000 r14 = 0x00007cc1cf319580
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - r15 = 0x00007cc1d9954740 rip = 0x00007cc1d3a8ee77
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - 8 libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 303 + 0xa]
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - rbx = 0x00007cc1d997c1c0 rbp = 0x00007cc1da260310
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - rsp = 0x00007cc1da2602e0 r12 = 0x00007cc1da2604f8
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - r13 = 0x0000000000000000 r14 = 0x00007cc1cf319580
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - r15 = 0x00007cc1d9954740 rip = 0x00007cc1d3e111b3
[task 2019-09-11T01:42:21.241Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - 9 libxul.so!MessageLoop::Run() [message_loop.cc:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 290 + 0xc]
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - rbx = 0x00007cc1da260328 rbp = 0x00007cc1da260350
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - rsp = 0x00007cc1da260320 r12 = 0x00007cc1da2604f8
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - r13 = 0x0000000000000000 r14 = 0x00007cc1d997c1c0
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - r15 = 0x00007cc1d99d40a0 rip = 0x00007cc1d3de435b
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - 10 libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 458 + 0x8]
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - rbx = 0x00007cc1d9954740 rbp = 0x00007cc1da2603a0
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - rsp = 0x00007cc1da260360 r12 = 0x00007cc1da2604f8
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - r13 = 0x0000000000000000 r14 = 0x00007cc1d997c1c0
[task 2019-09-11T01:42:21.242Z] 01:42:21 INFO - r15 = 0x00007cc1d99d40a0 rip = 0x00007cc1d3a8c094
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - 11 libnss3.so!_pt_root [ptthread.c:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 198 + 0x7]
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - rbx = 0x00007cc1d994b9b0 rbp = 0x00007cc1da2603e0
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - rsp = 0x00007cc1da2603b0 r12 = 0x00007cc1da2604f8
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - r13 = 0x0000000000000000 r14 = 0x00007cc1da260450
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - r15 = 0x0000000000000b06 rip = 0x00007cc1d95f8ab8
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - 12 libc.so + 0x89772
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - rbx = 0x00007cc1da2604d0 rbp = 0x0000000000000ae2
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - rsp = 0x00007cc1da2603f0 r12 = 0x00007cc1da260450
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - r13 = 0x00007cc1d95f89c5 r14 = 0x00007cc1da260450
[task 2019-09-11T01:42:21.243Z] 01:42:21 INFO - r15 = 0x00007cc1da2604e8 rip = 0x00007cc1f5934772
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - Found by: call frame info
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - 13 libnss3.so!pt_recvfrom_cont [ptio.c:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 0 + 0x5]
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - rsp = 0x00007cc1da260428 rip = 0x00007cc1d95f89c5
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - Found by: stack scanning
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - 14 libc.so + 0x299ec
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - rsp = 0x00007cc1da260440 rip = 0x00007cc1f58d49ec
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - Found by: stack scanning
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - 15 libc.so + 0x896c0
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - rsp = 0x00007cc1da260448 rip = 0x00007cc1f59346c0
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - Found by: stack scanning
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - 16 libc.so + 0x1ca66
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - rsp = 0x00007cc1da260450 rip = 0x00007cc1f58c7a66
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - Found by: stack scanning
[task 2019-09-11T01:42:21.244Z] 01:42:21 INFO - 17 libnss3.so!pt_recvfrom_cont [ptio.c:2bddf3f650f5954c6752917a6d4ad5acb55bd3e6 : 0 + 0x5]
[task 2019-09-11T01:42:21.245Z] 01:42:21 INFO - rsp = 0x00007cc1da2604b8 rip = 0x00007cc1d95f89c5
[task 2019-09-11T01:42:21.245Z] 01:42:21 INFO - Found by: stack scanning

Component: geckodriver → General
Product: Testing → GeckoView
Version: Version 3 → unspecified
Component: General → Networking
Product: GeckoView → Core

Hi Dylan,

It seems the crash happens in this test
The reason for the crash is that Firefox attempts to create a socket to a non-local domain as defined in server-locations.txt.
It's not clear from the crash what the domain is, and I don't understand how the test works. Can you take a look?

Flags: needinfo?(droeh)
Regressed by: 1557009

If the reason of the crash is the test accessing non-local addresses, then we should move the bug back into the GV product.

Component: Networking → General
Product: Core → GeckoView

(In reply to Valentin Gosu [:valentin] (he/him) from comment #1)

Hi Dylan,

It seems the crash happens in this test
The reason for the crash is that Firefox attempts to create a socket to a non-local domain as defined in server-locations.txt.
It's not clear from the crash what the domain is, and I don't understand how the test works. Can you take a look?

I have no idea why this would be attempting to create a socket to a non-local domain. All it does is load this test page: https://searchfox.org/mozilla-central/source/mobile/android/geckoview/src/androidTest/assets/www/trackers.html (which includes resources from domains that should be available) and then add and remove tracking exceptions (which should not involve network access at all).

Edit: To be clear, we've used that test page in other tests for over a year without any issue I'm aware of.

Flags: needinfo?(droeh)

The reason is printed to stderr - I just didn't know where that was 🙂
https://taskcluster-artifacts.net/SnPfdXrkQt6BswShLl-fGw/0/public/test_info//logcat-emulator-5554.log

09-11 11:55:36.716  2795  2820 E GeckoConsole: [JavaScript Error: "undefined"]
09-11 11:55:36.735  2795  2831 I Gecko   : FATAL ERROR: Non-local network connections are disabled and a connection attempt to shavar.services.mozilla.com (35.164.3.68) was made.
09-11 11:55:36.735  2795  2831 I Gecko   : You should only access hostnames available via the test networking proxy (if running mochitests) or from a test-specific httpd.js server (if running xpcshell tests). Browser services should be disabled or redirected to a local server.
09-11 11:55:36.739  2795  2831 W google-breakpad: ExceptionHandler::GenerateDump cloned child 
09-11 11:55:36.739  2795  2831 W google-breakpad: 2865

So it seems the problem is with shavar.services.mozilla.com
I guess we should disable those update services in tests?

(In reply to Valentin Gosu [:valentin] (he/him) from comment #4)

The reason is printed to stderr - I just didn't know where that was 🙂
https://taskcluster-artifacts.net/SnPfdXrkQt6BswShLl-fGw/0/public/test_info//logcat-emulator-5554.log

09-11 11:55:36.716  2795  2820 E GeckoConsole: [JavaScript Error: "undefined"]
09-11 11:55:36.735  2795  2831 I Gecko   : FATAL ERROR: Non-local network connections are disabled and a connection attempt to shavar.services.mozilla.com (35.164.3.68) was made.
09-11 11:55:36.735  2795  2831 I Gecko   : You should only access hostnames available via the test networking proxy (if running mochitests) or from a test-specific httpd.js server (if running xpcshell tests). Browser services should be disabled or redirected to a local server.
09-11 11:55:36.739  2795  2831 W google-breakpad: ExceptionHandler::GenerateDump cloned child 
09-11 11:55:36.739  2795  2831 W google-breakpad: 2865

So it seems the problem is with shavar.services.mozilla.com
I guess we should disable those update services in tests?

Yeah, this looks like Gecko is trying to update tracking protection lists. We already set some prefs that should prevent this, though: https://searchfox.org/mozilla-central/source/testing/profiles/unittest-required/user.js#45 -- I'll put up a patch today or Monday to try and log some more info.

Pushed by droeh@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/426128a9c71b
Add more logging to content blocking exception test. r=snorp

dupe of InitiateSocket bug 1564920 where another test tries to connect to Safe Browsing server.

Is this a GV bug or a test runner problem?

Status: NEW → RESOLVED
Closed: 4 months ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1564920
You need to log in before you can comment on or make changes to this bug.