ElasticSearchSink durability - rolling file problem

[vidarkongsli]

We have set up the ELS sink with durability in our ASP.NET application (running on IIS / Win2012 R2). We have also added a max size on the file, so that it will roll the files if they become too big. Our configuration is as follows:

.WriteTo.Elasticsearch(new ElasticsearchSinkOptions(new Uri("http://localhost:9200"))
                {
                    BufferBaseFilename = @"c:\logs\els_buffer",
                    BufferFileSizeLimitBytes = 10*1024*1024,
                    ConnectionTimeout = 15000,
                    BufferLogShippingInterval = TimeSpan.FromSeconds(20)
                }) 

Looking at the buffer files, we noticed that the .bookmark file appearently does not take the _001.json file into account. Here's the files:

    Directory: C:\logs


Mode                LastWriteTime     Length Name
----                -------------     ------ ----
-a---         9/17/2015   8:17 AM      35937 els_buffer-20150917.json
-a---         9/17/2015  10:51 AM      37784 els_buffer-20150917_001.json
-a---         9/17/2015   9:07 AM         42 els_buffer.bookmark

Looking at the last write times, we see that the _001.json file has been written to, but the .bookmark file has not. Here's the contents of the .bookmarkfile:

35937:::c:\logs\els_buffer-20150917.json

Furthermore, we got the following entry in the self-log:

2015-09-17T09:37:10 Rolling file target c:\logs\els_buffer-20150917.json was locked, attempting to open next in sequence (attempt 1)

This is the only entry in this file.

Any ideas about what's going on?

[guillaume86]

Do you use your ILogger as a singleton?

[vidarkongsli]

Yes, I suppose. Should that be avoided?

[IanYates]

No, it should be a singleton. The file locking error commonly appears when it's not used as a singleton

There was a common, but incorrect, pattern where the same logging configuration instance is used to generate multiple logger instances. Recent releases of Serilog (in the past month or so) throw an exception if this occurs so you fail early.

Given that's probably not your problem I guess some more sleuthing is required. Do you have multiple copies of your ASP.Net app pool running, such as a web garden? Is this a consistent problem or just occasional?

I don't know enough about the bookmark file maintenance but it does seem like there may be two problems here - the locked file (see above commentary & questions) and the bookmark file not being made aware of the "next in sequence" file. The latter sounds like it might be a bug.

[vidarkongsli]

I might be mistaken, but from quickly browsing the source code, I cannot find how the code would update the bookmark file in the situation where the RollingFileSink have increased the file index.

[nblumhardt]

Moved to: serilog-contrib/serilog-sinks-elasticsearch#27 (see #450)