Closed Bug 1631140 Opened 4 years ago Closed 4 years ago

Intermittent GECKO(1303) | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/ipc/chromium/src/third_party/libevent/signal.c:125:16 in evsig_set_base_ | application terminated with exit code -6

Categories

(Firefox :: Session Restore, defect, P5)

Product:
Firefox
Component:
Session Restore
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1616462

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: shindli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=298168172&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/A0zH-qjbSH-0jYmSxWmHKw/runs/0/artifacts/public/logs/live_backing.log

[task 2020-04-17T22:08:54.044Z] 22:08:54 INFO - SimpleTest FINISHED
[task 2020-04-17T22:08:56.651Z] 22:08:56 INFO - GECKO(1303) | ==================
[task 2020-04-17T22:08:56.652Z] 22:08:56 INFO - GECKO(1303) | WARNING: ThreadSanitizer: data race (pid=1303)
[task 2020-04-17T22:08:56.652Z] 22:08:56 INFO - GECKO(1303) | Write of size 4 at 0x7f9afbe840d8 by thread T4:
[task 2020-04-17T22:08:56.653Z] 22:08:56 INFO - GECKO(1303) | #0 evsig_set_base_ /builds/worker/checkouts/gecko/ipc/chromium/src/third_party/libevent/signal.c:125:16 (libxul.so+0x131ce0f)
[task 2020-04-17T22:08:56.653Z] 22:08:56 INFO - GECKO(1303) | #1 event_base_loop /builds/worker/checkouts/gecko/ipc/chromium/src/third_party/libevent/event.c:1901:3 (libxul.so+0x1315b84)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | #2 base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_pump_libevent.cc (libxul.so+0x12f67f9)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | #3 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:315:10 (libxul.so+0x12f3b3c)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | #4 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:308:3 (libxul.so+0x12f3b3c)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | #5 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:290:3 (libxul.so+0x12f3b3c)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | #6 base::Thread::ThreadMain() /builds/worker/checkouts/gecko/ipc/chromium/src/base/thread.cc:192:16 (libxul.so+0x1303ed5)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | #7 ThreadFunc(void*) /builds/worker/checkouts/gecko/ipc/chromium/src/base/platform_thread_posix.cc:40:13 (libxul.so+0x12fdcee)
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | Previous read of size 4 at 0x7f9afbe840d8 by main thread:
[task 2020-04-17T22:08:56.655Z] 22:08:56 INFO - GECKO(1303) | [failed to restore the stack]
[task 2020-04-17T22:08:56.656Z] 22:08:56 INFO - GECKO(1303) | Location is global 'evsig_base_fd' of size 4 at 0x7f9afbe840d8 (libxul.so+0x00000a9ce0d8)
[task 2020-04-17T22:08:56.656Z] 22:08:56 INFO - GECKO(1303) | Thread T4 'Gecko_IOThread' (tid=1313, running) created by main thread at:
[task 2020-04-17T22:08:56.656Z] 22:08:56 INFO - GECKO(1303) | #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (firefox+0x5749b)
[task 2020-04-17T22:08:56.657Z] 22:08:56 INFO - GECKO(1303) | #1 CreateThread /builds/worker/checkouts/gecko/ipc/chromium/src/base/platform_thread_posix.cc:123:14 (libxul.so+0x12fb377)
[task 2020-04-17T22:08:56.657Z] 22:08:56 INFO - GECKO(1303) | #2 PlatformThread::Create(unsigned long, PlatformThread::Delegate*, unsigned long*) /builds/worker/checkouts/gecko/ipc/chromium/src/base/platform_thread_posix.cc:134:10 (libxul.so+0x12fb377)
[task 2020-04-17T22:08:56.661Z] 22:08:56 INFO - GECKO(1303) | #3 base::Thread::StartWithOptions(base::Thread::Options const&) /builds/worker/checkouts/gecko/ipc/chromium/src/base/thread.cc:97:8 (libxul.so+0x1303ad1)
[task 2020-04-17T22:08:56.661Z] 22:08:56 INFO - GECKO(1303) | #4 NS_InitXPCOM /builds/worker/checkouts/gecko/xpcom/build/XPCOMInit.cpp:316:9 (libxul.so+0xb0771d)
[task 2020-04-17T22:08:56.662Z] 22:08:56 INFO - GECKO(1303) | #5 ScopedXPCOMStartup::Initialize(bool) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:1311:8 (libxul.so+0x635ccbd)
[task 2020-04-17T22:08:56.662Z] 22:08:56 INFO - GECKO(1303) | #6 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4739:22 (libxul.so+0x6365873)
[task 2020-04-17T22:08:56.663Z] 22:08:56 INFO - GECKO(1303) | #7 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4797:21 (libxul.so+0x6365be4)
[task 2020-04-17T22:08:56.663Z] 22:08:56 INFO - GECKO(1303) | #8 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0x6370792)
[task 2020-04-17T22:08:56.664Z] 22:08:56 INFO - GECKO(1303) | #9 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:217:22 (firefox+0xc93e3)
[task 2020-04-17T22:08:56.665Z] 22:08:56 INFO - GECKO(1303) | #10 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:331:16 (firefox+0xc93e3)
[task 2020-04-17T22:08:56.665Z] 22:08:56 INFO - GECKO(1303) | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/ipc/chromium/src/third_party/libevent/signal.c:125:16 in evsig_set_base_
[task 2020-04-17T22:08:56.669Z] 22:08:56 INFO - GECKO(1303) | ==================
[task 2020-04-17T22:08:56.920Z] 22:08:56 INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2020-04-17T22:08:56.921Z] 22:08:56 INFO - Buffered messages finished
[task 2020-04-17T22:08:56.921Z] 22:08:56 ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code -6
[task 2020-04-17T22:08:56.921Z] 22:08:56 INFO - runtests.py | Application ran for: 0:01:31.910209
[task 2020-04-17T22:08:56.923Z] 22:08:56 INFO - zombiecheck | Reading PID log: /tmp/tmpnbf24Ypidlog
[task 2020-04-17T22:08:56.923Z] 22:08:56 INFO - ==> process 1303 launched child process 1318
[task 2020-04-17T22:08:56.924Z] 22:08:56 INFO - ==> process 1303 launched child process 1363
[task 2020-04-17T22:08:56.925Z] 22:08:56 INFO - ==> process 1303 launched child process 1410
[task 2020-04-17T22:08:56.925Z] 22:08:56 INFO - ==> process 1303 launched child process 1489
[task 2020-04-17T22:08:56.926Z] 22:08:56 INFO - ==> process 1303 launched child process 1515
[task 2020-04-17T22:33:09.066Z] 22:33:09 INFO - Stopping web socket server
[task 2020-04-17T22:33:09.102Z] 22:33:09 INFO - Stopping ssltunnel
[task 2020-04-17T22:33:09.123Z] 22:33:09 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2020-04-17T22:33:09.123Z] 22:33:09 INFO - runtests.py | Running tests: end.
[task 2020-04-17T22:33:09.139Z] 22:33:09 INFO - Buffered messages finished
[task 2020-04-17T22:33:09.140Z] 22:33:09 INFO - 0 INFO TEST-START | Shutdown
[task 2020-04-17T22:33:09.141Z] 22:33:09 INFO - 1 INFO Passed: 26131
[task 2020-04-17T22:33:09.141Z] 22:33:09 INFO - 2 INFO Failed: 0
[task 2020-04-17T22:33:09.141Z] 22:33:09 INFO - 3 INFO Todo: 137
[task 2020-04-17T22:33:09.141Z] 22:33:09 INFO - 4 INFO Mode: e10s
[task 2020-04-17T22:33:09.142Z] 22:33:09 INFO - 5 INFO SimpleTest FINISHED
[task 2020-04-17T22:33:09.142Z] 22:33:09 INFO - Buffered messages finished
[task 2020-04-17T22:33:09.143Z] 22:33:09 INFO - SUITE-END | took 1546s
[task 2020-04-17T22:33:09.182Z] 22:33:09 ERROR - Return code: 250
[task 2020-04-17T22:33:09.185Z] 22:33:09 INFO - TinderboxPrint: mochitest-mochitest-plain<br/>716/0/0
[task 2020-04-17T22:33:09.185Z] 22:33:09 ERROR - # TBPL FAILURE #
[task 2020-04-17T22:33:09.185Z] 22:33:09 WARNING - setting return code to 2
[task 2020-04-17T22:33:09.186Z] 22:33:09 ERROR - The mochitest suite: mochitest-plain ran with return status: FAILURE
[task 2020-04-17T22:33:09.186Z] 22:33:09 INFO - Running post-action listener: _package_coverage_data
[task 2020-04-17T22:33:09.186Z] 22:33:09 INFO - Running post-action listener: _resource_record_post_action
[task 2020-04-17T22:33:09.187Z] 22:33:09 INFO - Running post-action listener: process_java_coverage_data
[task 2020-04-17T22:33:09.187Z] 22:33:09 INFO - [mozharness: 2020-04-17 22:33:09.187269Z] Finished run-tests step (success)
[task 2020-04-17T22:33:09.187Z] 22:33:09 INFO - Running post-run listener: _resource_record_post_run
[task 2020-04-17T22:33:09.437Z] 22:33:09 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2020-04-17T22:33:09.442Z] 22:33:09 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 47.89272352568164}, {"name": "io_write_bytes", "value": 2800951296}, {"name": "io.read_bytes", "value": 1584230400}, {"name": "io_write_time", "value": 358712}, {"name": "io_read_time", "value": 18676}], "extraOptions": ["e10s", "taskcluster-c3.xlarge"], "name": "mochitest.mochitest-plain.overall"}, {"subtests": [{"name": "time", "value": 0.03136587142944336}], "name": "mochitest.mochitest-plain.start-pulseaudio"}, {"subtests": [{"name": "time", "value": 31.337033987045288}, {"name": "cpu_percent", "value": 25.326666666666664}], "name": "mochitest.mochitest-plain.install"}, {"subtests": [{"name": "time", "value": 0.0004069805145263672}], "name": "mochitest.mochitest-plain.stage-files"}, {"subtests": [{"name": "time", "value": 1548.6268289089203}, {"name": "cpu_percent", "value": 48.35813915857603}], "name": "mochitest.mochitest-plain.run-tests"}]}
[task 2020-04-17T22:33:09.442Z] 22:33:09 INFO - Total resource usage - Wall time: 1579s; CPU: 48.0%; Read bytes: 1584230400; Write bytes: 2800951296; Read time: 18676; Write time: 358712
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU usage<br/>48.4%
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: I/O read bytes / time<br/>1,584,230,400 / 18,676
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: I/O write bytes / time<br/>2,800,951,296 / 358,712
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU idle<br/>3,200.0 (51.8%)
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU system<br/>222.5 (3.6%)
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU user<br/>2,740.5 (44.3%)
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2020-04-17T22:33:09.444Z] 22:33:09 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-04-17T22:33:09.446Z] 22:33:09 INFO - install - Wall time: 31s; CPU: 25.0%; Read bytes: 1007616; Write bytes: 1285476352; Read time: 224; Write time: 260548
[task 2020-04-17T22:33:09.447Z] 22:33:09 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-04-17T22:33:09.461Z] 22:33:09 INFO - run-tests - Wall time: 1549s; CPU: 48.0%; Read bytes: 1576030208; Write bytes: 1515474944; Read time: 18396; Write time: 98164
[task 2020-04-17T22:33:09.898Z] 22:33:09 WARNING - returning nonzero exit status 2
[task 2020-04-17T22:33:09.964Z] cleanup
[task 2020-04-17T22:33:09.142Z] 22:33:09 INFO - Buffered messages finished
[task 2020-04-17T22:33:09.143Z] 22:33:09 INFO - SUITE-END | took 1546s
[task 2020-04-17T22:33:09.182Z] 22:33:09 ERROR - Return code: 250
[task 2020-04-17T22:33:09.185Z] 22:33:09 INFO - TinderboxPrint: mochitest-mochitest-plain<br/>716/0/0
[task 2020-04-17T22:33:09.185Z] 22:33:09 ERROR - # TBPL FAILURE #
[task 2020-04-17T22:33:09.185Z] 22:33:09 WARNING - setting return code to 2
[task 2020-04-17T22:33:09.186Z] 22:33:09 ERROR - The mochitest suite: mochitest-plain ran with return status: FAILURE
[task 2020-04-17T22:33:09.186Z] 22:33:09 INFO - Running post-action listener: _package_coverage_data
[task 2020-04-17T22:33:09.186Z] 22:33:09 INFO - Running post-action listener: _resource_record_post_action
[task 2020-04-17T22:33:09.187Z] 22:33:09 INFO - Running post-action listener: process_java_coverage_data
[task 2020-04-17T22:33:09.187Z] 22:33:09 INFO - [mozharness: 2020-04-17 22:33:09.187269Z] Finished run-tests step (success)
[task 2020-04-17T22:33:09.187Z] 22:33:09 INFO - Running post-run listener: _resource_record_post_run
[task 2020-04-17T22:33:09.437Z] 22:33:09 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2020-04-17T22:33:09.442Z] 22:33:09 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 47.89272352568164}, {"name": "io_write_bytes", "value": 2800951296}, {"name": "io.read_bytes", "value": 1584230400}, {"name": "io_write_time", "value": 358712}, {"name": "io_read_time", "value": 18676}], "extraOptions": ["e10s", "taskcluster-c3.xlarge"], "name": "mochitest.mochitest-plain.overall"}, {"subtests": [{"name": "time", "value": 0.03136587142944336}], "name": "mochitest.mochitest-plain.start-pulseaudio"}, {"subtests": [{"name": "time", "value": 31.337033987045288}, {"name": "cpu_percent", "value": 25.326666666666664}], "name": "mochitest.mochitest-plain.install"}, {"subtests": [{"name": "time", "value": 0.0004069805145263672}], "name": "mochitest.mochitest-plain.stage-files"}, {"subtests": [{"name": "time", "value": 1548.6268289089203}, {"name": "cpu_percent", "value": 48.35813915857603}], "name": "mochitest.mochitest-plain.run-tests"}]}
[task 2020-04-17T22:33:09.442Z] 22:33:09 INFO - Total resource usage - Wall time: 1579s; CPU: 48.0%; Read bytes: 1584230400; Write bytes: 2800951296; Read time: 18676; Write time: 358712
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU usage<br/>48.4%
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: I/O read bytes / time<br/>1,584,230,400 / 18,676
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: I/O write bytes / time<br/>2,800,951,296 / 358,712
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU idle<br/>3,200.0 (51.8%)
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU system<br/>222.5 (3.6%)
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: CPU user<br/>2,740.5 (44.3%)
[task 2020-04-17T22:33:09.443Z] 22:33:09 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2020-04-17T22:33:09.444Z] 22:33:09 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-04-17T22:33:09.446Z] 22:33:09 INFO - install - Wall time: 31s; CPU: 25.0%; Read bytes: 1007616; Write bytes: 1285476352; Read time: 224; Write time: 260548
[task 2020-04-17T22:33:09.447Z] 22:33:09 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-04-17T22:33:09.461Z] 22:33:09 INFO - run-tests - Wall time: 1549s; CPU: 48.0%; Read bytes: 1576030208; Write bytes: 1515474944; Read time: 18396; Write time: 98164
[task 2020-04-17T22:33:09.898Z] 22:33:09 WARNING - returning nonzero exit status 2
[task 2020-04-17T22:33:09.964Z] cleanup
[task 2020-04-17T22:33:09.964Z] + cleanup
[task 2020-04-17T22:33:09.964Z] + local rv=2
[task 2020-04-17T22:33:09.964Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2020-04-17T22:33:09.964Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2020-04-17T22:33:09.970Z] + true
[task 2020-04-17T22:33:09.970Z] + cleanup_xvfb
[task 2020-04-17T22:33:09.970Z] ++ pidof Xvfb
[task 2020-04-17T22:33:09.977Z] + local xvfb_pid=40

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE
Blocks: tsan
You need to log in before you can comment on or make changes to this bug.