Closed Bug 1325438 Opened 3 years ago Closed 3 years ago

highly intermittent leak in mochitest plain tests/dom/xhr/tests

Categories

(Core :: DOM: Core & HTML, defect, P1)

defect

Tracking

()

RESOLVED FIXED
mozilla53
Tracking Status
firefox51 + unaffected
firefox52 + unaffected
firefox53 + fixed

People

(Reporter: jmaher, Assigned: mccr8)

References

Details

(Whiteboard: [MemShrink])

Attachments

(1 file)

we have not been showing leaks in mochitests recently due to an error in structured logs.  Because of that we have a handful of leaks.

this appears only on linux32 debug (non e10s):
https://treeherder.mozilla.org/#/jobs?repo=try&revision=8a0da8521414bfcd53df7f7c9abb88c8995771a2&group_state=expanded&selectedJob=33322440&filter-searchStr=mochitest-7

I see it enough that we are going to whitelist this so it doesn't show up in our normal results for leakchecking.

here is a snippet from a failure on the above try push:
07:14:13     INFO - Leaked URLs:
07:14:13     INFO -   http://127.0.0.1:8888/experiments-dummy/manifest
07:14:13     INFO - nsStringStats
07:14:13     INFO -  => mAllocCount:         217017
07:14:13     INFO -  => mReallocCount:        31069
07:14:13     INFO -  => mFreeCount:          216941  --  LEAKED 76 !!!
07:14:13     INFO -  => mShareCount:         195706
07:14:13     INFO -  => mAdoptCount:          19611
07:14:13     INFO -  => mAdoptFreeCount:      19609  --  LEAKED 2 !!!
07:14:13     INFO -  => Process ID: 3512, Thread ID: 3074447104
07:14:13     INFO - TEST-INFO | Main app process: exit 0
07:14:13     INFO - runtests.py | Application ran for: 0:06:40.792119
07:14:13     INFO - zombiecheck | Reading PID log: /tmp/tmpdkEMLvpidlog
07:14:13     INFO - ==> process 3512 launched child process 3532
07:14:13     INFO - zombiecheck | Checking for orphan process with PID: 3532
07:14:13     INFO - Stopping web server
07:14:13     INFO - Stopping web socket server
07:14:13     INFO - Stopping ssltunnel
07:14:13     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
07:14:13     INFO - TEST-INFO | leakcheck | plugin process: leak threshold set at 0 bytes
07:14:13     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 10000 bytes
07:14:13     INFO - TEST-INFO | leakcheck | geckomediaplugin process: leak threshold set at 20000 bytes
07:14:13     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
07:14:13     INFO - 
07:14:13     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 3512
07:14:13     INFO - 
07:14:13     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
07:14:13     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
07:14:13     INFO -    0 |TOTAL                                 |       19    13094| 4939978      295|
07:14:13     INFO -   33 |BackstagePass                         |       52      260|     333        5|
07:14:13     INFO -   64 |CacheEntry                            |      160      160|     245        1|
07:14:13     INFO -   67 |CacheEntryHandle                      |       16       16|    3336        1|
07:14:13     INFO -   68 |CacheFile                             |      232      232|     245        1|
07:14:13     INFO -   72 |CacheFileHandle                       |       68       68|     245        1|
07:14:13     INFO -   76 |CacheFileMetadata                     |      160      160|     245        1|
07:14:13     INFO -   84 |CacheStorageService                   |      188      188|       1        1|
07:14:13     INFO -   89 |CallbackObject                        |       28      112|    3074        4|
07:14:13     INFO -  126 |CondVar                               |       24      264|     878       11|
07:14:13     INFO -  142 |ConsoleReportCollector                |       36       36|    1162        1|
07:14:13     INFO -  156 |DOMEventTargetHelper                  |       40       40|     996        1|
07:14:13     INFO -  180 |DataStorage                           |      220      660|       3        3|
07:14:13     INFO -  224 |EventListenerManager                  |       92       92|    1726        1|
07:14:13     INFO -  301 |HttpBaseChannel                       |      940      940|     760        1|
07:14:13     INFO -  318 |IdlePeriod                            |       12       48|      73        4|
07:14:13     INFO -  339 |JSEventHandler                        |       24       96|    1169        4|
07:14:13     INFO -  356 |LoadInfo                              |      140      140|    2841        1|
07:14:13     INFO -  387 |Mutex                                 |       20      500|    8301       25|
07:14:13     INFO -  466 |PollableEvent                         |       12       12|       1        1|
07:14:13     INFO -  487 |ProtoAndIfaceCache                    |        8       40|     486        5|
07:14:13     INFO -  505 |ReentrantMonitor                      |       24      120|    3505        5|
07:14:13     INFO -  512 |RequestContextService                 |       56       56|       1        1|
07:14:13     INFO -  547 |Service                               |       80       80|       1        1|
07:14:13     INFO -  574 |StringAdopt                           |        1        2|   19611        2|
07:14:13     INFO -  600 |ThirdPartyUtil                        |       16       16|       1        1|
07:14:13     INFO -  628 |UrlClassifierLookupCallbackProxy      |       16       16|     652        1|
07:14:13     INFO -  682 |XMLHttpRequestEventTarget             |       44       44|     744        1|
07:14:13     INFO -  683 |XMLHttpRequestMainThread              |      384      384|     513        1|
07:14:13     INFO -  685 |XMLHttpRequestStringBuffer            |       40       40|    2122        1|
07:14:13     INFO -  690 |XPCNativeInterface                    |       28       28|    2952        1|
07:14:13     INFO -  691 |XPCNativeMember                       |        8        8|   68780        1|
07:14:13     INFO -  692 |XPCNativeScriptableInfo               |        4       20|    4318        5|
07:14:13     INFO -  693 |XPCNativeSet                          |       16       16|    1965        1|
07:14:13     INFO -  695 |XPCWrappedNative                      |       48      240|   20885        5|
07:14:13     INFO -  696 |XPCWrappedNativeProto                 |       20      100|    5419        5|
07:14:13     INFO -  699 |XPCWrappedNativeTearOff               |       16       80|   28363        5|
07:14:13     INFO -  781 |nsAuthURLParser                       |       12       12|       2        1|
07:14:13     INFO -  838 |nsCategoryObserver                    |       64       64|      10        1|
07:14:13     INFO -  841 |nsChannelClassifier                   |       32       32|     769        1|
07:14:13     INFO -  872 |nsCookiePermission                    |       36       36|       1        1|
07:14:13     INFO -  873 |nsCookieService                       |       80       80|       1        1|
07:14:13     INFO -  880 |nsDNSService                          |      104      104|       1        1|
07:14:13     INFO -  937 |nsEffectiveTLDService                 |       20       20|       1        1|
07:14:13     INFO - 1018 |nsHttpAuthCache::OriginClearObserver  |       16       32|       2        2|
07:14:13     INFO - 1021 |nsHttpChannel                         |     1188     1188|     760        1|
07:14:13     INFO - 1022 |nsHttpChannelAuthProvider             |      148      148|     733        1|
07:14:13     INFO - 1024 |nsHttpConnectionInfo                  |      140      140|     743        1|
07:14:13     INFO - 1025 |nsHttpConnectionMgr                   |      196      196|       1        1|
07:14:13     INFO - 1027 |nsHttpHandler                         |      540      540|       1        1|
07:14:13     INFO - 1029 |nsHttpRequestHead                     |       92       92|     760        1|
07:14:13     INFO - 1030 |nsHttpTransaction                     |      656      656|     541        1|
07:14:13     INFO - 1032 |nsIDNService                          |       56       56|       1        1|
07:14:13     INFO - 1035 |nsIOService                           |      160      160|       1        1|
07:14:13     INFO - 1044 |nsInputStreamPump                     |      116      116|     953        1|
07:14:13     INFO - 1048 |nsInterfaceRequestorAgg               |       24       24|    3639        1|
07:14:13     INFO - 1063 |nsJSPrincipals                        |       16       16|    4985        1|
07:14:13     INFO - 1074 |nsLocalFile                           |      124      620|    7503        5|
07:14:13     INFO - 1080 |nsMainThreadPtrHolder<T>              |       12       60|    4249        5|
07:14:13     INFO - 1114 |nsNotifyAddrListener                  |       96       96|       1        1|
07:14:13     INFO - 1135 |nsPermissionManager                   |       96       96|       1        1|
07:14:13     INFO - 1137 |nsPipe                                |      128      128|     801        1|
07:14:13     INFO - 1138 |nsPipeInputStream                     |       80       80|     801        1|
07:14:13     INFO - 1144 |nsPrefBranch                          |       80       80|      40        1|
07:14:13     INFO - 1151 |nsProxyInfo                           |       72       72|     744        1|
07:14:13     INFO - 1205 |nsSiteSecurityService                 |       48       48|       1        1|
07:14:13     INFO - 1209 |nsSocketTransportService              |      168      168|       1        1|
07:14:13     INFO - 1211 |nsStandardURL                         |      192      192|   22615        1|
07:14:13     INFO - 1217 |nsStreamConverterService              |       48       48|       1        1|
07:14:13     INFO - 1219 |nsStreamListenerWrapper               |       20       20|     513        1|
07:14:13     INFO - 1222 |nsStringBuffer                        |        8      608|  248086       76|
07:14:13     INFO - 1270 |nsTArray_base                         |        4      172| 1178198       43|
07:14:13     INFO - 1280 |nsThread                              |      200      800|      72        4|
07:14:13     INFO - 1284 |nsTimer                               |       16       16|    4140        1|
07:14:13     INFO - 1285 |nsTimerImpl                           |       68       68|    4140        1|
07:14:13     INFO - 1293 |nsTransportEventSinkProxy             |       44       44|     541        1|
07:14:13     INFO - 1298 |nsUUIDGenerator                       |      168      168|       1        1|
07:14:13     INFO - 1304 |nsUrlClassifierClassifyCallback       |       16       16|     663        1|
07:14:13     INFO - 1305 |nsUrlClassifierDBService              |       76       76|       1        1|
07:14:13     INFO - 1306 |nsUrlClassifierDBServiceWorker        |      100      100|       1        1|
07:14:13     INFO - 1307 |nsUrlClassifierLookupCallback         |       36       36|     652        1|
07:14:13     INFO - 1317 |nsWeakReference                       |       20      200|    1102       10|
07:14:13     INFO - 1353 |nsXMLHttpRequestXPCOMifier            |       36       36|     536        1|
07:14:13     INFO - 1391 |xptiInterfaceInfo                     |       20       20|     621        1|
07:14:13     INFO - 
07:14:13     INFO - nsTraceRefcnt::DumpStatistics: 1392 entries
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 BackstagePass
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 CacheEntry
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 CacheEntryHandle
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 CacheFile
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 CacheFileHandle
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 CacheFileMetadata
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 CacheStorageService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 4 CallbackObject
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 11 CondVar
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 ConsoleReportCollector
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 DOMEventTargetHelper
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 3 DataStorage
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 EventListenerManager
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 HttpBaseChannel
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 4 IdlePeriod
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 4 JSEventHandler
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 LoadInfo
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 25 Mutex
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 PollableEvent
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 ProtoAndIfaceCache
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 ReentrantMonitor
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 RequestContextService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 Service
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 2 StringAdopt
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 ThirdPartyUtil
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 UrlClassifierLookupCallbackProxy
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 XMLHttpRequestEventTarget
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 XMLHttpRequestMainThread
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 XMLHttpRequestStringBuffer
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 XPCNativeInterface
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 XPCNativeMember
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 XPCNativeScriptableInfo
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 XPCNativeSet
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 XPCWrappedNative
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 XPCWrappedNativeProto
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 XPCWrappedNativeTearOff
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsAuthURLParser
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsCategoryObserver
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsChannelClassifier
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsCookiePermission
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsCookieService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsDNSService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsEffectiveTLDService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 2 nsHttpAuthCache::OriginClearObserver
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpChannel
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpChannelAuthProvider
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpConnectionInfo
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpConnectionMgr
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpHandler
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpRequestHead
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsHttpTransaction
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsIDNService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsIOService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsInputStreamPump
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsInterfaceRequestorAgg
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsJSPrincipals
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 nsLocalFile
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 5 nsMainThreadPtrHolder<T>
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsNotifyAddrListener
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsPermissionManager
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsPipe
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsPipeInputStream
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsPrefBranch
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsProxyInfo
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsSiteSecurityService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsSocketTransportService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsStandardURL
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsStreamConverterService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsStreamListenerWrapper
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 76 nsStringBuffer
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 43 nsTArray_base
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 4 nsThread
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsTimer
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsTimerImpl
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsTransportEventSinkProxy
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsUUIDGenerator
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsUrlClassifierClassifyCallback
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsUrlClassifierDBService
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsUrlClassifierDBServiceWorker
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsUrlClassifierLookupCallback
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 10 nsWeakReference
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 nsXMLHttpRequestXPCOMifier
07:14:13     INFO - TEST-INFO | leakcheck | default process: leaked 1 xptiInterfaceInfo
07:14:13    ERROR - TEST-UNEXPECTED-FAIL | leakcheck | default process: 13094 bytes leaked (BackstagePass, CacheEntry, CacheEntryHandle, CacheFile, CacheFileHandle, ...)
Looks a duplicate of bug 1325274?
Priority: -- → P1
See Also: → 1325274
Shawn, since you've been looking at a similar bug 1325274, it'd be great that we have your help here, too. Thank you!
Flags: needinfo?(shuang)
Sure, i will try to help here.
Flags: needinfo?(shuang)
these are the same bugs, Andrew and I were both working on this same problem and it is easy to duplicate work.
[Tracking Requested - why for this release]: Leaks are bad.
Depends on: 1325158
Duplicate of this bug: 1325274
See Also: → 1326136
See Also: → 1317290
tracking 51/52/53 to get to the bottom of the leaks.
(In reply to Shawn Huang [:shawnjohnjr] from comment #7)
> I've applied all the patches from bug 1325158, I can still see leakage.
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=abc2eb3fbada91afb37442da891f35f7c340455a

I've tried to run dom/xhr/tests but still no luck to reproduce the bug locally. I will try to file a slave loan request.

Now it failed in M(6) from try results.

02:06:50    ERROR - TEST-UNEXPECTED-FAIL | leakcheck | default process: 12262 bytes leaked (BackstagePass, CallbackObject, CondVar, ConsoleReportCollector, DOMEventTargetHelper, ...)
02:06:50     INFO - runtests.py | Running tests: end.
02:06:50     INFO - Buffered messages finished
02:06:50     INFO -  dir: dom/tests/mochitest/notification
Whiteboard: [MemShrink]
Blocks: 1325947
(In reply to Shawn Huang [:shawnjohnjr] from comment #9)
> I've tried to run dom/xhr/tests but still no luck to reproduce the bug
> locally. I will try to file a slave loan request.

Your try push in comment 7 does not disable the leak suppression for the XHR directory, so leaks wouldn't show up there. Also, the M6 leak I see there is in the directory dom/tests/mochitest/notification, not in dom/xhr/tests. That said, I locally disabled the leak suppression and I'm not able to reproduce the XHR leak, though I only tried a couple of times.
More specifically, that notifications leak looks like an instance of bug 1317290.
I've been looking at Linux 32 debug logs on TreeHerder, for m-c, from around Dec 23rd to the 20th, and I have yet to see this leak (I'm looking at the raw logs). I'm not sure how the frequency is so much lower than the push in comment 0.
I made a try push with leak checking added back in for XHR, and I'll see how green it is:
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=e9c243c528ddcb589e0ae199d0c1012695ac269a
It looks pretty green. I think it would be okay to drop the whitelist for the XHR directory and just continue to fix the underlying issue in bug 1317290.
Andrew, Thanks.
Assignee: shuang → continuation
Comment on attachment 8824610 [details]
Bug 1325438 - Remove leak checking whitelist for tests/dom/xhr/tests.

https://reviewboard.mozilla.org/r/103036/#review103638

great stuff
Attachment #8824610 - Flags: review?(jmaher) → review+
Leak checking was only disabled for this directory on Nightly.
Pushed by amccreight@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/f40258de5ee2
Remove leak checking whitelist for tests/dom/xhr/tests. r=jmaher
https://hg.mozilla.org/mozilla-central/rev/f40258de5ee2
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla53
No longer blocks: 1325947
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.