My app crash randomly with error `Exception Info: System.IO.IOException: The process cannot access the file 'C:\...\Logs.log' because it is being used by another process.`

[AoooR42]

Hello, I have a problem that I think comes from this extension. My application is hosted on a Windows Server with IIS. It works perfectly for several days, then after a while it crashes with the error Exception Info: System.IO.IOException: The process cannot access the file 'C:\...\Logs.log' because it is being used by another process.

At first I thought it was because the log file was open next to it in Visual Studio, but even after closing the file and restarting my app, the error comes back a few days later. I'm pretty sure the log file isn't used anywhere else. And even if it is opened elsewhere, it shouldn't be a problem in theory, since I can open it in parallel with Visual Studio, and see the changes made to the file by nreco/logging. (so there's no problem with a file being opened and modified by two programs at the same time).

The extension is supposed to handle concurrency problems and use a queue, so I don't understand where the problem comes from, especially as the crashes occur at times that seem random and irregular to me.

Here is the full exception message:

Application: w3wp.exe
CoreCLR Version: 7.0.523.17405
.NET Version: 7.0.5
Description: The process was terminated due to an unhandled exception.
Exception Info: System.IO.IOException: The process cannot access the file 'C:\...\Logs.log' because it is being used by another process.
   at Microsoft.Win32.SafeHandles.SafeFileHandle.CreateFile(String fullPath, FileMode mode, FileAccess access, FileShare share, FileOptions options)
   at Microsoft.Win32.SafeHandles.SafeFileHandle.Open(String fullPath, FileMode mode, FileAccess access, FileShare share, FileOptions options, Int64 preallocationSize, Nullable`1 unixCreateMode)
   at System.IO.Strategies.OSFileStreamStrategy..ctor(String path, FileMode mode, FileAccess access, FileShare share, FileOptions options, Int64 preallocationSize, Nullable`1 unixCreateMode)
   at System.IO.Strategies.FileStreamHelpers.ChooseStrategyCore(String path, FileMode mode, FileAccess access, FileShare share, FileOptions options, Int64 preallocationSize, Nullable`1 unixCreateMode)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access)
   at NReco.Logging.File.FileLoggerProvider.FileWriter.<OpenFile>g__createLogFileStream|7_0(<>c__DisplayClass7_0&)
   at NReco.Logging.File.FileLoggerProvider.FileWriter.OpenFile(Boolean append)
   at NReco.Logging.File.FileLoggerProvider.FileWriter..ctor(FileLoggerProvider fileLogPrv)
   at NReco.Logging.File.FileLoggerProvider..ctor(String fileName, FileLoggerOptions options)
   at NReco.Logging.File.FileLoggerProvider..ctor(String fileName, Boolean append)
   at Microsoft.Extensions.Logging.FileLoggerExtensions.<>c__DisplayClass0_0.<AddFile>b__0(IServiceProvider srvPrv)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitIEnumerable(IEnumerableCallSite enumerableCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(Type serviceType)
   at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider, Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)
   at Microsoft.Extensions.Hosting.HostBuilder.<>c__DisplayClass35_0.<PopulateServiceCollection>b__2(IServiceProvider _)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(Type serviceType)
   at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider, Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)
   at Microsoft.Extensions.Hosting.HostBuilder.ResolveHost(IServiceProvider serviceProvider, DiagnosticListener diagnosticListener)
   at Microsoft.Extensions.Hosting.HostApplicationBuilder.Build()
   at Microsoft.AspNetCore.Builder.WebApplicationBuilder.Build()
   at Program.<Main>$(String[] args) in D:\...\Program.cs:line 32

As far as I'm concerned, the problem is just on line 32 of my Main, after that the problem comes solely from dotnet and this extension. My Program.cs:

using ...;

var builder = WebApplication.CreateBuilder(args); 

const string corsPolicyName = "CorsPolicySysProd";
var logFolderPath = builder.Environment.IsDevelopment() ? string.Empty : "C:\\inetpub\\logs\\LogFiles";
const string logFileName = "Logs.log";

// Add services to the container.

builder.Services.AddCors(options =>
    options.AddPolicy(corsPolicyName, corsBuilder =>
        corsBuilder.WithOrigins("http://..").AllowAnyMethod().AllowAnyHeader()));
builder.Services.AddControllers();
builder.Services.AddEndpointsApiExplorer();
builder.Services.AddSwaggerGen(options =>
{
    // add a custom operation filter which sets default values
    options.OperationFilter<SwaggerDefaultValues>();

    var fileName = typeof(Program).Assembly.GetName().Name + ".xml";
    var filePath = Path.Combine(AppContext.BaseDirectory, fileName);

    // integrate xml comments
    options.IncludeXmlComments(filePath);
});
builder.Services.AddLogging(loggingBuilder => loggingBuilder.AddFile(Path.Combine(logFolderPath, logFileName), append: true));

var app = builder.Build();

// Configure the HTTP request pipeline.

app.UseSwagger();
app.UseSwaggerUI();

//HTTPS redirection is disabled because ... is in HTTP.
//app.UseHttpsRedirection();

app.UseCors(corsPolicyName);

app.UseAuthorization();

app.MapControllers();

app.Run();

The only workaround I have so far is to restart the app in case of a crash. Let me know if there's anything else I can do to help identify the problem. thanks in advance for your help, and thanks for creating this extension :)

[VitaliyMF]

It works perfectly for several days, then after a while it crashes with the error Exception Info: System.IO.IOException: The process cannot access the file 'C:...\Logs.log' because it is being used by another process.

NReco.Logging.File expects that one logging file is used only by one application instance (exclusively). It tries to open a log file for write on the application start and keeps it open while application is running.

In your case, it might be possible that IIS tries to start 2nd application instance and if your app is configured for the same log file this error may occur. To prevent this you may specify custom HandleFileError handler (see https://github.com/nreco/logging#file-errors-handling) where typical behavior is choosing another log file name that is 100% is not used yet (or simply ignore this error to disable file logging).

[AoooR42]

Hello, sorry for not giving any news, I used HandleFileError, but for a week I haven't had any new crashes, so I haven't been able to test if it works or not. I don't know if I should leave this ticket open?

[VitaliyMF]

@AoooR42 if you defined "HandleFileError" handler you cannot get any file-open errors because they are suppressed and it is expected that your code inside this handler determines what to do if file cannot be opened.

If you want to test it just try to run your 2 instances of your app (that use the same log file) in your dev env.

[AoooR42]

I said "I haven't had any new crashes" because I defined in my HandleFileError to create a new log file in case of a crash, and since a week my logs are still written in the same log file, and there is no new file created 👍

[JiriZidek]

Me-too: See #57 my comment https://github.com/nreco/logging/issues/57#issuecomment-1753309361