Bug 2972 - Memory leak?
Summary: Memory leak?
Status: RESOLVED NOT_ON_ROADMAP
Alias: None
Product: Android
Classification: Xamarin
Component: Mono runtime / AOT Compiler ()
Version: 4.0
Hardware: PC Windows
: Highest normal
Target Milestone: ---
Assignee: Jonathan Pryor
URL:
Depends on:
Blocks:
 
Reported: 2012-01-19 11:36 UTC by Iain
Modified: 2013-05-30 23:26 UTC (History)
5 users (show)

Tags:
Is this bug a regression?: ---
Last known good build:


Attachments
repro app (11.49 KB, application/x-zip-compressed)
2012-01-19 11:36 UTC, Iain
Details


Notice (2018-05-24): bugzilla.xamarin.com is now in read-only mode.

Please join us on Visual Studio Developer Community and in the Xamarin and Mono organizations on GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs, copy them to the new locations as needed for follow-up, and add the new items under Related Links.

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.


Please create a new report on Developer Community or GitHub with your current version information, steps to reproduce, and relevant error messages or log files if you are hitting an issue that looks similar to this resolved bug and you do not yet see a matching new report.

Related Links:
Status:
RESOLVED NOT_ON_ROADMAP

Description Iain 2012-01-19 11:36:36 UTC
Created attachment 1235 [details]
repro app

- Download the repro app.
- Extract zip archive "MemoryLeak.zip".
- Open MemoryLeak/MemoryLeak.sln in vs2010, (reproduced running MFA 4.0.3).
- Build in debug mode, and deploy to a Motorola xoom wifi.
- Run the app MemoryLeak on the device and fling up and down the list approximately 10-15 times.
- Examine the output in logcat.  Sample log below.
- Total memory keeps jumping up every so often.

- Now comment out line 76 (the line that reads result.FindViewById<TextView>(1001).Text = Guid.NewGuid().ToString();)
- Redeploy and fling for a while.  Notice that on the first monodroid-gc cleanup summary, memory usage will jump up dramatically, but after this, should remain stable if you continue to fling for a while.
- This implies that either the call to FindViewById<TextView> or the setter on TextView.Text property appears to be leaking...

- Finally, as an additional strangeness, remove the comments surrounding line 29 (//System.GC.Collect(0);).
- Redeploy the app and watch memory usage just go up and up every time the test thread runs a loop iteration.

Looks like either a Memory leak in the GC or else misreporting of actual memory usage?   Unless I'm doing something extremely stupid?!?

Cheers
Iain

===logcat output===

I/ActivityManager(  146): Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0
x10200000 cmp=MemoryLeak.MemoryLeak/memoryleak.MemoryLeakActivity } from pid 11096
I/ActivityManager(  146): Start proc MemoryLeak.MemoryLeak for activity MemoryLeak.MemoryLeak/memoryleak.MemoryLeakActiv
ity: pid=14575 uid=10068 gids={3003, 1015}
I/ActivityThread(14575): Pub MemoryLeak.MemoryLeak.__mono_init__: mono.MonoRuntimeProvider
D/dalvikvm(14575): Trying to load lib /data/data/MemoryLeak.MemoryLeak/lib/libmonodroid.so 0x406ed460
D/dalvikvm(14575): Added shared lib /data/data/MemoryLeak.MemoryLeak/lib/libmonodroid.so 0x406ed460
D/TabletStatusBar(  194): lights on
W/MonoDroid-Debugger(14575): Not starting the debugger as the timeout value has been reached; current-time: 1326986615
timeout: 1326710260
I/monodroid-gc(14575): environment supports jni NewWeakGlobalRef
D/dalvikvm(14575): GC_FOR_ALLOC freed 45K, 4% free 6365K/6595K, paused 32ms
I/dalvikvm-heap(14575): Grow heap (frag case) to 6.767MB for 513744-byte allocation
D/dalvikvm(14575): GC_FOR_ALLOC freed <1K, 4% free 6867K/7111K, paused 28ms
D/dalvikvm(14575): GC_CONCURRENT freed <1K, 4% free 6871K/7111K, paused 2ms+2ms
I/mono-stdout(14575): Total memory: 30552
W/InputManagerService(  146): Starting input on non-focused client com.android.internal.view.IInputMethodClient$Stub$Pro
xy@41a81f80 (uid=10025 pid=11096)
I/ActivityManager(  146): Displayed MemoryLeak.MemoryLeak/memoryleak.MemoryLeakActivity: +1s234ms
D/TabletStatusBar(  194): lights on
I/SyncStatIntentRcvr(  232): Received intent: android.intent.action.SYNC_STATE_CHANGED
I/SyncStatusService(  232): onStart: android.intent.action.SYNC_STATE_CHANGED
I/SyncStatIntentRcvr(  232): Received intent: android.intent.action.SYNC_STATE_CHANGED
I/SyncStatusService(  232): onStart: android.intent.action.SYNC_STATE_CHANGED
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14575): GC_CONCURRENT freed 45K, 2% free 7373K/7495K, paused 2ms+2ms
D/dalvikvm(14575): GC_CONCURRENT freed <1K, 2% free 7849K/8007K, paused 2ms+1ms
D/dalvikvm(14575): GC_CONCURRENT freed <1K, 2% free 8325K/8455K, paused 2ms+2ms
D/dalvikvm(14575): GC_CONCURRENT freed <1K, 2% free 8979K/9095K, paused 1ms+2ms
D/dalvikvm(14575): GC_CONCURRENT freed <1K, 2% free 9871K/9991K, paused 2ms+2ms
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14575): GC_CONCURRENT freed 186K, 3% free 10767K/11079K, paused 1ms+2ms
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14237): GC_EXPLICIT freed 57K, 5% free 6288K/6595K, paused 2ms+2ms
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14575): GC_CONCURRENT freed 1410K, 13% free 10768K/12295K, paused 2ms+3ms
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14245): GC_EXPLICIT freed 90K, 5% free 6299K/6595K, paused 2ms+2ms
E/Gmail   (12985): IOException: java.net.UnknownHostException: Unable to resolve host "android.clients.google.com": No a
ddress associated with hostname
D/SyncManager(  146): failed sync operation rndtestlinn@gmail.com (com.google), gmail-ls, PERIODIC, earliestRunTime 5053
78965, SyncResult: stats [ numIoExceptions: 1]
I/SyncStatIntentRcvr(  232): Received intent: android.intent.action.SYNC_STATE_CHANGED
I/SyncStatusService(  232): onStart: android.intent.action.SYNC_STATE_CHANGED
I/ActivityManager(  146): No longer want com.rechild.advancedtaskkiller (pid 12324): hidden #16
I/SyncStatIntentRcvr(  232): Received intent: android.intent.action.SYNC_STATE_CHANGED
E/InputDispatcher(  146): channel '41489a08 com.rechild.advancedtaskkiller/com.rechild.advancedtaskkiller.AdvancedTaskKi
ller (server)' ~ Consumer closed input channel or an error occurred.  events=0x8
E/InputDispatcher(  146): channel '41489a08 com.rechild.advancedtaskkiller/com.rechild.advancedtaskkiller.AdvancedTaskKi
ller (server)' ~ Channel is unrecoverably broken and will be disposed!
I/WindowManager(  146): WINDOW DIED Window{41489a08 com.rechild.advancedtaskkiller/com.rechild.advancedtaskkiller.Advanc
edTaskKiller paused=false}
I/AccountTypeManager(11329): Loaded meta-data for 2 account types, 1 accounts in 3ms
I/SyncStatusService(  232): onStart: android.intent.action.SYNC_STATE_CHANGED
D/PerformBackupThread(  146): starting agent for backup of BackupRequest{app=ApplicationInfo{4097bbd0 com.google.android
.gm} full=false}
D/BackupManagerService(  146): awaiting agent for ApplicationInfo{4097bbd0 com.google.android.gm}
D/BackupManagerService(  146): agentConnected pkg=com.google.android.gm agent=android.os.BinderProxy@41076b20
I/Gmail   (12985): Bootstrapping db:/data/data/com.google.android.gm/databases/mailstore.stevenspencer01@gmail.com.db Cu
rrent version is 0
I/mono-stdout(14575): Total memory: 33704
I/Gmail   (12985): calculateUnknownSyncRationalesAndPurgeInBackground: exiting (labelMap not synced
I/Gmail   (12985): Bootstrapping db:/data/data/com.google.android.gm/databases/mailstore.linntest@gmail.com.db Current v
ersion is 0
D/dalvikvm(12985): GC_CONCURRENT freed 272K, 6% free 6713K/7111K, paused 3ms+2ms
I/Gmail   (12985): calculateUnknownSyncRationalesAndPurgeInBackground: exiting (labelMap not synced
W/BackupTransportService(  146): Backup account missing, trying again later
W/BackupTransportService(  146): Error sending final backup to server: java.io.IOException: Can't get Backup account
W/PerformBackupThread(  146): Backup pass unsuccessful, restaging
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14575): GC_CONCURRENT freed 1406K, 13% free 10767K/12295K, paused 2ms+2ms
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
I/mono-stdout(14575): Total memory: 33704
D/dalvikvm(14575): GC_EXPLICIT freed 1062K, 13% free 10762K/12295K, paused 2ms+2ms
I/monodroid-gc(14575): GC cleanup summary: 123 objects tested - resurrecting 123.
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
D/dalvikvm(25379): GC_FOR_ALLOC freed 1705K, 25% free 14468K/19079K, paused 101ms
D/dalvikvm(25379): GC_FOR_ALLOC freed 2406K, 27% free 14110K/19079K, paused 102ms
D/dalvikvm(25379): GC_CONCURRENT freed 279K, 26% free 14149K/19079K, paused 7ms+6ms
D/dalvikvm(14261): GC_EXPLICIT freed 232K, 5% free 6412K/6727K, paused 3ms+3ms
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
D/dalvikvm(14575): GC_CONCURRENT freed 1407K, 13% free 10758K/12295K, paused 1ms+2ms
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
D/dalvikvm(12215): GC_EXPLICIT freed 19K, 10% free 6295K/6919K, paused 2ms+2ms
D/dalvikvm(14575): GC_CONCURRENT freed 1409K, 13% free 10759K/12295K, paused 1ms+3ms
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
I/mono-stdout(14575): Total memory: 4492976
D/dalvikvm(12084): GC_EXPLICIT freed 229K, 14% free 6556K/7623K, paused 2ms+10ms
I/mono-stdout(14575): Total memory: 4492976
D/dalvikvm(14575): GC_CONCURRENT freed 1417K, 13% free 10758K/12295K, paused 2ms+3ms
D/dalvikvm(14575): GC_EXPLICIT freed 2K, 13% free 10756K/12295K, paused 2ms+2ms
I/monodroid-gc(14575): GC cleanup summary: 2 objects tested - resurrecting 2.
I/mono-stdout(14575): Total memory: 4681352
I/mono-stdout(14575): Total memory: 4681352
I/mono-stdout(14575): Total memory: 4681352
I/mono-stdout(14575): Total memory: 4681352
D/dalvikvm(11955): GC_EXPLICIT freed 146K, 5% free 7242K/7559K, paused 2ms+3ms
I/mono-stdout(14575): Total memory: 4681352
I/mono-stdout(14575): Total memory: 4681352
I/mono-stdout(14575): Total memory: 4681352
I/mono-stdout(14575): Total memory: 4681352
Comment 2 Jonathan Pryor 2013-05-30 23:26:12 UTC
GC's are complex and interesting constructs. Which brings us to the Mono 3.0-based 4.7.x alpha/beta. I do not see the "leak", nor do I see the "dramatic" memory increase. Instead, memory use is always around ~4MB.

When I run the app, without any changes:

> I/mono-stdout( 5264): Total memory: 4374064

Swipe around a lot...

> I/mono-stdout( 5264): Total memory: 4391424
...
> I/mono-stdout( 5264): Total memory: 4488504

Not a large change, probably because iirc the default sgen heap size in Mono 3.0 is ~4MB, which is (give or take) what we see above.

> - Now comment out line 76
> - Redeploy and fling for a while.  Notice that on the first monodroid-gc
>   cleanup summary, memory usage will jump up dramatically, but after this, 
>    should remain stable if you continue to fling for a while.

When I run on a Nexus 10, the Total memory is effectively unchanged:

> I/mono-stdout( 5169): Total memory: 4241200


> - Finally, as an additional strangeness, remove the comments surrounding line
>   29 (//System.GC.Collect(0);).
> - Redeploy the app and watch memory usage just go up and up every time the test
>    thread runs a loop iteration.

The numbers are less constant; they fluctuate more frequently:

> D/Mono    ( 5397): GC_MINOR: (user request) pause 3.75ms, total 4.29ms, bridge 0.01 promoted 0K major 608K los 8K
> I/mono-stdout( 5397): Total memory: 4365680
> D/Mono    ( 5397): GC_MINOR: (user request) pause 1.79ms, total 2.17ms, bridge 0.01 promoted 0K major 608K los 8K
> I/mono-stdout( 5397): Total memory: 4365736
> D/Mono    ( 5397): GC_MINOR: (user request) pause 1.75ms, total 2.12ms, bridge 0.01 promoted 0K major 608K los 8K
> I/mono-stdout( 5397): Total memory: 4365792
> D/Mono    ( 5397): GC_MINOR: (user request) pause 1.77ms, total 2.15ms, bridge 0.01 promoted 0K major 608K los 8K
> I/mono-stdout( 5397): Total memory: 4365848
> D/Mono    ( 5397): GC_MINOR: (user request) pause 1.26ms, total 1.51ms, bridge 0.01 promoted 0K major 608K los 8K
> I/mono-stdout( 5397): Total memory: 4365904

That said, the value isn't changing much.

As important, from my perspective, is GREF use. It's fairly constant:

> I/monodroid-gref( 6066): -g- grefc 29 gwrefc 0 handle 0x5250028e/G from    at Android.Runtime.JNIEnv.DeleteGlobalRef(IntPtr jobject)

So that's good.

A good question is what's consuming the ~4MB of heap memory that's being reported. Unfortunately, we lack the profiler that could easily answer that...