Update August 2016: Serilog.Sinks.RollingFile version 3.0.1 now includes a shared: true configuration option that takes advantage of atomic append writes to support shared log files without any of the issues below! You’ll need to update Serilog and the rolling file package to use it.

Serilog 1.3.5 includes some important improvements to the rolling file sink.

No doubt the least pleasant aspect of dealing with log files is concurrency. When multiple processes write to the same log file, either:

  1. They need to coordinate writes using system-wide mutual exclusion (unreliable)
  2. They need to wait for the file to become “free” and close it immediately after writing (slow)
  3. One of them must fail (inconvenient)

Serilog takes a bit of a stand on this and chooses option 3), requiring that each process uses its own log file, or set of rolling files.

This has the advantages of predictability and performance, and I’m happy with the choice.

But, there’s a catch, and it is a nasty one.

IIS and overlapped application pool recycling

When an IIS app pool is “recycled” (shut down and re-started to clean up any leaky resources) the IIS pipeline’s pretty smart about it. Rather than leave a site offline between unloading the old worker process and loading the new one, IIS starts the new process first and only unloads the old one once the new one is serving requests.

Unfortunately, this means the new app pool needs to open a log file still locked by the outgoing process. No logs for you!

Disabling overlapped recycling

For typical intranet sites, or web-facing sites behind a load balancer, disabling overlapped recycling isn’t a huge issue. To date this has been the solution for using Serilog with IIS. But, it isn’t an option for some, and happily those “some” were loud and determined enough to get a better solution into Serilog 1.3.5.

The old rolling scheme

Serilog still doesn’t handle locked single-file logs. Generally these kinds of logs aren’t used in e.g. IIS sites, so the old caveats of a file-per-process still apply if you use WriteTo.File().

Rolling files however already provide a model that maps quite naturally to the “rolling over” of IIS worker processes.

A sequence of files written by the rolling file sink might look like:

myapp-20140501.txt
myapp-20140502.txt
myapp-20140503.txt

As the days pass a new file is created, and eventually the old one is removed.

The fix: rolling when a file is locked

Now, assuming that it’s the third of May, if the IIS app pool is recycled you’ll see a sequence like:

myapp-20140501.txt
myapp-20140502.txt
myapp-20140503.txt
myapp-20140503_001.txt

The _001 file will be used by the new worker process, while the old one hangs on to the non-prefixed file.

Some guarantees

What happens when the new process, using the suffixed file, is recycled?

Well, the simplistic response would be for the replacement to open the non-suffixed file, since that is now in all likelihood unlocked. But this would make reading the files a pretty awful experience, as date/time ranges jumped around between them.

Instead, the new process will create:

myapp-20140503_002.txt

Important notes

The only caveat to note here is that the implementation is robust to the scenarios that commonly occur when restarting/recycling processes. It doesn’t address long-lived concurrent processes, for that you’ll need to decide on an alternative scheme (or use a more concurrency-friendly sink than what the file sinks can provide).

You should also be aware that the retained file count provided by the rolling file sink is per-file, not per-day, so if you expect frequent overlapped log file recycling, you should allow a few more retained files to ensure you keep the required date range. We’ll probably implement a retained-days count in the future.

Is this the long-term plan?

This is the long-term solution to locked files in Serilog, at least as far as any current plans cover. How does it work for you? Serilog’s a community project and always open to constructive feedback and good ideas.