Writing large file to storage device causes very large garbage collector delays to other threads

[RowanHarris]

Steps to Reproduce

1. The attached project is just a new opengl project with very small modifications to show this bug. A new thread is created to just continuously try and write to the sd card, the function is called DoThread(). The other modification is just to allocate some memory then set the variable to null each time OnRenderFrame is called, the allocation is large to give the GC something to dispose of. I also call GC.Collect(); just to make sure it is called each frame, the same effect happens if you dont force the GC however it can take a little longer to happen.
2. Run the attached project (preferably on mid or low range devices) and notice that the time between renders of frames which is output to the android log can be very delayed, on a samsung galaxy note 2 it can take up to 7 seconds between frames.

TestMemoryAlloc.zip

Expected Behavior

The render thread should continue rendering with only 30ms of delay from the garbage collector like normally happens.

Actual Behavior

The render thread can be delayed up to 7 seconds when the writing a file on another thread. I tested on an android 4.4, android 5.0 and android 7.0, the 7.0 had a much faster storage device so the effect was less but still up to 400ms. I also had similar results with File.Copy(string source, string destination) I also had similar results creating a native C++ dll to do the file write. I first noticed this issue when doing a File.Copy and it was a large file which resulted in 3 seconds of freeze on all the threads.

Version Information

Microsoft Visual Studio Community 2017
Version 15.6.4
VisualStudio.15.Release/15.6.4+27428.2015
Microsoft .NET Framework
Version 4.7.02556

Installed Version: Community

Visual C++ 2017 00369-60000-00001-AA611
Microsoft Visual C++ 2017

Application Insights Tools for Visual Studio Package 8.11.10212.1
Application Insights Tools for Visual Studio

ASP.NET and Web Tools 2017 15.0.40314.0
ASP.NET and Web Tools 2017

ASP.NET Core Razor Language Services 1.0
Provides languages services for ASP.NET Core Razor.

Azure App Service Tools v3.0.0 15.0.40215.0
Azure App Service Tools v3.0.0

C# Tools 2.7.0-beta3-62715-05. Commit Hash: db02128e6e3c4bdfc93e6ec425ac9162b4d4fe80
C# components used in the IDE. Depending on your project type and settings, a different version of the compiler may be used.

Common Azure Tools 1.10
Provides common services for use by Azure Mobile Services and Microsoft Azure Tools.

JavaScript Language Service 2.0
JavaScript Language Service

JavaScript Project System 2.0
JavaScript Project System

JetBrains ReSharper Ultimate 2017.3.3 Build 111.0.20180302.65130
JetBrains ReSharper Ultimate package for Microsoft Visual Studio. For more information about ReSharper Ultimate, visit http://www.jetbrains.com/resharper. Copyright © 2018 JetBrains, Inc.

Merq 1.1.17-rc (cba4571)
Command Bus, Event Stream and Async Manager for Visual Studio extensions.

Microsoft JVM Debugger 1.0
Provides support for connecting the Visual Studio debugger to JDWP compatible Java Virtual Machines

Microsoft MI-Based Debugger 1.0
Provides support for connecting Visual Studio to MI compatible debuggers

Microsoft Visual C++ Wizards 1.0
Microsoft Visual C++ Wizards

Microsoft Visual Studio VC Package 1.0
Microsoft Visual Studio VC Package

Mono Debugging for Visual Studio 4.9.11-pre (71eb098)
Support for debugging Mono processes with Visual Studio.

Node.js Tools 1.4.11027.3
Adds support for developing and debugging Node.js apps in Visual Studio

NuGet Package Manager 4.6.0
NuGet Package Manager in Visual Studio. For more information about NuGet, visit http://docs.nuget.org/.

ProjectServicesPackage Extension 1.0
ProjectServicesPackage Visual Studio Extension Detailed Info

TypeScript Tools 15.6.20202.3
TypeScript Tools for Microsoft Visual Studio

Visual Basic Tools 2.7.0-beta3-62715-05. Commit Hash: db02128e6e3c4bdfc93e6ec425ac9162b4d4fe80
Visual Basic components used in the IDE. Depending on your project type and settings, a different version of the compiler may be used.

Visual C++ for Cross Platform Mobile Development (Android) 15.0.27428.2015
Visual C++ for Cross Platform Mobile Development (Android)

Visual Studio Code Debug Adapter Host Package 1.0
Interop layer for hosting Visual Studio Code debug adapters in Visual Studio

Visual Studio Tools for CMake 1.0
Visual Studio Tools for CMake

VisualStudio.Mac 1.0
Mac Extension for Visual Studio

Xamarin 4.9.0.752 (0faa808ee)
Visual Studio extension to enable development for Xamarin.iOS and Xamarin.Android.

Xamarin Designer 4.10.58 (cee1369d0)
Visual Studio extension to enable Xamarin Designer tools in Visual Studio.

Xamarin.Android SDK 8.2.0.16 (HEAD/a78295902)
Xamarin.Android Reference Assemblies and MSBuild support.

Xamarin.iOS and Xamarin.Mac SDK 11.8.1.28 (3979d08)
Xamarin.iOS and Xamarin.Mac Reference Assemblies and MSBuild support.

Log File

log.zip

[grendello]

@RowanHarris In your testing, were you able to see the same issue with pure Java code? You mention testing with native C++ library to do the copying, but I wonder if you are able to reproduce it with Java. What follows is just a few ideas, please treat them as such.

While writing such heavily I/O bound code, especially for mobile devices, it is important to keep a few factors in mind.

First of all, the storage devices aren't very fast (especially on mid to low end devices), despite being flash storage. The throughput is less than ideal in many cases for that reason. On top of that, external storage is a protected resource requiring a special permission. Android checks whether the application has requested the require permission on file open time (in Android 6.0+) or on application installation time (in earlier Android versions and for "legacy" applications on 6.0+) and routes access to the storage via a system-level daemon (vold IIRC) which is responsible for controlling access (in Android 6.0+ it includes bind-mounting the external storage location into the application namespace depending on the current state of permissions). Now, I'm not 100% of what I'm going to write next, but it seems logical that the checks are made also while flushing buffers to the device because the permissions can be rescinded at any time during the application life. If the permission checks are indeed made while flushing the buffers then that costs lots of time. And I believe buffers are flushed/synced very often to external storage because the system must assume that the user may eject the SD card at any time and such unbuffered or nearly unbuffered synchronous I/O is slow.

Second of all, memory pressure. You are creating a nearly 50MB byte array in you thread and proceed to pump its contents through to a file using, again, buffered I/O which increases memory pressure on both the XA GC but also on the Dalvik/ART GC and it may mean the application is considered for eviction on the grounds of memory pressure (which is another scarce resource in mobile devices) as well as of the I/O pressure (the app is hogging access to a block device - all the requests to such devices are queued, and until your application is finished flushing its buffers no other app/daemon/etc can access the device). Also keep in mind that the more memory you allocate the more of it the GC has to scan every few ms. And, as your log file testifies, the Java GC blocks your app's main thread for collection - that means there's immense native GC pressure and XA needs to wait for its turn.

There's also a question of concurrency. Mobile devices may have 4 or 8 cores, but it's another very precious resource, this time mostly because of the energy consumption. For that reason, some of the cores (sometimes nearly all of them) may be turned off and woken up only when they are absolutely needed for computation-intensive tasks. I/O is not such a task and so it may happen that the device runs only on single core - and so your thread is not scheduled in parallel with the main thread, but rather has to wait for the I/O to finish so that context can be switched back to the main thread to do the other application tasks.

All of the above is guesswork without having spent time investigating what happens in your app in depth, however it is based on experience and knowledge of the internals so I might not be that far off the mark :) I'd recommend to do I/O in a more restrained manner. In my experience there's little gain to having large buffers to either read or write slow resources (be them storage or the network) and chunking up the data in manageable batches (say, 32k in size for storage I/O and 8k - yes, it's enough - for network) makes for a much better performing application. If you write your file in a separate thread then it means you don't need to hurry too much to free your main thread to interact with the user. It is better to throttle the I/O by adding a slight delay between writes of small buffers - the user experience should be much improved.

[RowanHarris]

Hi Marek, How are you? You have helped fix 3 Xamarin android bugs that I have posted in the past related to the GC so thanks again for those fixes and glad you are on this case! One of those bugs has some similarity https://bugzilla.xamarin.com/show_bug.cgi?id=20360, not the same but caused by threading and file IO causing GC issues.

I first noticed the issue with File.Copy which is a .net function, with this function I am not able to change buffer sizes or insert slight delays between writes. Just trying to copy 1 large file using this function can cause this problem if the garbage collector is executed while a large file copy is in progress. The large memory allocation was done just to put pressure on the GC. In our application is very complex and there are many smaller allocations happening however the point was to make this bug easily repeatable.

Yes I was able to stop this issue by adding delays, currently our app is not using the Xamarin File.Copy function because of this problem. I created the C++ library to work around this issue. I used just an 8K buffer and inserted a 7ms wait after the read and a 7ms wait after the write which seemed to stop the issue happening.

However it is still a rough workaround and the issue of the GC becoming unresponsive when using .net functions to write to the storage is an issue that warrants investigation.

[grendello]

@RowanHarris File.Copy is primarily a .NET API not really optimized for mobile scenarios, perhaps it would be a good idea if we optimized it (and similar API) for mobile

[RowanHarris]

You don't think it is worth checking to see the exact cause from the GC as to why it is freezing in these IO cases? Should the GC be prevented from running unless free memory is really running short if there is writes to the file system? It seems worth investigating the state of the GC in this example to confirm your hypothesis as to what is causing the freezes and that there is nothing that can be done to prevent them except optimize the .net code.

We suspect this issue is stale and no longer relevant. It will be closed if no further activity occurs within 14 more days. Any new comment (by anyone, not necessarily the author) will undo this process.

This issue will now be closed since it had been marked possibly-stale but received no further activity in the past 14 days. It is still possible to reopen or comment on the issue, but please note that the issue will be locked if it remains inactive for another 30 days.