Open Bug 1626420 Opened 3 years ago Updated 2 months ago

Intermittent LeakSanitizer | leak at unknown stack

Categories

(Core :: General, defect, P5)

defect

Tracking

()

REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=295652953&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/IvAODMp3SJWFEIB7KnkiNw/runs/0/artifacts/public/logs/live_backing.log


[task 2020-03-31T21:50:39.393Z] 21:50:39 INFO - TEST-INFO | Main app process: exit 0
[task 2020-03-31T21:50:39.393Z] 21:50:39 INFO - TEST-INFO | LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2020-03-31T21:50:39.393Z] 21:50:39 INFO - TEST-INFO | LeakSanitizer | This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2020-03-31T21:50:39.394Z] 21:50:39 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at unknown stack
[task 2020-03-31T21:50:39.395Z] 21:50:39 INFO - runtests.py | Application ran for: 0:26:54.243550
[task 2020-03-31T21:50:39.395Z] 21:50:39 INFO - zombiecheck | Reading PID log: /tmp/tmpMTwcmppidlog
[task 2020-03-31T21:50:39.396Z] 21:50:39 INFO - ==> process 2232 launched child process 2252
[task 2020-03-31T21:50:39.396Z] 21:50:39 INFO - ==> process 2232 launched child process 2288
[task 2020-03-31T21:50:39.398Z] 21:50:39 INFO - ==> process 2232 launched child process 2411
[task 2020-03-31T21:50:39.398Z] 21:50:39 INFO - ==> process 2232 launched child process 2468
[task 2020-03-31T21:50:39.399Z] 21:50:39 INFO - ==> process 2232 launched child process 2534
[task 2020-03-31T21:50:39.399Z] 21:50:39 INFO - ==> process 2232 launched child process 2589
[task 2020-03-31T21:50:39.399Z] 21:50:39 INFO - zombiecheck | Checking for orphan process with PID: 2468
[task 2020-03-31T21:50:39.400Z] 21:50:39 INFO - zombiecheck | Checking for orphan process with PID: 2534
[task 2020-03-31T21:50:39.400Z] 21:50:39 INFO - zombiecheck | Checking for orphan process with PID: 2411
[task 2020-03-31T21:50:39.400Z] 21:50:39 INFO - zombiecheck | Checking for orphan process with PID: 2252
[task 2020-03-31T21:50:39.400Z] 21:50:39 INFO - zombiecheck | Checking for orphan process with PID: 2288
[task 2020-03-31T21:50:39.401Z] 21:50:39 INFO - zombiecheck | Checking for orphan process with PID: 2589
[task 2020-03-31T21:50:39.401Z] 21:50:39 INFO - Stopping web server
[task 2020-03-31T21:50:39.423Z] 21:50:39 INFO - Stopping web socket server
[task 2020-03-31T21:50:39.445Z] 21:50:39 INFO - Stopping ssltunnel
[task 2020-03-31T21:50:39.465Z] 21:50:39 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2020-03-31T21:50:39.465Z] 21:50:39 INFO - runtests.py | Running tests: end.
[task 2020-03-31T21:50:39.507Z] 21:50:39 INFO - Buffered messages finished
[task 2020-03-31T21:50:39.508Z] 21:50:39 INFO - Running manifest: devtools/shared/webconsole/test/browser/browser.ini
[task 2020-03-31T21:50:39.617Z] 21:50:39 INFO - Setting pipeline to PAUSED ...
[task 2020-03-31T21:50:39.617Z] 21:50:39 INFO - Pipeline is PREROLLING ...
[task 2020-03-31T21:50:39.620Z] 21:50:39 INFO - Pipeline is PREROLLED ...
[task 2020-03-31T21:50:39.621Z] 21:50:39 INFO - Setting pipeline to PLAYING ...
[task 2020-03-31T21:50:39.621Z] 21:50:39 INFO - New clock: GstSystemClock
[task 2020-03-31T21:50:39.657Z] 21:50:39 INFO - Got EOS from element "pipeline0".
[task 2020-03-31T21:50:39.657Z] 21:50:39 INFO - Execution ended after 0:00:00.033576320
[task 2020-03-31T21:50:39.658Z] 21:50:39 INFO - Setting pipeline to PAUSED ...
[task 2020-03-31T21:50:39.658Z] 21:50:39 INFO - Setting pipeline to READY ...
[task 2020-03-31T21:50:39.658Z] 21:50:39 INFO - (gst-launch-1.0:2750): GStreamer-CRITICAL **: 21:50:39.653: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2020-03-31T21:50:39.658Z] 21:50:39 INFO - Setting pipeline to NULL ...
[task 2020-03-31T21:50:39.658Z] 21:50:39 INFO - Freeing pipeline ...
[task 2020-03-31T21:50:39.735Z] 21:50:39 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-03-31T21:50:39.743Z] 21:50:39 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2020-03-31T21:50:39.744Z] 21:50:39 INFO - UBSan enabled.
[task 2020-03-31T21:50:40.104Z] 21:50:40 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2020-03-31T21:50:40.225Z] 21:50:40 INFO - Increasing default timeout to 90 seconds
[task 2020-03-31T21:50:40.226Z] 21:50:40 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-03-31T21:50:40.233Z] 21:50:40 INFO - LSan enabled.
[task 2020-03-31T21:50:40.234Z] 21:50:40 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2020-03-31T21:50:40.234Z] 21:50:40 INFO - UBSan enabled.
[task 2020-03-31T21:50:40.234Z] 21:50:40 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-03-31T21:50:40.238Z] 21:50:40 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2020-03-31T21:50:40.238Z] 21:50:40 INFO - UBSan enabled.

Looks like the leaks ceased April 22? Are there supposed to be symbols in https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=298872140&repo=autoland&lineNumber=7557 ?

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

The memory usage looks pretty high:
[task 2020-05-18T10:11:53.242Z] 10:11:53 INFO - GECKO(2245) | MEMORY STAT | vsize 20977692MB | residentFast 3545MB
[task 2020-05-18T10:11:53.242Z] 10:11:53 INFO - TEST-OK | devtools/client/inspector/rules/test/browser_rules_variables_03-case-sensitive.js | took 4748ms

Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE

Recent failure:

[task 2020-06-15T23:04:32.496Z] 23:04:32 INFO - TEST-START | /IndexedDB/writer-starvation.htm
[task 2020-06-15T23:04:32.500Z] 23:04:32 INFO - Closing window 828
[task 2020-06-15T23:04:33.154Z] 23:04:33 INFO - PID 5229 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-06-15T23:04:33.526Z] 23:04:33 INFO - .
[task 2020-06-15T23:04:33.526Z] 23:04:33 INFO - TEST-OK | /IndexedDB/writer-starvation.htm | took 1028ms
[task 2020-06-15T23:04:33.528Z] 23:04:33 INFO - Restarting browser for new test group
[task 2020-06-15T23:04:33.561Z] 23:04:33 INFO - PID 3558 | 1592262273550 Marionette INFO Stopped listening on port 53490
[task 2020-06-15T23:04:34.012Z] 23:04:34 INFO - PID 3558 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-06-15T23:04:34.012Z] 23:04:34 INFO - PID 3558 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-06-15T23:04:34.012Z] 23:04:34 INFO - PID 3558 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-06-15T23:04:34.012Z] 23:04:34 INFO - PID 3558 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-06-15T23:04:34.190Z] 23:04:34 INFO - PID 3558 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-06-15T23:04:35.516Z] 23:04:35 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:35.516Z] 23:04:35 INFO - PID 3558 | Suppressions used:
[task 2020-06-15T23:04:35.516Z] 23:04:35 INFO - PID 3558 | count bytes template
[task 2020-06-15T23:04:35.516Z] 23:04:35 INFO - PID 3558 | 18 568 nsComponentManagerImpl
[task 2020-06-15T23:04:35.516Z] 23:04:35 INFO - PID 3558 | 2 288 libfontconfig.so
[task 2020-06-15T23:04:35.516Z] 23:04:35 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:35.638Z] 23:04:35 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:35.638Z] 23:04:35 INFO - PID 3558 | Suppressions used:
[task 2020-06-15T23:04:35.638Z] 23:04:35 INFO - PID 3558 | count bytes template
[task 2020-06-15T23:04:35.638Z] 23:04:35 INFO - PID 3558 | 18 568 nsComponentManagerImpl
[task 2020-06-15T23:04:35.638Z] 23:04:35 INFO - PID 3558 | 633 18287 libfontconfig.so
[task 2020-06-15T23:04:35.638Z] 23:04:35 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:35.721Z] 23:04:35 INFO - PID 5229 | -----------------------------------------------------
[task 2020-06-15T23:04:35.721Z] 23:04:35 INFO - PID 5229 | Suppressions used:
[task 2020-06-15T23:04:35.722Z] 23:04:35 INFO - PID 5229 | count bytes template
[task 2020-06-15T23:04:35.722Z] 23:04:35 INFO - PID 5229 | 18 568 nsComponentManagerImpl
[task 2020-06-15T23:04:35.722Z] 23:04:35 INFO - PID 5229 | 633 18287 libfontconfig.so
[task 2020-06-15T23:04:35.722Z] 23:04:35 INFO - PID 5229 | -----------------------------------------------------
[task 2020-06-15T23:04:35.763Z] 23:04:35 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:35.763Z] 23:04:35 INFO - PID 3558 | Suppressions used:
[task 2020-06-15T23:04:35.764Z] 23:04:35 INFO - PID 3558 | count bytes template
[task 2020-06-15T23:04:35.764Z] 23:04:35 INFO - PID 3558 | 18 568 nsComponentManagerImpl
[task 2020-06-15T23:04:35.764Z] 23:04:35 INFO - PID 3558 | 633 18287 libfontconfig.so
[task 2020-06-15T23:04:35.764Z] 23:04:35 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:36.207Z] 23:04:36 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:36.207Z] 23:04:36 INFO - PID 3558 | Suppressions used:
[task 2020-06-15T23:04:36.207Z] 23:04:36 INFO - PID 3558 | count bytes template
[task 2020-06-15T23:04:36.207Z] 23:04:36 INFO - PID 3558 | 18 568 nsComponentManagerImpl
[task 2020-06-15T23:04:36.207Z] 23:04:36 INFO - PID 3558 | 633 18287 libfontconfig.so
[task 2020-06-15T23:04:36.207Z] 23:04:36 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:37.033Z] 23:04:37 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:37.033Z] 23:04:37 INFO - PID 3558 | Suppressions used:
[task 2020-06-15T23:04:37.033Z] 23:04:37 INFO - PID 3558 | count bytes template
[task 2020-06-15T23:04:37.033Z] 23:04:37 INFO - PID 3558 | 15 464 nsComponentManagerImpl
[task 2020-06-15T23:04:37.034Z] 23:04:37 INFO - PID 3558 | 633 18083 libfontconfig.so
[task 2020-06-15T23:04:37.034Z] 23:04:37 INFO - PID 3558 | 4 832 mozJSComponentLoader
[task 2020-06-15T23:04:37.034Z] 23:04:37 INFO - PID 3558 | -----------------------------------------------------
[task 2020-06-15T23:04:37.138Z] 23:04:37 INFO - Browser exited with return code 0
[task 2020-06-15T23:04:37.139Z] 23:04:37 INFO - PROCESS LEAKS None
[task 2020-06-15T23:04:37.139Z] 23:04:37 INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 88 byte(s) leaked in 3 allocation(s).
[task 2020-06-15T23:04:37.139Z] 23:04:37 INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2020-06-15T23:04:37.139Z] 23:04:37 INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2020-06-15T23:04:37.139Z] 23:04:37 INFO - Allowed depth was 4
[task 2020-06-15T23:04:37.139Z] 23:04:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at unknown stack

Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 2 years ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago10 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Blocks: LSan
You need to log in before you can comment on or make changes to this bug.