Occasionally encountering strange race condition or timing issue in `ConvertResourcesCases`

[pjcollins]

We're running in to a seemingly rare bug where the ConvertResourcesCases task will fail during various file operations. These appear to have some sort of threading, race, or timing aspect, as the exact error or reproduction is not consistent.

I've managed to narrow things down slightly on a single test machine where this seems to be happening more frequently. Using the steps below, I can somewhat consistently cause this task to fail when attempting to process items from lp/*/jl, all of which correspond to various Xamarin.Android.Support.* NuGet references in these templates. I managed to reproduce a couple of times on my local machine as well with these steps.

Given the results we have seen so far, this appears to be a regression introduced somewhere in xamarin-android/d15-9 + mono/2018-06 + monodevelop/release-7.7

Steps to Reproduce

1. Create a new Android App -> Max Compatibility project in VS Mac. This should include version 27.0.2 of Xamarin.Android.Support.Compat.
2. Click on Build -> Build All. The initial build should succeed).
3. Right click on Packages -> Update. A minor version bump for these packages should be available (e.g. 27.0.2 -> 27.0.2.1).
4. Click on Build -> Build All. This build attempt is failing for me during ConvertResourcesCases pretty consistently on a mac mini running Sierra.

Expected Behavior

ConvertResourcesCases successfully completes on build and subsequent build attempts after changing various references or project options.

Actual Behavior

ConvertResourcesCases fails intermittently when attempting certain file operations. The "culprit" file in question varies from repro to repro, and the exception does not always reflect the state of my intermediate output directory (e.g. FileNotFoundException thrown when the file does exist).

/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: The "ConvertResourcesCases" task failed unexpectedly.
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: System.IO.FileNotFoundException: Could not find file "/Users/xamarinqa/agent/_work/r15/a/XQA.VSMac/XQA.VisualStudioMac/TestResults/f6a9104b/TestAndroidEnableAOTEnterprise/Temp/DroidApp/DroidApp/obj/Release/lp/6/jl/res/layout/notification_template_custom_big.xml"
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: File name: '/Users/xamarinqa/agent/_work/r15/a/XQA.VSMac/XQA.VisualStudioMac/TestResults/f6a9104b/TestAndroidEnableAOTEnterprise/Temp/DroidApp/DroidApp/obj/Release/lp/6/jl/res/layout/notification_template_custom_big.xml'
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018:   at System.IO.FileStream..ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share, System.Int32 bufferSize, System.Boolean anonymous, System.IO.FileOptions options) [0x00259] in /Users/builder/jenkins/workspace/build-package-osx-mono/2018-06/external/bockbuild/builds/mono-x64/mcs/class/corlib/System.IO/FileStream.cs:274 

/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: The "ConvertResourcesCases" task failed unexpectedly.
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: System.IO.IOException: Could not create file "/var/folders/44/n482q3wx171dnj8b6165rync0000gn/T/tmp5964ed16.tmp" or "/Users/xamarinqa/Projects/TestFin/TestFin/obj/Debug/lp/6/jl/res/values-en-rIN/values-en-rIN.xml". File already exists.
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018:   at System.IO.File.Copy (System.String sourceFileName, System.String destFileName, System.Boolean overwrite) [0x00193] in /Users/builder/jenkins/workspace/build-package-osx-mono/2018-06/external/bockbuild/builds/mono-x64/mcs/class/corlib/System.IO/File.cs:111 
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018:   at Xamarin.Android.Tools.Files.CopyIfChanged (System.String source, System.String destination) [0x00027] in <85b0a2338aa04872b3b64fcf0b67c0bd>:0 

/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: The "ConvertResourcesCases" task failed unexpectedly.
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: System.IO.FileNotFoundException: /var/folders/zz/xvp_v21d0_qgnjn2xd4kqsrh0000gn/T/tmp3b73f1d.tmp does not exist
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018: File name: '/var/folders/zz/xvp_v21d0_qgnjn2xd4kqsrh0000gn/T/tmp3b73f1d.tmp'
/Library/Frameworks/Mono.framework/External/xbuild/Xamarin/Android/Xamarin.Android.Common.targets(1666,2): error MSB4018:   at System.IO.File.Copy (System.String sourceFileName, System.String destFileName, System.Boolean overwrite) [0x00193] in /Users/builder/jenkins/workspace/build-package-osx-mono/2018-06/external/bockbuild/builds/mono-x64/mcs/class/corlib/System.IO/File.cs:111 

Version Information

https://gist.github.com/pjcollins/2dbe0b3beb7a61ffb84b7f6e8a2e712a

Log File

https://gist.github.com/pjcollins/f758cbbca74519af957fcaca5f4dc957
http://xqa.blob.core.windows.net/gist/log-0ae5db3450514d0d8dfc2f41a17141fc.txt
https://gist.github.com/pjcollins/c987b9044fbb556cf68dcbc3c7d22495

VS bug #660461

[jonathanpeppers]

I think this one might be related: #2017

I could never repro it myself...

[jonathanpeppers]

@dellis1972 any ideas?

Here is what I've seen when I try the steps above:

1. Sometimes it works
2. Sometimes ConvertResourcesCases throws an IOException
3. Sometimes Aapt fails complaining about an empty file (log here)

From what I'm seeing the _CleanIntermediateIfNuGetsChange target runs (triggers _CleanMonoAndroidIntermediateDir) and deletes obj/Debug/lp. This seems like it would be a good thing, since we are working with newer NuGet packages.

Then later ConvertResourcesCases seems to be working with empty files:

Resources/values-km/values-km.xml warning XA1001: AndroidResgen: Warning while updating Resource XML '/var/folders/nx/rzr6lcqj6j3_vp7vtp28v2cw0000gn/T/tmp705331d9.tmp': Root element is missing. [/Users/jonathanpeppers/Projects/bologna4/bologna4/bologna4.csproj]
Resources/anim/abc_popup_enter.xml warning XA1001: AndroidResgen: Warning while updating Resource XML '/var/folders/nx/rzr6lcqj6j3_vp7vtp28v2cw0000gn/T/tmp53847595.tmp': Root element is missing. [/Users/jonathanpeppers/Projects/bologna4/bologna4/bologna4.csproj]

Sometimes an IOException is thrown here instead...

[dellis1972]

This sounds like multiple msbuild tasks are running at the same time... one of partly copying files over while the other is trying to process them.. My understanding was that VS didn't allow that.. perhaps thats wrong .. in which case thats a problem :(

[dellis1972]

Oooo. I just remembered we had an issue recently where we could not create temp files on windows. This is because windows has a hard limit on the number of temp files it can create (65535).

Only the lower 16 bits of the uUnique parameter are used. This limits GetTempFileName to a maximum of 65,535 unique file names if the lpPathName and lpPrefixString parameters remain the same

I wonder if this is causing problems...
[1] https://docs.microsoft.com/en-us/windows/desktop/api/fileapi/nf-fileapi-gettempfilenamea

[dellis1972]

see https://devdiv.visualstudio.com/DevDiv/_workitems/edit/626304

[jonathanpeppers]

@dellis1972 we've been seeing this on Mac... I hadn't tried to repro on Windows yet.

Do we know if VS for Mac could be running some kind of design-time build at the same time? Would the IDE log show that?

[dellis1972]

No idea. Not even sure where to look for that.

…

Sent from my Windows 10 device From: Jonathan Peppers Sent: 08 August 2018 13:43 To: xamarin/xamarin-android Cc: Dean Ellis; Mention Subject: Re: [xamarin/xamarin-android] Occasionally encountering strange racecondition or timing issue in `ConvertResourcesCases` (#2043) @dellis1972 we've been seeing this on Mac... I hadn't tried to repro on Windows yet. Do we know if VS for Mac could be running some kind of design-time build at the same time? Would the IDE log show that? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

[jonathanpeppers]

I spent a lot of time debugging this, and I think I finally understand what is going on...

If I add this code to ConvertResourcesCases.Execute:

var process = Process.GetCurrentProcess ();
File.AppendAllText ("ConvertResourcesCases.log", $"ConvertResourcesCases: {DateTime.UtcNow} {process.ProcessName} {process.Id} {Environment.NewLine}");

This puts a log file in the same directory as the project.

At the step right before updating the NuGet packages, I delete the file so it's empty.

Then I can see it gets invoked by different processes, even though I only built once:

ConvertResourcesCases: 8/9/2018 1:03:54 PM mono-sgen64 7136
ConvertResourcesCases: 8/9/2018 1:03:54 PM mono-sgen64 7152
ConvertResourcesCases: 8/9/2018 1:04:02 PM mono-sgen64 7136

Another proof that builds are happening in parallel, is if I do this:

1. Build the new project
2. Update NuGets
3. Count to "10 Mississippi"
4. Build

It seems to work. What consistently seems to break is when you start a build quickly after updating NuGets.

What broke this?

I suspect: #1878

This change will delete obj\Debug\lp (and others) when NuGets change. Otherwise, we weren't actually using newer *.jar files or resource files from the updated NuGet packages!

After reviewing the code, it seems builds happening in parallel could break if __AndroidLibraryProjects__.zip isn't extracted yet.

How to fix it?

On Xamarin.Android's end, I think I can make some improvements where if things go wrong, bad/empty files aren't copied and passed to <Aapt />. Right now when you get into a broken state, you have to Rebuild to fix it...

@sgmunn question for VS for Mac:

• When you right click on Packages in the solution tree and select Update, is there some kind of automatic build happening?
• Sometimes I've seen a message "Updating Android resources...", I wonder if this is it? Maybe it runs this UpdateAndroidResources target: https://github.com/xamarin/xamarin-android/blob/90edf815a679a7e5488733d7629ef45a6ba75751/src/Xamarin.Android.Build.Tasks/Xamarin.Android.Common.targets#L1261
• Is there a way to make it make a build wait to start if another build is happening?