adams85 / filelogger

A lightweight yet feature-rich file logger implementation for the Microsoft.Extensions.Logging framework.
MIT License
147 stars 22 forks source link

Logger does not seem to handle parallelism #17

Closed jeff-simeon closed 2 years ago

jeff-simeon commented 2 years ago

I have the following configuration:

   services.AddLogging(b =>
            {
                b.AddFile(o =>
                {
                    o.RootPath = AppContext.BaseDirectory;
                    o.IncludeScopes = true;

                    o.Files = new[]
                    {
                        new LogFileOptions
                        {
                            Path = logFilePath
                        }
                    };
                });
                b.AddConfiguration(configuration.GetSection("Logging"));
            });

The initial set of log entries are flushed to the file right away, however, once the program goes parallel and has many different ILogger instances writing concurrently, no new log entries appear in the output file and by adding:

FileLoggerContext.Default.DiagnosticEvent += e => { Debug.WriteLine(e); };

I can see many events indicating file locking issues

' created at 9/23/2021 4:10:29 AM +00:00 to log file "logs\testlog.log" failed. System.IO.IOException: The process cannot access the file '....\Debug\logs\testlog.log' because it is being used by another process.
   at System.IO.FileStream.ValidateFileHandle(SafeFileHandle fileHandle)
   at System.IO.FileStream.CreateFileOpenHandle(FileMode mode, FileShare share, FileOptions options)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean useAsync)
   at Karambolo.Extensions.Logging.File.PhysicalFileAppender.CreateAppendStream(IFileInfo fileInfo)
   at Karambolo.Extensions.Logging.File.FileLoggerProcessor.WriteEntryAsync(LogFileInfo logFile, FileLogEntry entry, CancellationToken cancellationToken)

I know that it's not something I'm doing locking the file, because if I add

               o.FileAccessMode = LogFileAccessMode.OpenTemporarily;

I don't get any locking exceptions from FileLoggerContext.Default.DiagnosticEvent and new log entries are correctly flushed to the output log file.

adams85 commented 2 years ago

Is this your complete configuration? The line b.AddConfiguration(configuration.GetSection("Logging")); suggests that you probably have some JSON configuration too. Could you post the relevant part (the "Logging" section) of this configuration? Besides that, what is the library version you use? Which OS does your application run on?

Without these pieces of information I can't really start to look into this. However, the fact that LogFileAccessMode.OpenTemporarily solves the problem suggests that there are multiple log queues competing for the same log file. This can happen in a few ways. I've already had an issue where there was some DI configuration issue and two instances of FileLoggerProvider was created with the same configuration. Isn't it possible that you have something similar going on in your app?

adams85 commented 2 years ago

FYI, this may be useful for you too.

jeff-simeon commented 2 years ago

You called it. Multiple containers.

Thanks!