Bug 40912 - Out of memory exception with low memory usage
Summary: Out of memory exception with low memory usage
Status: CONFIRMED
Alias: None
Product: Android
Classification: Xamarin
Component: Mono runtime / AOT Compiler (show other bugs)
Version: 6.0.1 (C6SR1)
Hardware: PC Windows
: --- normal
Target Milestone: ---
Assignee: Jon Purdy
URL:
Depends on:
Blocks:
 
Reported: 2016-05-05 17:04 UTC by Rowan
Modified: 2017-03-21 11:47 UTC (History)
4 users (show)

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


Attachments
test app (7.81 MB, application/x-rar)
2016-05-05 17:04 UTC, Rowan
Details
test app part 2 (7.81 MB, application/x-rar)
2016-05-05 17:06 UTC, Rowan
Details
test app part 3 (7.81 MB, application/x-rar)
2016-05-05 17:08 UTC, Rowan
Details
test app part 4 (7.81 MB, application/x-rar)
2016-05-05 17:08 UTC, Rowan
Details
test app part 5 (6.37 MB, application/x-rar)
2016-05-05 17:09 UTC, Rowan
Details
Logcat of OOM with Galaxy Note 2 (2.39 MB, text/plain)
2016-05-05 19:16 UTC, Rowan
Details
This is a recompile of the app with Xamarin 4.3.0.458 (7.80 MB, application/x-rar)
2016-12-07 02:02 UTC, Rowan
Details
This is a recompile of the app with Xamarin 4.3.0.458 (7.80 MB, application/x-rar)
2016-12-07 02:03 UTC, Rowan
Details
This is a recompile of the app with Xamarin 4.3.0.458 (7.80 MB, application/x-rar)
2016-12-07 02:03 UTC, Rowan
Details
This is a recompile of the app with Xamarin 4.3.0.458 (7.80 MB, application/x-rar)
2016-12-07 02:03 UTC, Rowan
Details
This is a recompile of the app with Xamarin 4.3.0.458 (6.19 MB, application/x-rar)
2016-12-07 02:04 UTC, Rowan
Details
/proc/$pid/maps output (113.99 KB, text/plain)
2016-12-14 02:58 UTC, Jon Purdy
Details

Description Rowan 2016-05-05 17:04:51 UTC
Created attachment 15917 [details]
test app

We are getting out of memory exceptions even at low memory usage and taking as many precautions as I could find like limiting allocations to 8KB as much as possible to avoid being allocated into the LOS which can cause fragmentation after time.

The application does a lot more memory allocation than the average app would but this is not avoidable for our app.

This issue can happen with low memory usage, total application memory usage of 100mb or less, with android reporting 1GB or more of free memory.

the android file /proc/buddyinfo file reports lots of free pages in all the different allocation sizes at the time of the crash.

I have created a test application which you just need to start the app and wait a few hours for it to crash with the OOM.

This is not our normal application our normal application, I have made modifications to increase the cpu usage and memory usage to make this occur sooner. Under normal conditions it only rarely happens and taking much longer to happen but still does happen causing a big problem for us.

On real nexus 5 and 7 it happens in less than 2 hours. On a galaxy note 2 it happens after about 1 hour.

I have tested with the latest android sdk 6.0 x86_64 emulator configured as a nexus 5, it does not happen.

I split the app into 5 rar parts because of your upload restriction.

Please install the apk and also place the 2 other files at /sdcard/Folder5500.zip and at /sdcard/Resources.res

Then just launch the app and wait for it to crash with the OOM.

Every 30 seconds I write read /proc/meminfo and /proc/buddyinfo and check "dumpsys activity oom" put this into the android log to track the memory usage in detail.

I have also been forcing the garbage collector every 30 seconds, I know this should not be necessary if the mono runtime was working well but it did have an impact in reducing the OOM from happening (so maybe there is an issue in the garbage collector)

I am available to do any other changes you may require to the test app or assist in any way possible. Please let me know any questions you have.

I will attach a logcat from a galaxy note 2 that contains the OOM error

Here are my system details 
=== Xamarin Studio Enterprise ===

Version 5.10.3 (build 51)
Installation UUID: ce6a42b0-ba4b-4ea6-8535-b03f0d0d3af4
Runtime:
	Microsoft .NET 4.0.30319.42000
	GTK+ 2.24.23 (MS-Windows theme)
	GTK# 2.12.30

=== Xamarin.Profiler ===

Not Installed

=== Xamarin.Android ===

Version: 6.0.2.2 (Xamarin Enterprise)
Android SDK: C:\Program Files (x86)\Android\android-sdk
	Supported Android versions:
		4.0.3 (API level 15)
		4.1   (API level 16)
		4.3   (API level 18)
		4.4   (API level 19)
		5.0   (API level 21)
		5.1   (API level 22)
		6.0   (API level 23)

SDK Tools Version: 25.1.3

SDK Platform Tools Version: 23.1

SDK Build Tools Version: 23.0.3


Java SDK: C:\Program Files (x86)\Java\jdk1.7.0_55
java version "1.7.0_55"
Java(TM) SE Runtime Environment (build 1.7.0_55-b13)
Java HotSpot(TM) Client VM (build 24.55-b03, mixed mode, sharing)

Android Designer EPL code available here:
https://github.com/xamarin/AndroidDesigner.EPL

=== Xamarin Android Player ===

Version: 0.6.5
Location: C:\Program Files\Xamarin Android Player\DeviceManager.exe

=== Build Information ===

Release ID: 510030051
Git revision: f3c0d982165f785772d125f02668370d929014fb
Build date: 2016-03-24 16:41:31-04
Xamarin addins: ee5cfd3ecb6b20de47c1d25efb9a9abc101e8ce7
Build lane: monodevelop-windows-cycle6-c6sr3

=== Operating System ===

Windows 10.0.10586.0 (64-bit)
Comment 1 Rowan 2016-05-05 17:06:11 UTC
Created attachment 15918 [details]
test app part 2
Comment 2 Rowan 2016-05-05 17:08:07 UTC
Created attachment 15919 [details]
test app part 3
Comment 3 Rowan 2016-05-05 17:08:58 UTC
Created attachment 15920 [details]
test app part 4
Comment 4 Rowan 2016-05-05 17:09:51 UTC
Created attachment 15921 [details]
test app part 5
Comment 5 Rowan 2016-05-05 19:16:28 UTC
Created attachment 15923 [details]
Logcat of OOM with Galaxy Note 2
Comment 6 Jonathan Pryor 2016-05-18 21:02:46 UTC
A quick glance at Attachment #15923 [details] suggests that things are confusing.

Before the process dies with an OutOfMemoryException, it reports that the process is consuming 211MB

> 05-05 13:26:16.534: I/CPU Usage(13970):   PID PR CPU% S  #THR     VSS     RSS PCY UID      Name
> 05-05 13:26:16.534: I/CPU Usage(13970): 13970  3  31% S    32 1876552K 211544K  fg u0_a85   stara.x5500

*Mono* thinks that the process is consuming ~87MB, and the LOS is ~13MB:

> D/Mono(13970): GC_MINOR: (Nursery full) pause 8.49ms, total 9.49ms, bridge 0.00ms promoted 86416K major 86416K los 13345K
> D/Mono(13970): GC_MAJOR: (user request) pause 251.19ms, total 253.17ms, bridge 0.00ms major 86176K/0K los 13177K/0K

There is a very large discrepancy between ~87MB and 211MB.

ART thinks that it's consuming 12MB:

> I/art(13970): Explicit concurrent mark sweep GC freed 583(20KB) AllocSpace objects, 0(0B) LOS objects, 39% free, 7MB/12MB, paused 1.255ms total 16.033ms

We need better tooling, documentation, and knowledge sharing about how to handle cases like this, but at present there appears to be a ~111MB "hole" of RAM. JIT'd code/etc. will account for some of that, but I wouldn't expect it to take anywhere near 111MB...
Comment 7 Rowan 2016-12-07 02:02:31 UTC
Created attachment 18799 [details]
This is a recompile of the app with Xamarin   4.3.0.458
Comment 8 Rowan 2016-12-07 02:03:03 UTC
Created attachment 18800 [details]
This is a recompile of the app with Xamarin   4.3.0.458
Comment 9 Rowan 2016-12-07 02:03:29 UTC
Created attachment 18801 [details]
This is a recompile of the app with Xamarin   4.3.0.458
Comment 10 Rowan 2016-12-07 02:03:58 UTC
Created attachment 18802 [details]
This is a recompile of the app with Xamarin   4.3.0.458
Comment 11 Rowan 2016-12-07 02:04:55 UTC
Created attachment 18803 [details]
This is a recompile of the app with Xamarin   4.3.0.458
Comment 12 Jon Purdy 2016-12-09 22:20:15 UTC
I can’t reproduce the crash on my Nexus 5, but I am seeing similar memory usage, about 210MB RSS when the SGen heap is only ~67MB + 12MB LOS. Currently getting more info on the breakdown of JIT, malloc, shared libs, etc.
Comment 13 Rowan 2016-12-12 12:43:00 UTC
I have been testing with a Galaxy Note 2, we will try the nexus 5 again to see if we can get it to happen on our nexus 5.

It has been taking a long time for the crash to happen, about 12 hours on average on the galaxy note 2.

When it does happen now with the log is a little bit different, instead of crashing with an out of memory exception, it is returning a null array when trying to allocate an array.


here is the place where it seems to always crash, when trying to allocate some memory to a generic array. So now every time when this line is executed I also print to the logcat the desired size, then the actual allocated size.

var tmpArray = new T[newArrySize];
Log.Info("copy", newArrySize + " d " + (tmpArray != null ? tmpArray.Length : 0));

This is resulted in the following log output just before the crash.

12-10 08:13:28.450 7234-7267/? I/copy: 4110 d 0

which shows that the tmpArray is null, the app then crashes when it tries to use tmpArray

So it seems to be an OOM but instead of this error explicitly it is failing to allocate the memory and just continuing with null array.

The last garbage collection in the log was

12-10 08:13:28.375 7234-7267/? D/Mono: GC_TAR_BRIDGE bridges 0 objects 0 opaque 0 colors 0 colors-bridged 0 colors-visible 5 xref 0 cache-hit 0 cache-semihit 0 cache-miss 0 setup 0.20ms tarjan 0.01ms scc-setup 0.03ms gather-xref 0.00ms xref-setup 0.00ms cleanup 0.00ms
12-10 08:13:28.375 7234-7267/? D/Mono: GC_BRIDGE: Complete, was running for 0.06ms
12-10 08:13:28.375 7234-7267/? D/Mono: GC_MINOR: (Nursery full) time 9.98ms, stw 11.39ms promoted 403K major size: 122272K in use: 116847K los size: 63480K in use: 60291K

So it is using some memory but not excessive amounts, but still android reports well over 1 GB free memory.
Comment 14 Jon Purdy 2016-12-13 21:19:50 UTC
If we’re missing a proper OOM exception, that’s probably a bug. Handling OOM gracefully is difficult, so we make a best effort.

While attempting to run on a rooted Nexus to read /proc, I get a crash on startup from AndroidLib.SysLib.InitSys:

    The type initializer for 'CommonLib.ResourceFile' threw an exception.
      System.IO.FileNotFoundException: Could not find file "/sdcard/Resource.res".

Have you encountered this before? I’d like to find a workaround so I can get more info on what the app is doing internally.
Comment 15 Rowan 2016-12-13 21:36:46 UTC
the error message says file not found /sdcard/Resource.res

When installing you need to copy the 2 extra files from the zip to the /sdcard/ folder.

the install instructions as above are

Please install the apk and also place the 2 other files at /sdcard/Folder5500.zip and at /sdcard/Resources.res

thanks
Comment 16 Jon Purdy 2016-12-13 22:17:09 UTC
My mistake, thank you. I’ll update again today.
Comment 17 Jon Purdy 2016-12-14 02:58:01 UTC
Created attachment 18878 [details]
/proc/$pid/maps output

Here are the contents of /proc/$pid/maps for the app when the RSS is reported as 211MB. I haven’t had any clear insights yet, but I wanted to share what I’ve got.

155MB of these mappings look like graphics memory (/dev/kgsl-3d0, anon_inode:dmabuf) and 50MB are malloc ([anon:libc_malloc]).
Comment 18 Rowan 2016-12-14 18:26:04 UTC
interesting I was not aware of that file, I have added to the app that it now prints out to the android log the /proc/$pid/maps every 30 seconds

I then sum all the addresses for the 3d to work out the total memory and I can confirm that I also am getting approximately 150MB of memory used by opengl, fluctuating between 140 and 150 MB over time.

It does not increase with time, just fluctuates a little bit.

However I don't think it is included in the memory reporting. Because at the beginning, I get a total pss value of about 80MB while it is still loading things, and already with the 150MB of opengl memory being reported. So it can't be included in the total pss. Or the opengl memory reported in maps also includes reserved memory, even if it is not all used.

I get the total pss memory from
 activityManager.GetProcessMemoryInfo(pids);

which I also put in the android log with the tag "pss"

I also think their are multiple issues, we are hunting for the cause of the extra memory usage being reported. However my main concern is not the reason for an extra 100MB or so of memory (which still is important), but rather that the app can crash by a memory allocation failing with more than 1GB of free memory.
Comment 19 Zoltan Varga 2017-03-21 11:47:32 UTC
This might be related to:

https://bugzilla.xamarin.com/show_bug.cgi?id=52437

It was a bug which caused some memory allocation functions to return null instead of throwing an OOM exception.

Note You need to log in before you can comment on or make changes to this bug.