Intermittent linux-tsan ThreadSanitizer: nested bug in the same thread, aborting.
Categories
(Testing :: General, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Blocks 1 open bug, )
Details
(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])
Attachments
(1 obsolete file)
Filed by: aciure [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=288928788&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/RjudD43bRGaUq44tnDrgOw/runs/0/artifacts/public/logs/live_backing.log
[task 2020-02-14T13:38:43.955Z] 13:38:43 INFO - GECKO(3115) | Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_WebNavigation_page1.html" line: 0}]
[task 2020-02-14T13:38:44.863Z] 13:38:44 INFO - GECKO(3115) | Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_WebNavigation_page2.html" line: 0}]
[task 2020-02-14T13:38:45.753Z] 13:38:45 INFO - GECKO(3115) | ==3406==WARNING: Symbolizer buffer too small
[task 2020-02-14T13:38:45.753Z] 13:38:45 INFO - GECKO(3115) | ==3406==WARNING: Symbolizer buffer too small
[task 2020-02-14T13:38:45.753Z] 13:38:45 INFO - GECKO(3115) | ThreadSanitizer:DEADLYSIGNAL
[task 2020-02-14T13:38:45.753Z] 13:38:45 INFO - GECKO(3115) | ThreadSanitizer: nested bug in the same thread, aborting.
[task 2020-02-14T13:38:45.816Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0079,name=PBrowser::Msg_ParentActivated) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.816Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0079,name=PBrowser::Msg_ParentActivated) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.844Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0051,name=PBrowser::Msg_FlushTabState) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.844Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0096,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.844Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x370135,name=PContent::Msg_DetachBrowsingContext) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.940Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0057,name=PBrowser::Msg_UpdateEffects) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.941Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0051,name=PBrowser::Msg_FlushTabState) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.941Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E007B,name=PBrowser::Msg_StopIMEStateManagement) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.941Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0096,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2020-02-14T13:38:45.941Z] 13:38:45 INFO - GECKO(3115) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x370135,name=PContent::Msg_DetachBrowsingContext) Channel error: cannot send/recv
[task 2020-02-14T13:38:46.037Z] 13:38:46 ERROR - GECKO(3115) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2020-02-14T13:39:01.640Z] 13:39:01 INFO - GECKO(3115) | Console message: [JavaScript Error: "SessionStore: exception whilst flushing all windows: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]" nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)" location: "JS frame :: resource:///modules/sessionstore/SessionStore.jsm :: cleanup :: line 1835" data: no]" {file: "resource:///modules/sessionstore/SessionStore.jsm" line: 1837}]
[task 2020-02-14T13:39:01.641Z] 13:39:01 INFO - GECKO(3115) | cleanup@resource:///modules/sessionstore/SessionStore.jsm:1837:20
[task 2020-02-14T13:39:01.642Z] 13:39:01 INFO - GECKO(3115) | observe@resource://gre/modules/AsyncShutdown.jsm:551:16
[task 2020-02-14T13:39:01.643Z] 13:39:01 INFO - GECKO(3115) | observe@resource:///modules/ContentCrashHandlers.jsm:177:28
[task 2020-02-14T13:39:01.644Z] 13:39:01 INFO - GECKO(3115) | Console message: [JavaScript Error: "SessionStore: exception whilst flushing all windows: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]" nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)" location: "JS frame :: resource:///modules/sessionstore/SessionStore.jsm :: cleanup :: line 1835" data: no]" {file: "resource:///modules/sessionstore/SessionStore.jsm" line: 1837}]
[task 2020-02-14T13:39:01.644Z] 13:39:01 INFO - GECKO(3115) | cleanup@resource:///modules/sessionstore/SessionStore.jsm:1837:20
[task 2020-02-14T13:39:01.645Z] 13:39:01 INFO - GECKO(3115) | observe@resource://gre/modules/AsyncShutdown.jsm:551:16
[task 2020-02-14T13:39:01.646Z] 13:39:01 INFO - GECKO(3115) | observe@resource:///modules/ContentCrashHandlers.jsm:177:28
[task 2020-02-14T13:39:03.673Z] 13:39:03 INFO - GECKO(3115) | Console message: 1581687543320 Toolkit.Telemetry WARN TelemetryEnvironment::registerChangeListener - already shutdown
[task 2020-02-14T13:39:03.814Z] 13:39:03 INFO - GECKO(3115) | 1581687543807 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-02-14T13:39:03.815Z] 13:39:03 INFO - GECKO(3115) | 1581687543808 Marionette INFO Stopped listening on port 2828
[task 2020-02-14T13:39:03.815Z] 13:39:03 INFO - GECKO(3115) | 1581687543808 Marionette DEBUG Marionette stopped listening
[task 2020-02-14T13:39:03.831Z] 13:39:03 INFO - GECKO(3115) | *** WIFI GEO: shutdown called
[task 2020-02-14T13:39:03.892Z] 13:39:03 INFO - GECKO(3115) | Console message: *** WIFI GEO: shutdown called
[task 2020-02-14T13:39:05.382Z] 13:39:05 INFO - TEST-INFO | Main app process: exit 0
[task 2020-02-14T13:39:05.383Z] 13:39:05 INFO - runtests.py | Application ran for: 0:05:02.608471
[task 2020-02-14T13:39:05.383Z] 13:39:05 INFO - zombiecheck | Reading PID log: /tmp/tmpGs05M6pidlog
Comment 1•5 years ago
|
||
The PR at https://github.com/mozilla/treeherder/pull/6016 should make this more visible on Treeherder. TSan does not emit a SUMMARY when it hits this nested bug situation, which makes this particular intermittent hard to recognize right now.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 16•5 years ago
|
||
There are 20 failures associated to this bug in the last 7 days. These are occurring on linux1804-64-tsan, opt.
log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=299928498&repo=autoland&lineNumber=1703
[task 2020-04-29T03:46:38.394Z] 03:46:38 INFO - GECKO(1552) | 1588131998385 Marionette TRACE Received observer notification marionette-startup-requested
[task 2020-04-29T03:46:38.396Z] 03:46:38 INFO - GECKO(1552) | 1588131998388 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2020-04-29T03:46:40.252Z] 03:46:40 INFO - GECKO(1552) | 1588132000243 Marionette TRACE All scripts recorded.
[task 2020-04-29T03:46:41.260Z] 03:46:41 INFO - GECKO(1552) | 1588132001247 Marionette INFO Listening on port 2828
[task 2020-04-29T03:46:41.262Z] 03:46:41 INFO - GECKO(1552) | 1588132001249 Marionette DEBUG Marionette is listening
[task 2020-04-29T03:46:41.498Z] 03:46:41 INFO - GECKO(1552) | 1588132001488 Marionette DEBUG Accepted connection 0 from 127.0.0.1:59700
[task 2020-04-29T03:46:41.514Z] 03:46:41 INFO - GECKO(1552) | 1588132001506 Marionette DEBUG Closed connection 0
[task 2020-04-29T03:46:41.516Z] 03:46:41 INFO - GECKO(1552) | 1588132001513 Marionette DEBUG Accepted connection 1 from 127.0.0.1:59702
[task 2020-04-29T03:46:41.565Z] 03:46:41 INFO - GECKO(1552) | 1588132001560 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-04-29T03:46:42.012Z] 03:46:42 INFO - GECKO(1552) | 1588132001999 Marionette TRACE [5] Frame script loaded
[task 2020-04-29T03:46:42.316Z] 03:46:42 INFO - GECKO(1552) | 1588132002309 Marionette TRACE [5] Frame script registered
[task 2020-04-29T03:46:42.476Z] 03:46:42 INFO - GECKO(1552) | 1588132002469 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"7a3874a9-5850-4013-a61d-362d549302a0","capabilities":{"browserName":"firefox","browserVersion":"77.0a ... p/tmplYNUB4.mozrunner","moz:shutdownTimeout":360000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-04-29T03:46:42.640Z] 03:46:42 INFO - GECKO(1552) | 1588132002623 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmp2jxYcv.zip","temporary":false}]
[task 2020-04-29T03:46:43.762Z] 03:46:43 INFO - GECKO(1552) | ==1663==WARNING: Symbolizer buffer too small
[task 2020-04-29T03:46:43.763Z] 03:46:43 INFO - GECKO(1552) | ==1663==WARNING: Symbolizer buffer too small
[task 2020-04-29T03:46:43.763Z] 03:46:43 INFO - GECKO(1552) | ThreadSanitizer:DEADLYSIGNAL
[task 2020-04-29T03:46:43.763Z] 03:46:43 INFO - GECKO(1552) | ThreadSanitizer: nested bug in the same thread, aborting.
[task 2020-04-29T03:46:43.880Z] 03:46:43 INFO - GECKO(1552) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x380131,name=PContent::Msg_AsyncMessage) Channel error: cannot send/recv
[task 2020-04-29T03:46:43.924Z] 03:46:43 ERROR - GECKO(1552) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2020-04-29T03:46:45.888Z] 03:46:45 INFO - runtests.py | Waiting for browser...
[task 2020-04-29T03:46:45.929Z] 03:46:45 INFO - GECKO(1552) | 1588132005919 Marionette DEBUG Closed connection 1
[task 2020-04-29T03:46:46.484Z] 03:46:46 INFO - GECKO(1552) | 1588132006473 Marionette TRACE [22] Frame script loaded
[task 2020-04-29T03:46:46.484Z] 03:46:46 INFO - GECKO(1552) | 1588132006480 Marionette ERROR [22] No reply from Marionette:Register
[task 2020-04-29T03:46:47.586Z] 03:46:47 INFO - GECKO(1552) | 1588132007573 Marionette DEBUG 1 <- [1,2,{"error":"unknown error","message":"Could not install add-on: /tmp/tmp2jxYcv.zip: AddonManager is not initialized","stac ... t@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"},null]
[task 2020-04-29T03:46:49.080Z] 03:46:49 INFO - GECKO(1552) | 1588132009073 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-04-29T03:46:49.081Z] 03:46:49 INFO - GECKO(1552) | 1588132009074 Marionette INFO Stopped listening on port 2828
[task 2020-04-29T03:46:49.081Z] 03:46:49 INFO - GECKO(1552) | 1588132009074 Marionette DEBUG Marionette stopped listening
:gbrown can you take a look?
Comment 17•5 years ago
|
||
Hopefully :decoder understands what is happening here...
| Comment hidden (Intermittent Failures Robot) |
Comment 19•5 years ago
|
||
(In reply to Geoff Brown [:gbrown] from comment #17)
Hopefully :decoder understands what is happening here...
No, in fact I don't. We have had this problem since the beginning, but intermittently and at an acceptable rate. This is a TSan internal problem of some sort. I will try to raise it again with the Google/TSan developers (leaving needinfo for this)
| Comment hidden (Intermittent Failures Robot) |
Comment 21•5 years ago
|
||
In the last 7 days there have been 30 occurrences on linux1804-64-tsan opt.
Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=302607390&repo=autoland&lineNumber=1772
...
[task 2020-05-16T22:18:02.658Z] 22:18:02 INFO - TEST-OK | dom/encoding/test/test_utf16_files.html | took 916ms
[task 2020-05-16T22:18:02.807Z] 22:18:02 INFO - TEST-START | Shutdown
[task 2020-05-16T22:18:02.811Z] 22:18:02 INFO - Passed: 57
[task 2020-05-16T22:18:02.814Z] 22:18:02 INFO - Failed: 0
[task 2020-05-16T22:18:02.815Z] 22:18:02 INFO - Todo: 0
[task 2020-05-16T22:18:02.816Z] 22:18:02 INFO - Mode: e10s
[task 2020-05-16T22:18:02.818Z] 22:18:02 INFO - Slowest: 8579ms - /tests/dom/encoding/test/test_stringencoding.html
[task 2020-05-16T22:18:02.818Z] 22:18:02 INFO - SimpleTest FINISHED
[task 2020-05-16T22:18:02.822Z] 22:18:02 INFO - TEST-INFO | Ran 1 Loops
[task 2020-05-16T22:18:02.823Z] 22:18:02 INFO - SimpleTest FINISHED
[task 2020-05-16T22:18:06.082Z] 22:18:06 INFO - GECKO(1568) | 1589667486073 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-05-16T22:18:06.083Z] 22:18:06 INFO - GECKO(1568) | 1589667486075 Marionette INFO Stopped listening on port 2828
[task 2020-05-16T22:18:06.084Z] 22:18:06 INFO - GECKO(1568) | 1589667486076 Marionette DEBUG Marionette stopped listening
[task 2020-05-16T22:18:11.890Z] 22:18:11 INFO - TEST-INFO | Main app process: exit 0
[task 2020-05-16T22:18:11.890Z] 22:18:11 INFO - runtests.py | Application ran for: 0:01:06.919046
[task 2020-05-16T22:18:11.891Z] 22:18:11 INFO - zombiecheck | Reading PID log: /tmp/tmpqjLl7fpidlog
[task 2020-05-16T22:18:11.892Z] 22:18:11 INFO - ==> process 1568 launched child process 1583
[task 2020-05-16T22:18:11.892Z] 22:18:11 INFO - ==> process 1568 launched child process 1663
[task 2020-05-16T22:18:11.893Z] 22:18:11 INFO - ==> process 1568 launched child process 1679
[task 2020-05-16T22:18:11.893Z] 22:18:11 INFO - ==> process 1568 launched child process 1750
[task 2020-05-16T22:18:11.893Z] 22:18:11 INFO - ==> process 1568 launched child process 1775
[task 2020-05-16T22:18:11.894Z] 22:18:11 INFO - zombiecheck | Checking for orphan process with PID: 1663
[task 2020-05-16T22:18:11.895Z] 22:18:11 INFO - zombiecheck | Checking for orphan process with PID: 1679
[task 2020-05-16T22:18:11.895Z] 22:18:11 INFO - zombiecheck | Checking for orphan process with PID: 1775
[task 2020-05-16T22:18:11.896Z] 22:18:11 INFO - zombiecheck | Checking for orphan process with PID: 1750
[task 2020-05-16T22:18:11.897Z] 22:18:11 INFO - zombiecheck | Checking for orphan process with PID: 1583
[task 2020-05-16T22:18:11.897Z] 22:18:11 INFO - Stopping web server
[task 2020-05-16T22:18:11.913Z] 22:18:11 INFO - Stopping web socket server
[task 2020-05-16T22:18:11.937Z] 22:18:11 INFO - Stopping ssltunnel
[task 2020-05-16T22:18:11.957Z] 22:18:11 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2020-05-16T22:18:11.958Z] 22:18:11 INFO - runtests.py | Running tests: end.
[task 2020-05-16T22:18:11.978Z] 22:18:11 INFO - Buffered messages finished
[task 2020-05-16T22:18:11.978Z] 22:18:11 INFO - Running manifest: dom/html/test/mochitest.ini
[task 2020-05-16T22:18:11.979Z] 22:18:11 INFO - The following extra prefs will be set:
[task 2020-05-16T22:18:11.979Z] 22:18:11 INFO - plugin.load_flash_only=false
[task 2020-05-16T22:18:11.999Z] 22:18:11 INFO - Setting pipeline to PAUSED ...
[task 2020-05-16T22:18:11.999Z] 22:18:11 INFO - Pipeline is PREROLLING ...
[task 2020-05-16T22:18:12.003Z] 22:18:12 INFO - Pipeline is PREROLLED ...
[task 2020-05-16T22:18:12.003Z] 22:18:12 INFO - Setting pipeline to PLAYING ...
[task 2020-05-16T22:18:12.003Z] 22:18:12 INFO - New clock: GstSystemClock
[task 2020-05-16T22:18:12.039Z] 22:18:12 INFO - Got EOS from element "pipeline0".
[task 2020-05-16T22:18:12.039Z] 22:18:12 INFO - Execution ended after 0:00:00.033449850
[task 2020-05-16T22:18:12.039Z] 22:18:12 INFO - Setting pipeline to PAUSED ...
[task 2020-05-16T22:18:12.040Z] 22:18:12 INFO - Setting pipeline to READY ...
[task 2020-05-16T22:18:12.040Z] 22:18:12 INFO - (gst-launch-1.0:1841): GStreamer-CRITICAL **: 22:18:12.034: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2020-05-16T22:18:12.040Z] 22:18:12 INFO - Setting pipeline to NULL ...
[task 2020-05-16T22:18:12.040Z] 22:18:12 INFO - Freeing pipeline ...
[task 2020-05-16T22:18:12.064Z] 22:18:12 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-05-16T22:18:12.390Z] 22:18:12 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2020-05-16T22:18:12.822Z] 22:18:12 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-05-16T22:18:12.822Z] 22:18:12 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-05-16T22:18:12.826Z] 22:18:12 INFO - MochitestServer : launching [u'/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpfpsDhI.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2020-05-16T22:18:12.826Z] 22:18:12 INFO - runtests.py | Server pid: 1860
[task 2020-05-16T22:18:12.830Z] 22:18:12 INFO - runtests.py | Websocket server pid: 1863
[task 2020-05-16T22:18:12.833Z] 22:18:12 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-05-16T22:18:12.849Z] 22:18:12 INFO - runtests.py | SSL tunnel pid: 1866
[task 2020-05-16T22:18:13.598Z] 22:18:13 INFO - runtests.py | Running with scheme: http
[task 2020-05-16T22:18:13.598Z] 22:18:13 INFO - runtests.py | Running with e10s: True
[task 2020-05-16T22:18:13.599Z] 22:18:13 INFO - runtests.py | Running with fission: False
[task 2020-05-16T22:18:13.599Z] 22:18:13 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2020-05-16T22:18:13.599Z] 22:18:13 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2020-05-16T22:18:13.600Z] 22:18:13 INFO - runtests.py | Running tests: start.
[task 2020-05-16T22:18:13.600Z] 22:18:13 INFO -
[task 2020-05-16T22:18:13.620Z] 22:18:13 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpfpsDhI.mozrunner
[task 2020-05-16T22:18:13.637Z] 22:18:13 INFO - runtests.py | Application pid: 1885
[task 2020-05-16T22:18:13.637Z] 22:18:13 INFO - TEST-INFO | started process GECKO(1885)
[task 2020-05-16T22:18:19.966Z] 22:18:19 INFO - GECKO(1885) | 1589667499958 Marionette TRACE Marionette enabled
[task 2020-05-16T22:18:21.055Z] 22:18:21 INFO - GECKO(1885) | 1589667501051 Marionette TRACE Received observer notification toplevel-window-ready
[task 2020-05-16T22:18:32.735Z] 22:18:32 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:32.735Z] 22:18:32 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.479Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.479Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.481Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.481Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.485Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.485Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.488Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.489Z] 22:18:33 INFO - GECKO(1885) | ==2010==WARNING: Symbolizer buffer too small
[task 2020-05-16T22:18:33.491Z] 22:18:33 INFO - GECKO(1885) | ThreadSanitizer:DEADLYSIGNAL
[task 2020-05-16T22:18:33.491Z] 22:18:33 INFO - GECKO(1885) | ThreadSanitizer: nested bug in the same thread, aborting.
[task 2020-05-16T22:18:33.540Z] 22:18:33 INFO - GECKO(1885) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x390023,name=PContent::Msg_PreferenceUpdate) Channel error: cannot send/recv
...
...
[task 2020-05-16T22:18:33.693Z] 22:18:33 INFO - GECKO(1885) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x390023,name=PContent::Msg_PreferenceUpdate) Channel error: cannot send/recv
[task 2020-05-16T22:18:33.751Z] 22:18:33 ERROR - GECKO(1885) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2020-05-16T22:18:33.992Z] 22:18:33 INFO - GECKO(1885) | JavaScript error: resource://activity-stream/lib/ActivityStreamPrefs.jsm, line 27: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIPrefBranch.removeObserver]
[task 2020-05-16T22:18:40.413Z] 22:18:40 INFO - GECKO(1885) | JavaScript error: , line 0: uncaught exception: 2147500036
[task 2020-05-16T22:18:40.413Z] 22:18:40 INFO - GECKO(1885) | JavaScript error: resource://activity-stream/lib/TopSitesFeed.jsm, line 447: uncaught exception: 2147500036
[task 2020-05-16T22:18:40.413Z] 22:18:40 INFO - GECKO(1885) | JavaScript error: resource://activity-stream/lib/TopSitesFeed.jsm, line 473: uncaught exception: 2147500036
[task 2020-05-16T22:21:13.694Z] 22:21:13 INFO - runtests.py | Waiting for browser...
[task 2020-05-16T22:21:13.695Z] 22:21:13 INFO - TEST-INFO | Main app process: exit 0
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 24•5 years ago
|
||
This bug failed 32 times in the last 7 days. Occurs on linux1804-64-tsan on opt build types.
Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304326413&repo=mozilla-central&lineNumber=2879
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 27•5 years ago
|
||
In the past week there were 34 failures on linux1804-64-tsan opt.
Recent failure log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=306204415&repo=autoland&lineNumber=3541
[task 2020-06-13T08:08:26.989Z] 08:08:26 INFO - TEST-INFO | started process GECKO(3270)
[task 2020-06-13T08:08:31.669Z] 08:08:31 INFO - GECKO(3270) | 1592035711664 Marionette TRACE Marionette enabled
[task 2020-06-13T08:08:32.447Z] 08:08:32 INFO - GECKO(3270) | 1592035712441 Marionette TRACE Received observer notification toplevel-window-ready
[task 2020-06-13T08:08:40.787Z] 08:08:40 INFO - GECKO(3270) | console.error: SearchService: "_readCacheFile: Error reading cache file:" (new Error("", "(unknown module)"))
[task 2020-06-13T08:08:40.883Z] 08:08:40 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:40.884Z] 08:08:40 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.341Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.342Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.342Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.342Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.342Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.342Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.342Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.343Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.344Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.345Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.347Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.347Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.347Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.347Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.355Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.355Z] 08:08:41 INFO - GECKO(3270) | ==3381==WARNING: Symbolizer buffer too small
[task 2020-06-13T08:08:41.355Z] 08:08:41 INFO - GECKO(3270) | ThreadSanitizer:DEADLYSIGNAL
[task 2020-06-13T08:08:41.355Z] 08:08:41 INFO - GECKO(3270) | ThreadSanitizer: nested bug in the same thread, aborting.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 31•5 years ago
|
||
This bug failed 35 times in the last 7 days. Occurs on linux1804-64-tsan on opt build types.
Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=308527626&repo=autoland&lineNumber=2783
| Comment hidden (Intermittent Failures Robot) |
Comment 33•5 years ago
|
||
There are 34 failures in last 7 days. This happens on linux1804-64-tsan on opt.
Recent failure log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=309425861&repo=autoland&lineNumber=2109
| Comment hidden (Intermittent Failures Robot) |
Comment 35•5 years ago
|
||
TSan developers suggested that we add some debug output to our Clang and see if that sheds some light on what is happening. I will try to take a stab at it this week.
| Comment hidden (Intermittent Failures Robot) |
Comment 37•5 years ago
|
||
In the last 7 days there have been 22 occurrences on linux1804-64-tsan opt.
Recent failure: https://treeherder.mozilla.org/logviewer.html#?job_id=311057963&repo=mozilla-central
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 40•5 years ago
|
||
This bug failed failed 33 times in the last 7 days. This happens on linux1804-64-tsan opt.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=312459194&repo=autoland&lineNumber=2858
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 46•5 years ago
|
||
Christian, circling back at comment 35, any chance this is still on your radar? The bug is now in disable recommended queue with:
- 53 total failures in the last 7 days https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-08-15&endday=2020-08-22&tree=trunk&bug=1615608
- 172 total failures in the last 30 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-07-23&endday=2020-08-22&tree=trunk&bug=1615608
A fix would be welcomed here given the failure rate.
Updated•5 years ago
|
Comment 47•5 years ago
|
||
(In reply to Cosmin Sabou [:CosminS] from comment #46)
Christian, circling back at comment 35, any chance this is still on your radar?
This is still on my radar, but previous attempts to debug this failed so far. It might well be that this bug will stick around a bit longer.
Given the amount of bugs we have found so far, I still think that the rate here is acceptable (although annoying, I agree), and would not justify to disable TSan as a whole. If this was a single test or a small group of tests, then I would disable it immediately but this issue can happen across all of CI unfortunately :/
I'm leaving the needinfo to make sure I take another stab at this soon.
Updated•5 years ago
|
| Comment hidden (Intermittent Failures Robot) |
Comment 49•5 years ago
|
||
Hi Christian, are there any updates here?
There are 41 total failures in the last 7 days on linux1804-64-tsan opt.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=314220068&repo=mozilla-central&lineNumber=2526
[task 2020-08-27T22:09:46.893Z] 22:09:46 INFO - TEST-START | dom/security/test/referrer-policy/test_img_referrer.html
[task 2020-08-27T22:09:49.341Z] 22:09:49 INFO - GECKO(2489) | ==2629==WARNING: Symbolizer buffer too small
[task 2020-08-27T22:09:49.341Z] 22:09:49 INFO - GECKO(2489) | ==2629==WARNING: Symbolizer buffer too small
[task 2020-08-27T22:09:49.342Z] 22:09:49 INFO - GECKO(2489) | ThreadSanitizer:DEADLYSIGNAL
[task 2020-08-27T22:09:49.343Z] 22:09:49 INFO - GECKO(2489) | ThreadSanitizer: nested bug in the same thread, aborting.
[task 2020-08-27T22:09:49.399Z] 22:09:49 INFO - GECKO(2489) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x390149,name=PContent::Msg_AsyncMessage) Channel error: cannot send/recv
[task 2020-08-27T22:09:49.435Z] 22:09:49 ERROR - GECKO(2489) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2020-08-27T22:09:51.697Z] 22:09:51 INFO - GECKO(2489) | 1598566191696 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-08-27T22:09:51.701Z] 22:09:51 INFO - GECKO(2489) | 1598566191697 Marionette INFO Stopped listening on port 2828
[task 2020-08-27T22:09:51.702Z] 22:09:51 INFO - GECKO(2489) | 1598566191697 Marionette DEBUG Marionette stopped listening
[task 2020-08-27T22:10:02.697Z] 22:10:02 INFO - TEST-INFO | Main app process: exit 0
| Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 54•5 years ago
|
||
It looks like this bug went completely away with the upgrade to Clang 11. I guess that's great news \o/
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Updated•1 year ago
|
Description
•