Intermittent LeakSanitizer | leak at mozilla::net::AddStaticElement, AddStaticElement, InitializeStaticHeaders, mozilla::net::nvFIFO::nvFIFO
Categories
(Core :: Networking: HTTP, defect, P1)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr91 | --- | unaffected |
firefox99 | --- | unaffected |
firefox100 | --- | wontfix |
firefox101 | --- | wontfix |
People
(Reporter: intermittent-bug-filer, Assigned: valentin)
References
(Depends on 1 open bug, Blocks 1 open bug, Regression)
Details
(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [stockwell unknown][necko-triaged])
Attachments
(2 obsolete files)
Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=373266187&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KjgtngrmT_ydlCKUGoG7-Q/runs/0/artifacts/public/logs/live_backing.log
[task 2022-04-04T12:25:33.406Z] 12:25:33 INFO - PID 18606 | Direct leak of 32 byte(s) in 1 object(s) allocated from:
[task 2022-04-04T12:25:33.406Z] 12:25:33 INFO - PID 18606 | #0 0x557fd54a2e6d in malloc /builds/worker/fetches/llvm-project/compiler-rt/lib/asan/asan_malloc_linux.cpp:129:3
[task 2022-04-04T12:25:33.407Z] 12:25:33 INFO - PID 18606 | #1 0x557fd54ddd1d in moz_xmalloc /builds/worker/checkouts/gecko/memory/mozalloc/mozalloc.cpp:52:15
[task 2022-04-04T12:25:33.407Z] 12:25:33 INFO - PID 18606 | #2 0x7fcc4c095999 in operator new /builds/worker/workspace/obj-build/dist/include/mozilla/cxxalloc.h:33:10
[task 2022-04-04T12:25:33.408Z] 12:25:33 INFO - PID 18606 | #3 0x7fcc4c095999 in mozilla::net::AddStaticElement(nsTString<char> const&, nsTString<char> const&) /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Compression.cpp:96:18
[task 2022-04-04T12:25:33.408Z] 12:25:33 INFO - PID 18606 | #4 0x7fcc4c0183af in InitializeStaticHeaders /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Compression.cpp:115:5
[task 2022-04-04T12:25:33.409Z] 12:25:33 INFO - PID 18606 | #5 0x7fcc4c0183af in mozilla::net::nvFIFO::nvFIFO() /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Compression.cpp:183:20
[task 2022-04-04T12:25:33.409Z] 12:25:33 INFO - PID 18606 | #6 0x7fcc4c01b9d3 in mozilla::net::Http2BaseCompressor::Http2BaseCompressor() /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Compression.cpp:234:22
[task 2022-04-04T12:25:33.410Z] 12:25:33 INFO - PID 18606 | #7 0x7fcc4c03aabd in mozilla::net::Http2Compressor::Http2Compressor() /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Compression.h:155:3
[task 2022-04-04T12:25:33.410Z] 12:25:33 INFO - PID 18606 | #8 0x7fcc4c039ab5 in mozilla::net::Http2Session::Http2Session(nsISocketTransport*, mozilla::net::SpdyVersion, bool) /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Session.cpp:110:15
[task 2022-04-04T12:25:33.411Z] 12:25:33 INFO - PID 18606 | #9 0x7fcc4c0389db in mozilla::net::Http2Session::CreateSession(nsISocketTransport*, mozilla::net::SpdyVersion, bool) /builds/worker/checkouts/gecko/netwerk/protocol/http/Http2Session.cpp:105:11
[task 2022-04-04T12:25:33.411Z] 12:25:33 INFO - PID 18606 | #10 0x7fcc4c24347a in mozilla::net::nsHttpConnection::StartSpdy(nsISSLSocketControl*, mozilla::net::SpdyVersion) /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnection.cpp:292:9
[task 2022-04-04T12:25:33.412Z] 12:25:33 INFO - PID 18606 | #11 0x7fcc4c259c1f in mozilla::net::nsHttpConnection::HandshakeDoneInternal() /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnection.cpp
[task 2022-04-04T12:25:33.412Z] 12:25:33 INFO - PID 18606 | #12 0x7fcc4c2c9a5a in operator() /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnection.cpp:2543:19
[task 2022-04-04T12:25:33.413Z] 12:25:33 INFO - PID 18606 | #13 0x7fcc4c2c9a5a in mozilla::detail::RunnableFunction<mozilla::net::nsHttpConnection::HandshakeDone()::$_0>::Run() /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:531:5
[task 2022-04-04T12:25:33.413Z] 12:25:33 INFO - PID 18606 | #14 0x7fcc4b4b41cf in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1181:16
[task 2022-04-04T12:25:33.413Z] 12:25:33 INFO - PID 18606 | #15 0x7fcc4b4bd98c in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:465:10
[task 2022-04-04T12:25:33.414Z] 12:25:33 INFO - PID 18606 | #16 0x7fcc4b86f8f1 in mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:1202:11
[task 2022-04-04T12:25:33.414Z] 12:25:33 INFO - PID 18606 | #17 0x7fcc4b87154c in non-virtual thunk to mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp
[task 2022-04-04T12:25:33.415Z] 12:25:33 INFO - PID 18606 | #18 0x7fcc4b4b41cf in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1181:16
[task 2022-04-04T12:25:33.415Z] 12:25:33 INFO - PID 18606 | #19 0x7fcc4b4bd98c in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:465:10
[task 2022-04-04T12:25:33.416Z] 12:25:33 INFO - PID 18606 | #20 0x7fcc4c7978a8 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:300:20
[task 2022-04-04T12:25:33.416Z] 12:25:33 INFO - PID 18606 | #21 0x7fcc4c6a3061 in RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:380:10
[task 2022-04-04T12:25:33.417Z] 12:25:33 INFO - PID 18606 | #22 0x7fcc4c6a3061 in RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:373:3
[task 2022-04-04T12:25:33.417Z] 12:25:33 INFO - PID 18606 | #23 0x7fcc4c6a3061 in MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:355:3
[task 2022-04-04T12:25:33.418Z] 12:25:33 INFO - PID 18606 | #24 0x7fcc4b4ac6fc in nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:385:10
[task 2022-04-04T12:25:33.418Z] 12:25:33 INFO - PID 18606 | #25 0x7fcc6cba0ade in _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5
[task 2022-04-04T12:25:33.418Z] 12:25:33 INFO - PID 18606 | #26 0x7fcc6e85d6da in start_thread /tmp/glibc/nptl/pthread_create.c:463
[task 2022-04-04T12:25:33.419Z] 12:25:33 INFO - PID 18606 | -----------------------------------------------------
[task 2022-04-04T12:25:33.419Z] 12:25:33 INFO - PID 18606 | Suppressions used:
[task 2022-04-04T12:25:33.420Z] 12:25:33 INFO - PID 18606 | count bytes template
[task 2022-04-04T12:25:33.420Z] 12:25:33 INFO - PID 18606 | 9 280 nsComponentManagerImpl
[task 2022-04-04T12:25:33.421Z] 12:25:33 INFO - PID 18606 | 631 18073 libfontconfig.so
[task 2022-04-04T12:25:33.421Z] 12:25:33 INFO - PID 18606 | 4 16407 libglib-2.0.so
[task 2022-04-04T12:25:33.421Z] 12:25:33 INFO - PID 18606 | 1 192 mozJSComponentLoader
[task 2022-04-04T12:25:33.421Z] 12:25:33 INFO - PID 18606 | 2 48 XPCWrappedNativeJSOps
[task 2022-04-04T12:25:33.422Z] 12:25:33 INFO - PID 18606 | -----------------------------------------------------
[task 2022-04-04T12:25:33.422Z] 12:25:33 INFO - PID 18606 | 1649075132911 geckodriver::browser DEBUG Browser process stopped: exit status: 0
[task 2022-04-04T12:25:33.423Z] 12:25:33 INFO - PID 18606 | 1649075132911 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2022-04-04T12:25:33.423Z] 12:25:33 INFO - PID 18606 | 1649075132930 webdriver::server DEBUG -> GET /status
[task 2022-04-04T12:25:33.423Z] 12:25:33 INFO - PID 18606 | 1649075132930 webdriver::server DEBUG <- 200 OK {"value":{"message":"","ready":true}}
[task 2022-04-04T12:25:33.424Z] 12:25:33 INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 1952 byte(s) leaked in 61 allocation(s).
[task 2022-04-04T12:25:33.424Z] 12:25:33 INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2022-04-04T12:25:33.424Z] 12:25:33 INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2022-04-04T12:25:33.424Z] 12:25:33 INFO - Allowed depth was 4
[task 2022-04-04T12:25:33.425Z] 12:25:33 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::net::AddStaticElement, AddStaticElement, InitializeStaticHeaders, mozilla::net::nvFIFO::nvFIFO
[task 2022-04-04T12:25:33.425Z] 12:25:33 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::net::AddStaticElement, InitializeStaticHeaders, mozilla::net::nvFIFO::nvFIFO, mozilla::net::Http2BaseCompressor::Http2BaseCompressor
[task 2022-04-04T12:25:33.426Z] 12:25:33 INFO - Closing logging queue
[task 2022-04-04T12:25:33.427Z] 12:25:33 INFO - queue closed
[task 2022-04-04T12:25:33.869Z] 12:25:33 INFO - PID 18921 | 1649075133367 geckodriver INFO Listening on 127.0.0.1:53319
[task 2022-04-04T12:25:33.869Z] 12:25:33 INFO - Starting runner
[task 2022-04-04T12:25:34.122Z] 12:25:34 INFO - TEST-START | /_mozilla/webdriver/take_full_screenshot/iframe.py
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 3•2 years ago
|
||
Set release status flags based on info from the regressing bug 1755767
Comment 4•2 years ago
|
||
:dragana, since you are the author of the regressor, bug 1755767, could you take a look?
For more information, please visit auto_nag documentation.
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment 9•2 years ago
•
|
||
Dragana, when and where was it fixed? If you would have a reference that would be great. I'm asking because we recently had such a leak in a beta simulation for 107b12:
Note that the wdspec issues are tracked via bug 1759310 whereby it's not happening that often anymore because we have exceptions for these leaks in place for now:
https://searchfox.org/mozilla-central/source/testing/web-platform/meta/webdriver/tests/__dir__.ini
Updated•2 years ago
|
Comment 10•2 years ago
|
||
Reopening given that this is not fixed but only accepted via manifest files. Leaving needinfo for Dragana.
Comment 11•2 years ago
|
||
Valentin maybe you could help here? Thanks a lot.
Assignee | ||
Comment 12•2 years ago
|
||
Dragana has an idea how to fix this.
Comment 13•2 years ago
|
||
Currently, NSS calls the handshake completed callback function, HandshakeCallback from nsNSSCallbacks.cpp. HandshakeCallback calls nsNSSSocketInfo::SetHandshakeCompleted that calls TlsHandshaker::HandshakeDone. All of this is happening while NSS holds a lock. When a handshake is done, necko may need to finish setting up Http/2Session(in the nsHttpConnection::HandshakeDoneInternal) and for that it needs info from NSS, but NSS holds the lock and that is not possible. To resolve this problem necko sets TlsHandshakerTlsHandshaker::mTlsHandshakeComplitionPending to true and dispatches a runnable that will call nsHttpConnection::HandshakeDoneInternal). This dispatch causes bug 1762911, probably due to a shutdown happening just before the runnable is executed.
To resolve the issue and to better integrate HandshakeDoneInternal into necko we will do the following:
TlsHandshaker::HandshakeDone will set mTlsHandshakeComplitionPending to true and call nsHttpConnection::ForceSend. The nsHttpConnection::ForceSend function is a better way to force the handshake to be finished because it is taking already existing standard necko code paths.
nsHttpConnection::ForceSend calls nsHttoConnection::OnOutputStreamReady that will call TlsHandshaker::Ensure NPNComplete that will call nsHttpConnection::HandshakeDoneInternal.
Updated•2 years ago
|
Comment 14•2 years ago
|
||
Comment 15•2 years ago
|
||
The patch I have created does not resolve the issue. The leak still exists, but this time the stack is called from nsSockettransportService while iterating through sockets that are ready to read or write. This stack shows that the original theory is not entirely correct.
I have landed the patch that I created anyway because I think the patch is the more appropriate way to deal with this case.
Comment 16•2 years ago
|
||
Marking the bug leave-open because the current patch does not fix the issue.
Comment 17•2 years ago
|
||
Comment 18•2 years ago
|
||
I will not have time to work on this bug, so I am unassigning myself.
Comment 19•2 years ago
|
||
Pushed by ddamjanovic@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/2c4c34f31021 Change how necko finishes TLS handshake r=necko-reviewers,kershaw
Comment 20•2 years ago
|
||
Backed out for causing xpcshell failures at test_servers.js.
Backout link: https://hg.mozilla.org/integration/autoland/rev/9c5cc040ce0cda90686ed7218b508e8b1320ddc3
Failure log:
https://treeherder.mozilla.org/logviewer?job_id=393727028&repo=autoland&lineNumber=4003
https://treeherder.mozilla.org/logviewer?job_id=393742939&repo=autoland&lineNumber=2046
Comment 21•2 years ago
|
||
Valentin, would someone of the necko team be able to continue this work including a fix for the crash which caused Dragana's patch to get backed out?
Assignee | ||
Comment 22•2 years ago
|
||
Yes, I'll have a look.
Updated•2 years ago
|
Assignee | ||
Comment 24•2 years ago
|
||
mTlsHandshaker->EnsureNPNComplete() may change nsHttpConnection::mState.
Calling SendConnectRequest() requires that we are in the SETTING_UP_TUNNEL.
As such, we should move the call to EnsureNPNComplete, to ensure we never
call SendConnectRequest when mProxyConnectStream is null.
Depends on D159078
Comment 25•2 years ago
|
||
There are some r+ patches which didn't land and no activity in this bug for 2 weeks.
:valentin, could you have a look please?
If you still have some work to do, you can add an action "Plan Changes" in Phabricator.
For more information, please visit auto_nag documentation.
Updated•2 years ago
|
Comment 26•2 years ago
|
||
Comment on attachment 9298055 [details]
Bug 1762911 - Change how necko finishes TLS handshake
Revision D159078 was moved to bug 1801292. Setting attachment 9298055 [details] to obsolete.
Comment 27•2 years ago
|
||
Comment on attachment 9301295 [details]
Bug 1762911 - SendConnectRequest should only be called when mState==SETTING_UP_TUNNEL r=#necko
Revision D160892 was moved to bug 1801292. Setting attachment 9301295 [details] to obsolete.
Assignee | ||
Updated•2 years ago
|
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) |
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) |
Description
•