FantasticFiasco / serilog-sinks-http

A Serilog sink sending log events over HTTP.
Apache License 2.0
172 stars 42 forks source link

Durable HttpLogShipper does not process all the messages on dispose #394

Open alex-netkachov opened 1 week ago

alex-netkachov commented 1 week ago

Describe the bug

The Durable HttpLogShipper does not process all messages upon shutdown.

To Reproduce

  1. Configure the HTTP sync for the console app.
  2. Run the app once a day.
  3. The app logs a few messages and calls await Serilog.Log.CloseAndFlushAsync(); at the end.
  4. The app runs quickly, so the internal timer does not trigger.

The app sends messages every other day but fails to send all of them.

Expected behavior

When await Serilog.Log.CloseAndFlushAsync(); is called, the app should send all logs.

Analysis

The durable sync creates a bookmark file and a buffer file. The bookmark file's content is offset:::buffer file name, e.g., 5776:::C:\Projects\ConsoleApp1\Logs\Buffer-20241005.txt.

CloseAndFlushAsync triggers HttpLogShipper's OnTick method. See here.

This method reads the bookmark file, checks for events in the buffer, updates the bookmark, and exits if no events are found.

The issue occurs when the app runs the next day: the method reads the bookmark file, finds no new events, updates the bookmark, and exits without sending any events.

The following day, the app sends the events for the previous day, causing a delay that increases by one day with each run.

Reproducing this issue is somewhat complex. I’ve set up an Elastic Stack instance, configured the app, retrieved the logs from the problematic server, and run the app several times with a breakpoint in OnTick.

github-actions[bot] commented 1 week ago

Hi there and welcome to this repository!

A maintainer will be with you shortly, but first and foremost I would like to thank you for taking the time to report this issue. Quality is of the highest priority for us, and we would never release anything with known defects. We aim to do our best but unfortunately you are here because you encountered something we didn't expect. Lets see if we can figure out what went wrong and provide a remedy for it.

FantasticFiasco commented 1 week ago

Hi @alex-netkachov.

Is this the same issue as #102?

alex-netkachov commented 1 week ago

I think it is close enough. If CloseAndFlush() processes all the buffered events, it would solve my issue as well, as I call it. But TBH, I would rather prefer it to work even without calling CloseAndFlush(). E.g., auto-flush on dispose.