Flush-to-disk option

[temp-impl]

In Windows 10 and Windows Server 2012 R2, StreamWriter.Flush won't write the data to disk immediately.

You can know this by running under code and watching the file size through "dir" command.

Log.Logger = new LoggerConfiguration()
    .WriteTo.File("log.txt")
    .CreateLogger();

for (var i = 0; i < 100; ++i)
{
    Console.WriteLine(i);
    Log.Information("Hello, file logger!");
    System.Threading.Thread.Sleep(1000);
}

We can write to disk immediately by touching the file like this.

var touched = new FileInfo("log.txt").LastWriteTime;

Could you please improve "buffered:false" or add new option to do this?

P.S.
I'm using Serilog.Sinks.RollingFile for windows service logging, and collecting the logs by Microsoft Operations Management Suite (OMS). I found OMS log collection is not working good, because above.

[nblumhardt]

Thank for the note. Full sync-to-disk is very, very slow (order of milliseconds). I've been hesitant to add the option because in most apps it'll be unacceptable. The current behavior is to flush through to the OS page cache, which, while it won't protect from data loss in a power outage (very little can), deals with process crashes and the like.

In your scenario, would the perf hit be acceptable? Is the concern data loss, or is OMS the primary driver for needing this?

Cheers!

[temp-impl]

Hi!

This is my problem detail.

• OMS doesn't collect logs that file size is not increased.
• Serilog.Sinks.RollingFile doesn't write log to disk until it's rolling, because OS page cache is large.
  The log file size of a day is about 300KB from 600KB.
• I want to collect logs for monitoring the windows service. OMS can make alert if there are no logs during some time.

I found another way to write to disk almost immediately.
In this way, the buffer size is reduced to 1KB. Tested in Windows 10 and Windows Server 2012 R2.

var file = File.Open("log.txt", FileMode.Append, FileAccess.Write, FileShare.Read);
var writer = new StreamWriter(file, <encoding>);
writer.Write("Some string");
writer.Flush();
file.Flush(true); // this

It's very helpful if my problem will be solved by the library, but I know it is difficult problem for the library...

Thanks

[pakrym]

@nblumhardt we have the same issue while using Serilog for Azure AppServices logging, Log Stream feature picks up changes only when logs file size is increased.

Azure AppServices file logging is intended as temporary thing that you turn on to debug you application live, so we are somewhat fine with taking a performance hit although it would be better to flush events in batches with a short timeout rather then each time.

Other solution is to have timer and open/close file for reading in parallel which will also force OS to flush the data/update attributes.

[nblumhardt]

@pakrym thanks for the info, sounds like this is something we'll need to accommodate.

A simple wrapper that closed/reopened the file by disposing/re-creating the sink on a timer could be implemented atop what's there now, but doesn't seem like a long-term option.

Going one step further might look like:

1. Add FlushToDisk() on both FileSink and RollingFileSink
2. Create a wrapper sink PeriodicFlushToDisk that calls the wrapped sink's FlushToDisk() method on a timer at some specified interval
3. Add TimeSpan? flushToDiskInterval as an optional argument to WriteTo.File() and WriteTo.RollingFile(), and wrap the configured sink if it is specified

Sound like a plan?

[pakrym]

Sounds like exactly what we need!

[pakrym]

@nblumhardt what's your plan on timeline of this? I can do a PR if you have something on you list already. We are pretty anxious to get this in because it blocks one of the main features of integration.

[nblumhardt]

@pakrym I'll take a quick look now; if I can get something together quickly it might be easier if I coordinate it, but if not, a PR would be welcome. Will let you know later today. Thanks!

[muratg]

👀

[nblumhardt]

@muratg @pakrym build 3.1.0-dev-00747, now on NuGet, should expose the flushToDiskInterval option. Can you please check that it gets your scenario unblocked and let us know?

Moving on to the downstream rolling file support...

[nblumhardt]

Going to reopen this until we're comfortable it's all covered.

[nblumhardt]

Hrm, thought I was pushing to my fork, but nope, pushed to dev serilog/serilog-sinks-rollingfile@a8d1ece - oops.

CI was clean, rolling file support now published as https://www.nuget.org/packages/Serilog.Sinks.RollingFile/3.1.0-dev-00745.

[pakrym]

@nblumhardt everything seems to work well with this change. Thank you.

[nblumhardt]

We'll let this bake a short while before releasing as stable - let me know if there's any urgency around getting a non-prerelease version up. Cheers!

[muratg]

@nblumhardt Thanks! How long are you planning to keep this baking? We'll be depending on this in our 1.1 release :)

[nblumhardt]

@muratg I'll put some time aside on Monday to upgrade some apps and test more rigorously. Considering it's an "opt-in" feature there's no great danger in putting it out there, ideally we'll just be confident that it works :-) .. If I can't break it, I'm happy to push the button 👍

[muratg]

@nblumhardt Awesome, thanks!