Intermittent leakcheck | tab XXXXX bytes leaked (ChannelEventQueue, DOMEventTargetHelper, ListenerAndContextContainer, LoadInfo, Mutex, ...)

NEW
Unassigned

Status

()

defect
P5
normal
5 months ago
a month ago

People

(Reporter: intermittent-bug-filer, Unassigned)

Tracking

({intermittent-failure, leave-open})

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [retriggered][stockwell disabled])

Attachments

(1 attachment)

Reporter

Description

5 months ago
treeherder
Filed by: ebalazs [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=216585758&repo=mozilla-inbound

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

TEST-INFO | leakcheck | tab leaked 66 nsTArray_base
[task 2018-12-12T13:36:33.468Z] 13:36:33     INFO - TEST-INFO | leakcheck | tab leaked 3 nsWeakReference
[task 2018-12-12T13:36:33.470Z] 13:36:33     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 21260 bytes leaked (ChannelEventQueue, DOMEventTargetHelper, ListenerAndContextContainer, LoadInfo, Mutex, ...)
[task 2018-12-12T13:36:33.470Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.471Z] 13:36:33     INFO - leakcheck | Processing leak log file /tmp/tmpki7WCK.mozrunner/runtests_leaks_854.log
[task 2018-12-12T13:36:33.471Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.472Z] 13:36:33     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 11407
[task 2018-12-12T13:36:33.472Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.473Z] 13:36:33     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2018-12-12T13:36:33.474Z] 13:36:33     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2018-12-12T13:36:33.474Z] 13:36:33     INFO -    0 |TOTAL                                 |       41        0|19690637        0|
[task 2018-12-12T13:36:33.475Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.475Z] 13:36:33     INFO - nsTraceRefcnt::DumpStatistics: 2017 entries
[task 2018-12-12T13:36:33.476Z] 13:36:33     INFO - TEST-PASS | leakcheck | default no leaks detected!
[task 2018-12-12T13:36:33.476Z] 13:36:33     INFO - leakcheck | Processing leak log file /tmp/tmpki7WCK.mozrunner/runtests_leaks_854_tab_pid11481.log
[task 2018-12-12T13:36:33.477Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.479Z] 13:36:33     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 11481
[task 2018-12-12T13:36:33.479Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.480Z] 13:36:33     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2018-12-12T13:36:33.480Z] 13:36:33     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2018-12-12T13:36:33.481Z] 13:36:33     INFO -    0 |TOTAL                                 |       41        0|   58335        0|
[task 2018-12-12T13:36:33.481Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.482Z] 13:36:33     INFO - nsTraceRefcnt::DumpStatistics: 799 entries
[task 2018-12-12T13:36:33.482Z] 13:36:33     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2018-12-12T13:36:33.483Z] 13:36:33     INFO - leakcheck | Processing leak log file /tmp/tmpki7WCK.mozrunner/runtests_leaks_854_tab_pid11554.log
[task 2018-12-12T13:36:33.484Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.484Z] 13:36:33     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 11554
[task 2018-12-12T13:36:33.485Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.486Z] 13:36:33     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2018-12-12T13:36:33.486Z] 13:36:33     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2018-12-12T13:36:33.487Z] 13:36:33     INFO -    0 |TOTAL                                 |       45        0|   17993        0|
[task 2018-12-12T13:36:33.487Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.488Z] 13:36:33     INFO - nsTraceRefcnt::DumpStatistics: 452 entries
[task 2018-12-12T13:36:33.490Z] 13:36:33     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2018-12-12T13:36:33.491Z] 13:36:33     INFO - Closing logging queue
[task 2018-12-12T13:36:33.492Z] 13:36:33     INFO - queue closed
[task 2018-12-12T13:36:33.501Z] 13:36:33     INFO - Setting up ssl
[task 2018-12-12T13:36:33.538Z] 13:36:33     INFO - certutil | 
[task 2018-12-12T13:36:33.574Z] 13:36:33     INFO - certutil | 
[task 2018-12-12T13:36:33.595Z] 13:36:33     INFO - certutil | 
[task 2018-12-12T13:36:33.595Z] 13:36:33     INFO - Certificate Nickname                                         Trust Attributes
[task 2018-12-12T13:36:33.596Z] 13:36:33     INFO -                                                              SSL,S/MIME,JAR/XPI
[task 2018-12-12T13:36:33.596Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.596Z] 13:36:33     INFO - web-platform-tests                                           CT,, 
[task 2018-12-12T13:36:33.596Z] 13:36:33     INFO - 
[task 2018-12-12T13:36:33.612Z] 13:36:33     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpIBG6w4.mozrunner
[task 2018-12-12T13:36:33.628Z] 13:36:33     INFO - Starting runner
[task 2018-12-12T13:36:33.652Z] 13:36:33     INFO - PID 11711 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpIBG6w4.mozrunner/runtests_leaks_854.log
Comment hidden (Intermittent Failures Robot)
Summary: Intermittent leakcheck | tab 21260 bytes leaked (ChannelEventQueue, DOMEventTargetHelper, ListenerAndContextContainer, LoadInfo, Mutex, ...) → Intermittent leakcheck | tab XXXXX bytes leaked (ChannelEventQueue, DOMEventTargetHelper, ListenerAndContextContainer, LoadInfo, Mutex, ...)
as a note, this is leaking on the https://searchfox.org/mozilla-central/source/testing/web-platform/tests/infrastructure/server directory and luckily with the link above it doesn't seem to move between chunks- so the retriggers on chunk 14 are useful.

2 failures out of 50 runs is a low failure rate, osx seems to have a higher failure rate, maybe we can look there?  I would also like a larger window to show a few pushes with frequent failures and a  few without.
Flags: needinfo?(jmaher)
Continued with the retriggers up until here http://tinyurl.com/y8c2k23z. Looks like the failure started on autoland and couple of days before this bug was filed.
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Added more retriggers to the link provided by Cosmin above.
Whiteboard: [stockwell disable-recommended] → [retrigger][stockwell disable-recommended]
I r/b this on OS X 10.10 debug (wpt16) and Linux x64 debug (wpt14) and found a first wpt14 failure from the 10th of December on fa0a179388e9 https://bugzilla.mozilla.org/show_bug.cgi?id=1512459

https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=pending%2Crunning%2Ctestfailed%2Cbusted%2Cexception%2Cretry%2Crunnable&tochange=cd3b56196f095bd95733b419a5ecdd93381570be&searchStr=wpt&fromchange=c10d57e490762a628dcb53d44449ea2e9de919ca&selectedJob=217390643

jmaher: Hi, can you have a look at this result? and if this is not related can you please advise how to disable it? Thank you!
Flags: needinfo?(jmaher)
Whiteboard: [retrigger][stockwell disable-recommended] → [retriggered][stockwell disable-recommended]
:ebalazs_, I don't see retriggers prior to fa0a179388e9, I would like to see more data showing failures and no failures.  I see 1/20 failures on fa0a179388e9  and cd3b56196f09, but only one instance of wpt16 on the previous commits, can you collect more data on the two previous pushes?  Unfortunately this takes 70+ minutes; I would like to see 2 failures/platform instead of 1, so I assume we need another 10-20 for the existing pushes and 30-40 for the 2 previous pushes.
Flags: needinfo?(jmaher)
for many of the failures, it is fixed a day or so later in bug 1512116 (7 of the failures).  The other failures (14) seem to be mostly related to infrastructure/server/wpt-server-websocket.sub.html and 4 others are random.

I came to this conclusion by examining each log file and keeping notes, I did:
1) open file
2) search for TEST-UNEX (find the matching leak line)
3) search for TEST-OK
4) search backwards (up in the document) for TEST-OK
5) record the testname as that is the last TEST-OK we saw before the leak

Given that we run tests in a directory in the same browser session, something in infrastructure/server/* is leaking and we could apply similar logic to:
https://searchfox.org/mozilla-central/source/testing/web-platform/meta/infrastructure/server/__dir__.ini

I would copy the changes from bug 1512116:
https://hg.mozilla.org/integration/autoland/rev/d9a3b54ccbf3

and apply those to the __dir__.ini referenced in this comment.

Eliza, would you like to write up a patch?
Flags: needinfo?(jmaher) → needinfo?(ebalazs)
Sure, I created the patch as suggested. Thank you for the help :)
Flags: needinfo?(ebalazs)
Attachment #9033531 - Flags: review?(jmaher)
Attachment #9033531 - Flags: review?(jmaher) → review+
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell disabled]

Comment 15

5 months ago
Pushed by nbeleuzu@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/95778cef33dd
Allow tab leaks for infrastucture tests. r=jmaher
Keywords: checkin-needed
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)
You need to log in before you can comment on or make changes to this bug.