.Net Core 2.2 console application : System.Private.CoreLib System.ArgumentOutOfRangeException (FileSystemWatcher)

[carlossanlop]

From @patrick-blanc on Thursday, May 16, 2019 1:29:06 PM

Getting unhandled exception from System.Private.CoreLib

System.ArgumentOutOfRangeException
HResult=0x80131502
Message=startIndex cannot be larger than length of string.
Parameter name: startIndex
Source=System.Private.CoreLib
StackTrace:
at System.String.Substring(Int32 startIndex, Int32 length)
at Microsoft.Extensions.FileProviders.Physical.PhysicalFilesWatcher.OnFileSystemEntryChange(String fullPath)
at Microsoft.Extensions.FileProviders.Physical.PhysicalFilesWatcher.OnRenamed(Object sender, RenamedEventArgs e)
at System.IO.FileSystemWatcher.NotifyRenameEventArgs(WatcherChangeTypes action, String name, String oldName)
at System.IO.FileSystemWatcher.ParseEventBufferAndNotifyForEach(Byte[] buffer)
at System.IO.FileSystemWatcher.ReadDirectoryChangesCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* overlappedPointer)
at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)

My console application (running on windows machine) try to run "npm install" command in different task on different folders.

Sometimes, I get the exception sometimes not. I am not using any FileWatcher in my console application. So my question is why did I get this exception from .net core. Is a .net core console app using by default a file watcher ? Anyone to help me to get rid of that exception.

Here is information from dotnet --info

> .NET Core SDK (reflecting any global.json):
>  Version:   2.2.204
>  Commit:    8757db13ec
> 
> Runtime Environment:
>  OS Name:     Windows
>  OS Version:  10.0.17134
>  OS Platform: Windows
>  RID:         win10-x64
>  Base Path:   C:\Program Files\dotnet\sdk\2.2.204\
> 
> Host (useful for support):
>   Version: 2.2.5
>   Commit:  0a3c9209c0
> 
> .NET Core SDKs installed:
>   2.1.602 [C:\Program Files\dotnet\sdk]
>   2.1.604 [C:\Program Files\dotnet\sdk]
>   2.2.202 [C:\Program Files\dotnet\sdk]
>   2.2.204 [C:\Program Files\dotnet\sdk]
> 
> .NET Core runtimes installed:
>   Microsoft.AspNetCore.All 2.1.9 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
>   Microsoft.AspNetCore.All 2.1.11 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
>   Microsoft.AspNetCore.All 2.2.3 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
>   Microsoft.AspNetCore.All 2.2.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
>   Microsoft.AspNetCore.App 2.1.9 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
>   Microsoft.AspNetCore.App 2.1.11 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
>   Microsoft.AspNetCore.App 2.2.3 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
>   Microsoft.AspNetCore.App 2.2.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
>   Microsoft.NETCore.App 2.1.9 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
>   Microsoft.NETCore.App 2.1.11 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
>   Microsoft.NETCore.App 2.2.3 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
>   Microsoft.NETCore.App 2.2.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]

I see a thread related to same exception on aspnetcore (1 year ago) : #dotnet/aspnetcore#2536

it seems it has been fixed in release 2.0.1 of Microsoft.Extensions.FileProviders.Physical, as I am using .net core 2.2 I don't think it's related. As said before I am not creating any FileWatcher. My code is basically checking if directory exists (like node_modules) if not it run a process (cmd) and run the npm install.

Notice that I find strange that PhysicalFilesWatcher.OnRenamed is throwing an exception on System.String.Substring(Int32 startIndex, Int32 length) because OnRenamed does not use this method but is using System.String.Substring(Int32 startIndex)

Thanks for your help
any hints would be greatly appreciated

Copied from original issue: dotnet/corefx#37707

[carlossanlop]

From @patrick-blanc on Tuesday, May 21, 2019 10:31:29 AM

After investigations, we found that problem seems to be related to this commands.

.AddJsonFile("appsettings.json", false, true)

By settings true for reload on change (that was a mistake done by c/c code), a file system watched is created but not only on the appsettings file. The file system start check the entire files in all folders, subfolders. This produce a memory leak done by the FileSystemWatcher that was taking memory and memory each time a npm install was done by a child process of the console app.

To fix it I just set the reloadOnChange to false. It does not create any watcher then and no memory problem at least.

.AddJsonFile("appsettings.json", false, false)

[carlossanlop]

From @JeremyKuhne on Monday, June 3, 2019 9:09:38 PM

This should be in https://github.com/aspnet/Extensions. @karelz do you have write access to transfer this or know who does?

Microsoft.Extensions.FileProviders.Physical.PhysicalFilesWatcher.OnFileSystemEntryChange should be hardened for the reported call stack.

[analogrelay]

Notice that I find strange that PhysicalFilesWatcher.OnRenamed is throwing an exception on System.String.Substring(Int32 startIndex, Int32 length) because OnRenamed does not use this method but is using System.String.Substring(Int32 startIndex)

This is probably due to inlining. Substring(Int32) just calls straight in to Substring(Int32, Int32) so it's probably getting inlined.

Can you clarify what you were doing in the file system when this changed? Were you moving files in or out of the project directory? I do see a possible case where this exception could be thrown but it would only be if a file was moved out of the directory.

This is something we should consider hardening for. Basically, my hunch is that if you have a file under the watched directory and then move it outside the watched directory, to a location with a shorter base path, then the Substring call could fail like this since we assume the path is prefixed by the root directory.

[ghost]

As part of the migration of components from dotnet/extensions to dotnet/runtime (aspnet/Announcements#411) we will be bulk closing some of the older issues. If you are still interested in having this issue addressed, just comment and the issue will be automatically reactivated (even if you aren't the author). When you do that, I'll page the team to come take a look. If you've moved on or workaround the issue and no longer need this change, just ignore this and the issue will be closed in 7 days.

If you know that the issue affects a package that has moved to a different repo, please consider re-opening the issue in that repo. If you're unsure, that's OK, someone from the team can help!

[carlossanlop]

@patrick-blanc your issue was moved to this repo. Can you please help answer @anurse's questions?

[ghost]

Paging @dotnet/extensions-migration ! This issue has been revived from staleness. Please take a look and route to the appropriate repository.

[dlyz]

There is some new information about this issue.

1. It can be reproduced (see gist).
2. Required preconditions to reproduce it: parallel renames of physical files (at least two threads), a non-empty directory with a name of length 1 (directory 'a' in gist), working PhysicalFilesWatcher.
3. Exceptions with one-letter-directory-names is not a true cause, it just a consequence of the real bug, which does not produce any exceptions without one-letter-directory-names, but the behavior is still incorrect.
4. The real problem is here: sometimes e.FullPath or e.OldFullPath can not be detected and corresponding property contains root path with the trailing slash (strange undocumented api behavior?). Then substring will cut off one excess char and combine will produce incorrect path.
5. The real real problem is here, because this code can not correctly work with mixed rename events in the buffer and the resulting behavior for this case is not obvious at all.

[carlossanlop]

@patrick-blanc @dlyz I recently fixed a bug in ParseEventBufferAndNotifyForEach, although that issue is not exactly the same, I wonder if the actual fix may have made the underlying FileSystemWatcher more stable and ended up getting rid of this problem. #42419

• Did your repro occur when attempting to monitor files over the network by any chance?
• Can you please try to repro with 5.0 see if the issue is still happening?

[maryamariyan]

It can be reproduced (see gist).

@carlossanlop the gist linked from @dlyz still gives a repro with net5.0 and latest packages.

[danmoseley]

Next step is probably to run the repo while logging what

runtime/src/libraries/System.IO.FileSystem.Watcher/src/System/IO/FileSystemWatcher.Win32.cs

Line 253 in d0e2281

private unsafe void ParseEventBufferAndNotifyForEach(byte[] buffer)

is receiving and in what order, specifically the rename events. Perhaps the OS is giving us these events in an unexpected ordering.