.NET Tool Crashes When Run Concurrently

[Kurt-von-Laven]

I suspect #728 remains present at dotnet-csharpier 0.19.1, which we run as a pre-commit hook both locally and in CI. Here is the relevant excerpt from our .pre-commit-config.yaml:

- id: csharpier
  name: Run CSharpier on C# files
  entry: dotnet
  language: system
  types:
    - c#
  args: [tool, run, dotnet-csharpier]

When we run pre-commit on all files in our repository, it filters out any non-C# files and feeds the rest to dotnet-csharpier in multiple batches, effectively running a series of commands of the following form in quick succession:

dotnet tool run dotnet-csharpier a1.cs b1.cs c1.cs ...
dotnet tool run dotnet-csharpier a2.cs b2.cs c2.cs ...
dotnet tool run dotnet-csharpier a3.cs b3.cs c3.cs ...
...

This seems to work reliably locally, but fails about 2/3 to 3/4 of the time in CI, starting when we upgraded from CSharpier 0.18.0 to 0.19.1. Perhaps the difference stems from there being more limited computing resources available in CI. Here is the pertinent pre-commit output from one of the failed runs:

Run CSharpier on C# files.....................................................Failed
- hook id: csharpier
- exit code: 1

Unhandled exception: System.Text.Json.JsonException: 'h' is invalid after a single JSON value. Expected end of data. Path: $['/home/runner/work/path/to/the/first/cs/file/lexicographically/in/our/repository.cs'] | LineNumber: 0 | BytePositionInLine: 2978.
 ---> System.Text.Json.JsonReaderException: 'h' is invalid after a single JSON value. Expected end of data. LineNumber: 0 | BytePositionInLine: 2978.
   at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes)
   at System.Text.Json.Utf8JsonReader.ConsumeNextToken(Byte marker)
   at System.Text.Json.Utf8JsonReader.ConsumeNextTokenOrRollback(Byte marker)
   at System.Text.Json.Utf8JsonReader.ReadSingleSegment()
   at System.Text.Json.Utf8JsonReader.Read()
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   --- End of inner exception stack trace ---
   at System.Text.Json.ThrowHelper.ReThrowWithPath(ReadStack& state, JsonReaderException ex)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 utf8Json, JsonTypeInfo jsonTypeInfo, Nullable`1 actualByteCount)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 json, JsonTypeInfo jsonTypeInfo)
   at System.Text.Json.JsonSerializer.Deserialize[TValue](String json, JsonSerializerOptions options)
   at CSharpier.Cli.FormattingCacheFactory.InitializeAsync(CommandLineOptions commandLineOptions, PrinterOptions printerOptions, IFileSystem fileSystem, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/FormattingCache.cs:line 48
   at CSharpier.Cli.FormattingCacheFactory.InitializeAsync(CommandLineOptions commandLineOptions, PrinterOptions printerOptions, IFileSystem fileSystem, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/FormattingCache.cs:line 61
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass27_0.<<UseVersionOption>b__1>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass25_0.<<UseTypoCorrections>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<UseSuggestDirective>b__24_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<<UseParseDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass11_0.<<UseDebugDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<RegisterWithDotnetSuggest>b__10_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass14_0.<<UseExceptionHandler>b__0>d.MoveNext()

Please let me know if I can provide additional information.

[belav]

It sounds like somehow the json file is getting corrupted, possibly with multiple processes trying to read and write it at the same time. I should have a chance to dig into trying to reproduce this locally in the next few days. As a fallback option, I am debating between adding an option to disable the cache or catching exceptions like this and falling back to not using the cache.

The only thing I am curious about, does the error message vary? If so that seems like a good indication my hunch about two processes writing the file at the same time is correct.

[Kurt-von-Laven]

Yes, the message varies slightly. Here is a different example:

Unhandled exception: System.Text.Json.JsonException: '"' is invalid after a single JSON value. Expected end of data. Path: $['/home/runner/work/path/to/some/other/cs/file/in/our/repository.cs'] | LineNumber: 0 | BytePositionInLine: 4130.
 ---> System.Text.Json.JsonReaderException: '"' is invalid after a single JSON value. Expected end of data. LineNumber: 0 | BytePositionInLine: 4130.
   at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes)
   at System.Text.Json.Utf8JsonReader.ConsumeNextToken(Byte marker)
   at System.Text.Json.Utf8JsonReader.ConsumeNextTokenOrRollback(Byte marker)
   at System.Text.Json.Utf8JsonReader.ReadSingleSegment()
   at System.Text.Json.Utf8JsonReader.Read()
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   --- End of inner exception stack trace ---
   at System.Text.Json.ThrowHelper.ReThrowWithPath(ReadStack& state, JsonReaderException ex)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 utf8Json, JsonTypeInfo jsonTypeInfo, Nullable`1 actualByteCount)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 json, JsonTypeInfo jsonTypeInfo)
   at System.Text.Json.JsonSerializer.Deserialize[TValue](String json, JsonSerializerOptions options)
   at CSharpier.Cli.FormattingCacheFactory.InitializeAsync(CommandLineOptions commandLineOptions, PrinterOptions printerOptions, IFileSystem fileSystem, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/FormattingCache.cs:line 48
   at CSharpier.Cli.FormattingCacheFactory.InitializeAsync(CommandLineOptions commandLineOptions, PrinterOptions printerOptions, IFileSystem fileSystem, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/FormattingCache.cs:line 61
   at CSharpier.Cli.CommandLineFormatter.FormatPhysicalFiles(CommandLineFormatterResult commandLineFormatterResult, CommandLineOptions commandLineOptions, IFileSystem fileSystem, IConsole console, ILogger logger, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/CommandLineFormatter.cs:line 139
   at CSharpier.Cli.CommandLineFormatter.Format(CommandLineOptions commandLineOptions, IFileSystem fileSystem, IConsole console, ILogger logger, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/CommandLineFormatter.cs:line 63
   at CSharpier.Cli.Program.Run(String[] directoryOrFile, Boolean check, Boolean fast, Boolean skipWrite, Boolean writeStdout, Boolean pipeMultipleFiles, Boolean noCache, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/Program.cs:line 81
   at System.CommandLine.Invocation.CommandHandler.GetExitCodeAsync(Object value, InvocationContext context)
   at System.CommandLine.Invocation.ModelBindingCommandHandler.InvokeAsync(InvocationContext context)
   at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<<BuildInvocationChain>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass23_0.<<UseParseErrorReporting>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass16_0.<<UseHelp>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass27_0.<<UseVersionOption>b__1>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass25_0.<<UseTypoCorrections>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<UseSuggestDirective>b__24_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<<UseParseDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass11_0.<<UseDebugDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<RegisterWithDotnetSuggest>b__10_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass14_0.<<UseExceptionHandler>b__0>d.MoveNext()
Unhandled exception: System.Text.Json.JsonException: '"' is invalid after a single JSON value. Expected end of data. Path: $['/home/runner/work/scribemd-uwp/scribemd-uwp/jScribeMDXVII/ExperiencePage.xaml.cs'] | LineNumber: 0 | BytePositionInLine: [413](https://github.com/ScribeMD/scribemd-uwp/runs/8164922315?check_suite_focus=true#step:6:434)0.
 ---> System.Text.Json.JsonReaderException: '"' is invalid after a single JSON value. Expected end of data. LineNumber: 0 | BytePositionInLine: 4130.
   at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes)
   at System.Text.Json.Utf8JsonReader.ConsumeNextToken(Byte marker)
   at System.Text.Json.Utf8JsonReader.ConsumeNextTokenOrRollback(Byte marker)
   at System.Text.Json.Utf8JsonReader.ReadSingleSegment()
   at System.Text.Json.Utf8JsonReader.Read()
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   --- End of inner exception stack trace ---
   at System.Text.Json.ThrowHelper.ReThrowWithPath(ReadStack& state, JsonReaderException ex)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 utf8Json, JsonTypeInfo jsonTypeInfo, Nullable`1 actualByteCount)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 json, JsonTypeInfo jsonTypeInfo)
   at System.Text.Json.JsonSerializer.Deserialize[TValue](String json, JsonSerializerOptions options)
   at CSharpier.Cli.FormattingCacheFactory.InitializeAsync(CommandLineOptions commandLineOptions, PrinterOptions printerOptions, IFileSystem fileSystem, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/FormattingCache.cs:line 48
   at CSharpier.Cli.FormattingCacheFactory.InitializeAsync(CommandLineOptions commandLineOptions, PrinterOptions printerOptions, IFileSystem fileSystem, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/FormattingCache.cs:line 61
   at CSharpier.Cli.CommandLineFormatter.FormatPhysicalFiles(CommandLineFormatterResult commandLineFormatterResult, CommandLineOptions commandLineOptions, IFileSystem fileSystem, IConsole console, ILogger logger, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/CommandLineFormatter.cs:line 139
   at CSharpier.Cli.CommandLineFormatter.Format(CommandLineOptions commandLineOptions, IFileSystem fileSystem, IConsole console, ILogger logger, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/CommandLineFormatter.cs:line 63
   at CSharpier.Cli.Program.Run(String[] directoryOrFile, Boolean check, Boolean fast, Boolean skipWrite, Boolean writeStdout, Boolean pipeMultipleFiles, Boolean noCache, CancellationToken cancellationToken) in /home/runner/work/csharpier/csharpier/Src/CSharpier.Cli/Program.cs:line 81
   at System.CommandLine.Invocation.CommandHandler.GetExitCodeAsync(Object value, InvocationContext context)
   at System.CommandLine.Invocation.ModelBindingCommandHandler.InvokeAsync(InvocationContext context)
   at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<<BuildInvocationChain>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass23_0.<<UseParseErrorReporting>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass16_0.<<UseHelp>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass27_0.<<UseVersionOption>b__1>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass25_0.<<UseTypoCorrections>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<UseSuggestDirective>b__24_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<<UseParseDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass11_0.<<UseDebugDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<RegisterWithDotnetSuggest>b__10_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass14_0.<<UseExceptionHandler>b__0>d.MoveNext()

As a workaround, we added require_serial: true to the hook definition, disabling concurrency. So far that seems to have worked, although we haven't run many trials yet.

[belav]

I believe this should be resolved now with 0.19.2. I could reproduce the problem you saw semi-reliably and found a couple other issues.

[Kurt-von-Laven]

The fixes appear to be working for us so far, so I have removed require_serial: true from the pre-commit hook definition; thank you!