Closed Bug 1533124 Opened 6 years ago Closed 4 years ago

Intermittent LeakSanitizer | leak at mozilla::net::CookieSettings::Create, mozilla::net::LoadInfo::LoadInfo, nsDocShell::DoURILoad, nsDocShell::InternalLoad

Categories

(Core :: Networking: WebSockets, defect, P3)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

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

#[markdown(off)]
Filed by: ccoroiu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=232214059&repo=autoland

https://queue.taskcluster.net/v1/task/Wm_e1QykTsOv0Xzhx-Kr3A/runs/0/artifacts/public/logs/live_backing.log

[task 2019-03-06T18:49:18.738Z] 18:49:18 INFO - TEST-START | /websockets/referrer.any.worker.html
[task 2019-03-06T18:49:18.743Z] 18:49:18 INFO - Closing window 358629769217
[task 2019-03-06T18:49:18.852Z] 18:49:18 INFO - PID 18064 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-03-06T18:49:19.743Z] 18:49:19 INFO - .
[task 2019-03-06T18:49:19.744Z] 18:49:19 INFO - TEST-OK | /websockets/referrer.any.worker.html | took 1005ms
[task 2019-03-06T18:49:19.780Z] 18:49:19 INFO - PID 18064 | 1551898159774 Marionette INFO Stopped listening on port 2828
[task 2019-03-06T18:49:19.803Z] 18:49:19 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:19.806Z] 18:49:19 INFO - PID 18064 | Suppressions used:
[task 2019-03-06T18:49:19.808Z] 18:49:19 INFO - PID 18064 | count bytes template
[task 2019-03-06T18:49:19.809Z] 18:49:19 INFO - PID 18064 | 30 928 nsComponentManagerImpl
[task 2019-03-06T18:49:19.810Z] 18:49:19 INFO - PID 18064 | 611 17713 libfontconfig.so
[task 2019-03-06T18:49:19.812Z] 18:49:19 INFO - PID 18064 | 1 29 libglib-2.0.so
[task 2019-03-06T18:49:19.813Z] 18:49:19 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:20.090Z] 18:49:20 INFO - PID 18064 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-03-06T18:49:21.296Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.297Z] 18:49:21 INFO - PID 18064 | Suppressions used:
[task 2019-03-06T18:49:21.297Z] 18:49:21 INFO - PID 18064 | count bytes template
[task 2019-03-06T18:49:21.297Z] 18:49:21 INFO - PID 18064 | 30 928 nsComponentManagerImpl
[task 2019-03-06T18:49:21.297Z] 18:49:21 INFO - PID 18064 | 611 17713 libfontconfig.so
[task 2019-03-06T18:49:21.297Z] 18:49:21 INFO - PID 18064 | 1 29 libglib-2.0.so
[task 2019-03-06T18:49:21.297Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.346Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.346Z] 18:49:21 INFO - PID 18064 | Suppressions used:
[task 2019-03-06T18:49:21.346Z] 18:49:21 INFO - PID 18064 | count bytes template
[task 2019-03-06T18:49:21.346Z] 18:49:21 INFO - PID 18064 | 30 928 nsComponentManagerImpl
[task 2019-03-06T18:49:21.346Z] 18:49:21 INFO - PID 18064 | 2 288 libfontconfig.so
[task 2019-03-06T18:49:21.346Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.572Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.573Z] 18:49:21 INFO - PID 18064 | Suppressions used:
[task 2019-03-06T18:49:21.574Z] 18:49:21 INFO - PID 18064 | count bytes template
[task 2019-03-06T18:49:21.574Z] 18:49:21 INFO - PID 18064 | 30 928 nsComponentManagerImpl
[task 2019-03-06T18:49:21.575Z] 18:49:21 INFO - PID 18064 | 611 17713 libfontconfig.so
[task 2019-03-06T18:49:21.575Z] 18:49:21 INFO - PID 18064 | 1 29 libglib-2.0.so
[task 2019-03-06T18:49:21.576Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.616Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:21.617Z] 18:49:21 INFO - PID 18064 | Suppressions used:
[task 2019-03-06T18:49:21.617Z] 18:49:21 INFO - PID 18064 | count bytes template
[task 2019-03-06T18:49:21.617Z] 18:49:21 INFO - PID 18064 | 30 928 nsComponentManagerImpl
[task 2019-03-06T18:49:21.617Z] 18:49:21 INFO - PID 18064 | 611 17713 libfontconfig.so
[task 2019-03-06T18:49:21.617Z] 18:49:21 INFO - PID 18064 | 1 29 libglib-2.0.so
[task 2019-03-06T18:49:21.617Z] 18:49:21 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:22.733Z] 18:49:22 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:22.733Z] 18:49:22 INFO - PID 18064 | Suppressions used:
[task 2019-03-06T18:49:22.734Z] 18:49:22 INFO - PID 18064 | count bytes template
[task 2019-03-06T18:49:22.734Z] 18:49:22 INFO - PID 18064 | 27 824 nsComponentManagerImpl
[task 2019-03-06T18:49:22.735Z] 18:49:22 INFO - PID 18064 | 4 832 mozJSComponentLoader::LoadModule
[task 2019-03-06T18:49:22.735Z] 18:49:22 INFO - PID 18064 | 611 17509 libfontconfig.so
[task 2019-03-06T18:49:22.736Z] 18:49:22 INFO - PID 18064 | 338 14872 _PR_Getfd
[task 2019-03-06T18:49:22.736Z] 18:49:22 INFO - PID 18064 | 1 29 libglib-2.0.so
[task 2019-03-06T18:49:22.736Z] 18:49:22 INFO - PID 18064 | -----------------------------------------------------
[task 2019-03-06T18:49:22.857Z] 18:49:22 INFO - Browser exited with return code 0
[task 2019-03-06T18:49:22.858Z] 18:49:22 INFO - PROCESS LEAKS None
[task 2019-03-06T18:49:22.859Z] 18:49:22 INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 3216 byte(s) leaked in 27 allocation(s).
[task 2019-03-06T18:49:22.859Z] 18:49:22 INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2019-03-06T18:49:22.859Z] 18:49:22 INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2019-03-06T18:49:22.859Z] 18:49:22 INFO - Allowed depth was 4
[task 2019-03-06T18:49:22.860Z] 18:49:22 INFO - TEST-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, nsTSubstring, nsTSubstring
[task 2019-03-06T18:49:22.860Z] 18:49:22 INFO - INFO | LeakSanitizer | Frame Alloc matched a expected leak
[task 2019-03-06T18:49:22.861Z] 18:49:22 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::dom::WebSocket::WebSocket, mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket_Binding::_constructor, CallJSNative
[task 2019-03-06T18:49:22.862Z] 18:49:22 INFO - INFO | LeakSanitizer | Frame mozilla::dom::WebSocket::WebSocket matched a expected leak
[task 2019-03-06T18:49:22.862Z] 18:49:22 INFO - TEST-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, Gecko_StartBulkWriteString, nsstring::nsAString::start_bulk_write_impl
[task 2019-03-06T18:49:22.862Z] 18:49:22 INFO - INFO | LeakSanitizer | Frame Alloc matched a expected leak
[task 2019-03-06T18:49:22.863Z] 18:49:22 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::net::WebSocketChannelChild::AsyncOpen, mozilla::dom::WebSocketImpl::AsyncOpen, mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket_Binding::_constructor

This is a very confusing bug. I can't find any instance of CookieSettings::Create in the tree.
I this something that bounced from m-c?

This is from bug 1525245 , Andreea please take a look.

Retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Casan%2Cweb%2Cplatform%2Ctests%2Cwith%2Ce10s%2Ctest-linux64-asan%2Fopt-web-platform-tests-e10s-7%2Cw-e10s%28wpt7%29&tochange=9f8a1b41032052121d45540b57db45710011820e&fromchange=34f94fc00f2191bfd709eb87d8cc367a80b5f0f1&group_state=expanded&selectedJob=232210638

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=232946145&repo=autoland&lineNumber=19538

[task 2019-03-10T00:34:40.745Z] 00:34:40 INFO - TEST-START | /websockets/referrer.any.worker.html
[task 2019-03-10T00:34:40.754Z] 00:34:40 INFO - Closing window 358629769217
[task 2019-03-10T00:34:41.556Z] 00:34:41 INFO - PID 20484 | =================================================================
[task 2019-03-10T00:34:41.557Z] 00:34:41 INFO - PID 20484 | LeakSanitizer: detected memory leaks
[task 2019-03-10T00:34:41.557Z] 00:34:41 INFO - PID 20484 | Indirect leak of 1176 byte(s) in 3 object(s) allocated from:
[task 2019-03-10T00:34:41.560Z] 00:34:41 INFO - PID 20484 | #0 0x55b338a6b953 in malloc /builds/worker/workspace/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:146:3
[task 2019-03-10T00:34:41.560Z] 00:34:41 INFO - PID 20484 | #1 0x55b338aa017d in moz_xmalloc /builds/worker/workspace/build/src/memory/mozalloc/mozalloc.cpp:68:15
[task 2019-03-10T00:34:41.561Z] 00:34:41 INFO - PID 20484 | #2 0x7f6ab256ee95 in operator new /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/mozalloc.h:131:10
[task 2019-03-10T00:34:41.561Z] 00:34:41 INFO - PID 20484 | #3 0x7f6ab256ee95 in mozilla::net::BaseWebSocketChannel::InitLoadInfo(nsINode*, nsIPrincipal*, nsIPrincipal*, unsigned int, unsigned int) /builds/worker/workspace/build/src/netwerk/protocol/websocket/BaseWebSocketChannel.cpp:207
[task 2019-03-10T00:34:41.564Z] 00:34:41 INFO - PID 20484 | #4 0x7f6ab97e23eb in mozilla::dom::WebSocketImpl::InitializeConnection(nsIPrincipal*) /builds/worker/workspace/build/src/dom/websocket/WebSocket.cpp:1720:19
[task 2019-03-10T00:34:41.565Z] 00:34:41 INFO - PID 20484 | #5 0x7f6ab97dca91 in mozilla::dom::WebSocket::ConstructorCommon(mozilla::dom::GlobalObject const&, nsTSubstring<char16_t> const&, mozilla::dom::Sequence<nsTString<char16_t> > const&, nsITransportProvider*, nsTSubstring<char> const&, mozilla::ErrorResult&) /builds/worker/workspace/build/src/dom/websocket/WebSocket.cpp:1262:9
[task 2019-03-10T00:34:41.566Z] 00:34:41 INFO - PID 20484 | #6 0x7f6ab97dbfd3 in mozilla::dom::WebSocket::Constructor(mozilla::dom::GlobalObject const&, nsTSubstring<char16_t> const&, mozilla::ErrorResult&) /builds/worker/workspace/build/src/dom/websocket/WebSocket.cpp:923:10
[task 2019-03-10T00:34:41.566Z] 00:34:41 INFO - PID 20484 | #7 0x7f6ab6890aa1 in mozilla::dom::WebSocket_Binding::_constructor(JSContext*, unsigned int, JS::Value*) /builds/worker/workspace/build/src/obj-firefox/dom/bindings/WebSocketBinding.cpp:1122:59
[task 2019-03-10T00:34:41.566Z] 00:34:41 INFO - PID 20484 | #8 0x7f6abd9ce49f in CallJSNative /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:442:13

[task 2019-03-10T00:34:45.790Z] 00:34:45 INFO - Browser exited with return code 0
[task 2019-03-10T00:34:45.792Z] 00:34:45 INFO - PROCESS LEAKS None
[task 2019-03-10T00:34:45.793Z] 00:34:45 INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 7292 byte(s) leaked in 55 allocation(s).
[task 2019-03-10T00:34:45.797Z] 00:34:45 INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2019-03-10T00:34:45.798Z] 00:34:45 INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2019-03-10T00:34:45.798Z] 00:34:45 INFO - Allowed depth was 4
[task 2019-03-10T00:34:45.798Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, nsTSubstring, nsTSubstring
[task 2019-03-10T00:34:45.798Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame Alloc matched a expected leak
[task 2019-03-10T00:34:45.798Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::dom::WebSocket::WebSocket, mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket::Constructor, mozilla::dom::WebSocket_Binding::_constructor
[task 2019-03-10T00:34:45.799Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::dom::WebSocket::WebSocket matched a expected leak
[task 2019-03-10T00:34:45.799Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, Gecko_StartBulkWriteString, nsstring::nsAString::start_bulk_write_impl
[task 2019-03-10T00:34:45.800Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame Alloc matched a expected leak
[task 2019-03-10T00:34:45.800Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, nsTSubstring, mozilla::net::nsStandardURL::BuildNormalizedSpec
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame Alloc matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::net::WebSocketEventService::GetOrCreate, mozilla::dom::WebSocketImpl::Init, mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket::Constructor
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::net::WebSocketEventService::GetOrCreate matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::WeakPtr, WeakPtr, mozilla::Maybe, mozilla::ContentPrincipal::AddonPolicy
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::WeakPtr matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::net::WebSocketChannelChild::AsyncOpen, mozilla::dom::WebSocketImpl::AsyncOpen, mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket::Constructor
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::net::WebSocketChannelChild::AsyncOpen matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::net::nsStandardURL::TemplatedMutator, Init, mozilla::net::nsStandardURL::TemplatedMutator, operator
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::net::nsStandardURL::TemplatedMutator matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at nsSupportsWeakReference::GetWeakReference, NS_GetWeakReference, do_GetWeakReference, mozilla::dom::Document::ResetToURI
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame nsSupportsWeakReference::GetWeakReference matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket::Constructor, mozilla::dom::WebSocket_Binding::_constructor, CallJSNative
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::dom::WebSocket::ConstructorCommon matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::SchedulerGroup::CreateEventTargetFor, mozilla::SchedulerGroup::CreateEventTargets, mozilla::dom::TabGroup::TabGroup, mozilla::dom::ContentChild::GetConstructedEventTarget
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::SchedulerGroup::CreateEventTargetFor matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, Gecko_StartBulkWriteCString, nsstring::nsACString::start_bulk_write_impl
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame Alloc matched a expected leak
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::net::CookieSettings::Create, mozilla::net::LoadInfo::LoadInfo, nsDocShell::DoURILoad, nsDocShell::InternalLoad
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - TEST-FAIL | LeakSanitizer | leak at mozilla::net::BaseWebSocketChannel::InitLoadInfo, mozilla::dom::WebSocketImpl::InitializeConnection, mozilla::dom::WebSocket::ConstructorCommon, mozilla::dom::WebSocket::Constructor
[task 2019-03-10T00:34:45.801Z] 00:34:45 INFO - INFO | LeakSanitizer | Frame mozilla::net::BaseWebSocketChannel::InitLoadInfo matched a expected leak

Flags: needinfo?(amarchesini)

This seems to be a dup of bug 1516300.

Flags: needinfo?(amarchesini)

(In reply to Andrea Marchesini [:baku] from comment #7)

This seems to be a dup of bug 1516300.

It's just that bug 1516300 had very small failure rates. This one leaks quite often.

Andrea any plans on fixing this? failure rate is very high.

There are 267 total failures in the last 7 days all on linux64 asan

Flags: needinfo?(amarchesini)

I looked in some logs and this cannot be disabled as it is leaking in different test files. Removing the disable-recommended tag, waiting on reply from Andrea.

Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

Failure rate seems to have decreased starting with the 18th of March.

Whiteboard: [stockwell disable-recommended] → [stockwell needswork]
Whiteboard: [stockwell disable-recommended] → [stockwell needswork]

There are 2 total failures in the last 7 days.

Flags: needinfo?(amarchesini)
Whiteboard: [stockwell disable-recommended] → [stockwell unknown]

The priority flag is not set for this bug.
:michal, could you have a look please?

Flags: needinfo?(michal.novotny)
See Also: → 1535792

Low rate: P3.

Priority: -- → P3
Whiteboard: [stockwell unknown] → [stockwell unknown][necko-triaged]
Flags: needinfo?(michal.novotny)

Bulk closing some old intermittents.

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