FileStreamingTarget performance on Win8 with a large file

[JamesNK]

I have noticed the larger the log file that is being written to, the more disk IO an application creates when writing to that file.

I tested creating a 0.5gb log file and my application's disk IO shoots up into the hundreds of megabytes. I don't know what FileIO.AppendTextAsync does internally but it isn't efficient when appending to a large file.

Version: MetroLog.0.9.0 Platform: Win8.1

[clairernovotny]

Hi @JamesNK, thanks for bringing this up. You're right, I have no idea what FileIO.AppendTextAsync does internally either. It's probably loading the whole thing up though :(

Looking at possible workarounds, is it critical that the log stays as a single file or would it be acceptable to split it based on size (automatically based on a configurable value)?

[JamesNK]

The problem with splitting on size is if the limit is 500kb, that is still a lot of disk IO if you write to it often.

Have you tried creating a writer stream, seeking to the end and then writing the new text? Seeking every write would probably the same issue (worth testing) but if you left the stream open then it should be quick.

[clairernovotny]

I'm sure that leaving an open stream is probably the best solution here. Any chance of a PR for this?

[JamesNK]

I tested this but there was still a lot of IO:

protected override async Task WriteTextToFileCore(IStorageFile file, string contents)
{
    using (Stream stream = await file.OpenStreamForWriteAsync())
    {
        stream.Seek(0, SeekOrigin.End);

        using (StreamWriter streamWriter = new StreamWriter(stream))
        {
            await streamWriter.WriteAsync(contents);
        }
    }
}

If it was just a matter of storing a reference to an open stream and closing it on Dispose then I'd do it but you're passing in the StorageFile to the target so you're going to have to do something like have a cache of open streams. I'll leave that to you.

[clairernovotny]

I've just been looking over the file target code and can see that it needs some love. I can't recall why it was designed the way it was, but it seems terribly inefficient to do a create file/append on each write.

I'll have a go at making this better.

[clairernovotny]

This should be better now. Can you please try with 1.0-beta01?

https://www.nuget.org/packages/MetroLog/1.0.0-beta01

It keeps a cache of open stream writers. AutoFlush is enabled on them so it should just work. There's a method on the FileTargetBase you can call to close them manually if you need to.

[JamesNK]

Great. I'll try it next week.

[JamesNK]

Performance writing to a large file is much better.

Is there a reason why the FileSnapshotTarget was removed in beta 1? I was using that to write errors to their own file.

[JamesNK]

Well I wrote my own. Oddly FileSnapshotLayout was still around event though the target isn't. I didn't find a way to close the writer so I hacked it into the write method.

public class FileSnapshotTarget : FileTarget
{
    public FileSnapshotTarget()
        : this(new FileSnapshotLayout())
    {
    }

    public FileSnapshotTarget(Layout layout)
        : base(layout)
    {
        FileNamingParameters.IncludeLevel = true;
        FileNamingParameters.IncludeLogger = true;
        FileNamingParameters.IncludeSession = false;
        FileNamingParameters.IncludeSequence = true;
        FileNamingParameters.IncludeTimestamp = FileTimestampMode.DateTime;
        FileNamingParameters.CreationMode = FileCreationMode.ReplaceIfExisting;
    }

    protected override async Task WriteTextToFileCore(StreamWriter stream, string contents)
    {
        await stream.WriteAsync(contents);
        stream.Dispose();
    }
}

[JamesNK]

btw a StreamWriter isn't a Stream. It's a TextWriter.

[clairernovotny]

Sorry about the missing type - was an oversight when was rearranging stuff to fit into a bait-switch pcl library. I'll make sure that gets in very soon.

Did that help the IO perf?

[clairernovotny]

I just restored this into dev; it's in this pkg: https://ci.appveyor.com/api/buildjobs/26qv4pkotf9nj676/artifacts/MetroLog.1.0.0-dev43.nupkg

I also added an option to the FileTargetBase called KeepLogFilesOpenForWrite that defaults to true. If you set it to false, it'll close the stream after each write instead of caching it and keeping it open.

[JamesNK]

Bug fixed I think.

[clairernovotny]

Fantastic, glad that was able to help. I'll get this out to NuGet shortly. I was just awaiting your confirmation on this.

[clairernovotny]

This build is now up on NuGet.org as rc1. https://www.nuget.org/packages/MetroLog/1.0.0-rc1

Barring any major issues, I think 1.0 is basically done.