Frequent "file being used by another process IOException" when building documentation

Hi, I maintain https://github.com/microsoft/FactoryOrchestrator, which uses DefaultDocumentation to generate markdown files.

When building both locally and in ADO I frequently hit "Unhandled Exception: System.AggregateException: One or more errors occurred. ---> System.Exception: Error while writing documentation for Microsoft.FactoryOrchestrator.Core ---> System.IO.IOException: The process cannot access the file 'D:\FactoryOrchestrator\bin\DefaultDocumentation\CoreLibrary\Microsoft-FactoryOrchestrator-Core.md' because it is being used by another process."

By adding basic retry logic I am able to work around the issue, but I couldn't figure out the root cause of the exception, all threads are writing different files at the time of the exception.

A dump captured from running the debug version of your tool (0.6.13) I built locally is at https://1drv.ms/u/s!AigADXVMXV_6t8ML930SnhDu6vxfog?e=xOd4uQ

You might also be able to repro by checking out and building https://github.com/microsoft/FactoryOrchestrator

The retry logic I added (EDIT, one retry works fine in debug, but not for release, updated to 10 retries):

        public void WriteDocumentation(string outputFolderPath, int retryIOException = 0)
        {
            _docItems.Values.Where(i => i.GeneratePage).AsParallel().ForAll(i =>
            {
                try
                {
                    using DocumentationWriter writer = new DocumentationWriter(_fileNameMode, _nestedTypeVisibility, _wikiLinks, _docItems, _links, outputFolderPath, i);
                    i.WriteDocumentation(writer);

                }
                catch (Exception exception)
                {
                    if (retryIOException < 10 && exception is System.IO.IOException)
                    {
                        // Retry up to 10 times on IOException
                        WriteDocumentation(outputFolderPath, ++retryIOException);
                    }
                    else
                    {
                        throw new Exception($"Error while writing documentation for {i.FullName}", exception);
                    }
                }
            });
        }

While I would love to root cause this and get a real fix, maybe adding this logic or something similar in the interm might help me and any others who hit this?

Removing AsParallel().ForAll and using a serial foreachalso resolves the issue.

Full exception stack:

  Unhandled Exception: System.AggregateException: One or more errors occurred. ---> System.Exception: Error while writing documentation for Microsoft.FactoryOrchestrator.Core ---> System.IO.IOException: The process cannot access the file 'D:\FactoryOrchestrator\bin\DefaultDocumentation\CoreLibrary\Microsoft-FactoryOrchestrator-Core.md' because it is being used by another process.
     at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
     at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
     at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
     at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost)
     at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost)
     at System.IO.File.InternalWriteAllText(String path, String contents, Encoding encoding, Boolean checkHost)
     at DefaultDocumentation.DocumentationWriter.Dispose()
     at DefaultDocumentation.DocumentationGenerator.<>c__DisplayClass10_0.<WriteDocumentation>b__1(DocItem i)
     --- End of inner exception stack trace ---
     at DefaultDocumentation.DocumentationGenerator.<>c__DisplayClass10_0.<WriteDocumentation>b__1(DocItem i)
     at System.Linq.Parallel.ForAllOperator`1.ForAllEnumerator`1.MoveNext(TInput& currentElement, Int32& currentKey)
     at System.Linq.Parallel.ForAllSpoolingTask`2.SpoolingWork()
     at System.Linq.Parallel.SpoolingTaskBase.Work()
     at System.Linq.Parallel.QueryTask.BaseWork(Object unused)
     at System.Threading.Tasks.Task.Execute()
     --- End of inner exception stack trace ---
     at System.Linq.Parallel.QueryTaskGroupState.QueryEnd(Boolean userInitiatedDispose)
     at System.Linq.Parallel.DefaultMergeHelper`2.System.Linq.Parallel.IMergeHelper<TInputOutput>.Execute()
     at System.Linq.Parallel.MergeExecutor`1.Execute[TKey](PartitionedStream`2 partitions, Boolean ignoreOutput, ParallelMergeOptions options, TaskScheduler taskScheduler, Boolean isOrdered, CancellationState cancellationState, Int32 queryId)
     at System.Linq.Parallel.PartitionedStreamMerger`1.Receive[TKey](PartitionedStream`2 partitionedStream)
     at System.Linq.Parallel.ForAllOperator`1.WrapPartitionedStream[TKey](PartitionedStream`2 inputStream, IPartitionedStreamRecipient`1 recipient, Boolean preferStriping, QuerySettings settings)
     at System.Linq.Parallel.UnaryQueryOperator`2.UnaryQueryOperatorResults.ChildResultsRecipient.Receive[TKey](PartitionedStream`2 inputStream)
     at System.Linq.Parallel.ScanQueryOperator`1.ScanEnumerableQueryOperatorResults.GivePartitionedStream(IPartitionedStreamRecipient`1 recipient)
     at System.Linq.Parallel.UnaryQueryOperator`2.UnaryQueryOperatorResults.GivePartitionedStream(IPartitionedStreamRecipient`1 recipient)
     at System.Linq.Parallel.QueryOperator`1.GetOpenedEnumerator(Nullable`1 mergeOptions, Boolean suppressOrder, Boolean forEffect, QuerySettings querySettings)
     at System.Linq.Parallel.ForAllOperator`1.RunSynchronously()
     at DefaultDocumentation.Program.Main(String[] args)

Out of curiosity, I tried a few things.

This bug also repros on your Dummy project with the following arguments: /assembly:D:\DefaultDocumentation\source\Dummy\bin\Release\net5.0\Dummy.dll /xml:D:\DefaultDocumentation\source\Dummy\documentation\Dummy.xml /output:"D:\DummyOut" /home:"Dummy" /fileNameMode:"FullName" /nestedTypeVisibility:"Namespace" /invalidCharReplacement:"" /wikiLinks:"false"

Maybe I'm doing something non-standard in my args?

Here is the average and median runtimes in milliseconds when of running your tool 100 times on my project with the above parallel & retry logic versus serial logic, on the release build of 0.6.13 I made. Since the tool still runs pretty fast even with no parallelism, it might be worth considering removing parallelism entirely here... (I was unable to test with Dummy as that threw this exception even with 10 retries allowed!)

Args used:

/assembly:"D:\FactoryOrchestrator\bin\Debug\AnyCPU\Microsoft.FactoryOrchestrator.Core\netstandard2.0\Microsoft.FactoryOrchestrator.Core.dll" /xml:"D:\FactoryOrchestrator\bin\Debug\AnyCPU\Microsoft.FactoryOrchestrator.Core\netstandard2.0\Microsoft.FactoryOrchestrator.Core.xml" /output:"D:\FactoryOrchestrator\bin\DefaultDocumentation\CoreLibrary" /home:"Microsoft.FactoryOrchestrator.Core" /fileNameMode:"FullName" /nestedTypeVisibility:"Namespace" /invalidCharReplacement:"" /wikiLinks:"false"

 /assembly:D:\DefaultDocumentation\source\Dummy\bin\Release\net5.0\Dummy.dll /xml:D:\DefaultDocumentation\source\Dummy\documentation\Dummy.xml /output:"D:\DummyOut" /home:"Dummy" /fileNameMode:"FullName" /nestedTypeVisibility:"Namespace" /invalidCharReplacement:"" /wikiLinks:"false"

	FactoryOrchestrator	Dummy
Parallel & 10 retry max (AVG)	624.55 ms	Crashes
Parallel & 10 retry max (MED)	620 ms	Crashes
Serial (AVG)	914.62ms	197.01 ms
Serial (MED)	864 ms	188 ms

It seems like moving to serial using foreach might be the most reliable fix.

        public void WriteDocumentation(string outputFolderPath)
        {
            foreach (var doc in _docItems.Values.Where(i => i.GeneratePage))
            {
                try
                {
                    using DocumentationWriter writer = new DocumentationWriter(_fileNameMode, _nestedTypeVisibility, _wikiLinks, _docItems, _links, outputFolderPath, doc);
                    doc.WriteDocumentation(writer);

                }
                catch (Exception exception)
                {
                   throw new Exception($"Error while writing documentation for {doc.FullName}", exception);
                }
            }
        }

hum I did put a retry logic when deleting the files at the start https://github.com/Doraku/DefaultDocumentation/blob/bd26f1c99e47317f46a49c4820b3f973fdae87ef/source/DefaultDocumentation/Program.cs#L111 but completely ignored the file creation. It did happened to me because I was using multiple TargetFrameworks on my projects so my fix was to put condition in the csproj to only generate DefaultDocumentation for a single target but your reproduction is kinda alarming :/ Thanks for all this, I will look into it!

I can't reproduce it but I have a fairly old cpu, so maybe there's something wrong with the file system when trying to write too many files at the same time :/ I took your word for it and removed the parallel execution, premature optimization probably biting me in the ass eh. As you said it didn't do much :)

I really appreciate you addressing this so quickly @Doraku !

Thanks for writing such a useful piece of OSS, this was the best doc generator out of the (admittedly only a handful of) ones I tried 😃, and your prompt resolution here only helps confirm that 🥇 .

Doraku / DefaultDocumentation

Frequent "file being used by another process IOException" when building documentation #39