CODEWITHSUNDEEP
c#.net-coresplunkserilog
Christian
Christian

Reputation: 131

Log messages discarded when logging to Splunk using Serilog

We have a Windows service that creates a new thread and runs a scheduled task once per day. Logging is done with Serilog and sink is Splunk ("Serilog.Sinks.Splunk"). During a successful run we write eight information messages to the log (Log.Information("") ). The messages are more or less identical from one run to another, apart from a timestamp and integer values. Four of the messages is logged before the actual job tasks are done and four after.

We have discovered that sometimes all eight messages turn up in Splunk, sometimes only the four last messages (those logged after the time consuming processing has been done) and sometimes none of the messages.

When we add another sink, writing to file ("Serilog.Sinks.File") we always get all of the eight messages in the file.

Adding Serilog debug logging (Serilog.Debugging.SelfLog.Enable), when log messages are discarded we get the following debug message logged (once - not one per lost message): "2019-08-30T11:28:03.9029821Z A status code of Forbidden was received when attempting to send to https://<>/services/collector. The event has been discarded and will not be placed back in the queue."

Adding a Sleep (System.Threading.Thread.Sleep() ) first thing in the scheduled task we always get the logging done after the Sleep in Splunk, so it seems it takes some time to set up the connection to the Splunk endpoint and any messages sent before the connection is up is just discarded. Since three of the messages are logged by an external nuget package (Hangfire) before the execution enters into our code we frequently lose these three messages and it isn't ideal to have a Sleep() in our code.

Pseudo code (including the Sleep), as I described log messages 1-3 (and 6-8) are written by an external nuget package:

    public Task DoJob()
    {
        var currentRunInformation = new RunInformation();
        try
        {
            System.Threading.Thread.Sleep(3000);
            Log.Information($"Log message 4");

            //Get Data
            var jobData = GetJobData();
            //Do some calculations
            var calculated = DoCalculations(jobData);

            //Save result
            PersistResult(calculated);

            Log.Information($"Log message 4");
            return Task.CompletedTask;
        }
        catch (Exception exception)
        {
            Log.Error(exception, $"Error log");
            return Task.FromException(exception);
        }
    }

Is there any way we can make the logging wait for an open connection before sending messages? Or any other options to avoid having our logging discarded in an unpredictable manner?

Upvotes: 1

Views: 2812

Answers (1)

C. Augusto Proiete
C. Augusto Proiete

Reputation: 27818

There's nothing out-of-the-box in Serilog.Sinks.Splunk to perform additional checks on Splunk before sending messages, or to retry messages that failed. You can track this issue to get notified if/when this ever gets implemented in the future.

Behind the scenes, the sink is simply sending HTTP POST requests to the Splunk Event Collector...

To have the behaviour that you want, you'd have to implement a variation of Serilog.Sinks.Splunk. You could probably borrow the implementation of durable log shipping from Serilog.Sinks.Seq, and store messages that failed to send in a file, and retry later...

ps: Funny enough, even the code sample that shows how to use the sink, has a Thread.Sleep before sending messages to give Splunk a chance to warm up... 🙈

Upvotes: 4

Related Questions