Why do I get Serilog SelfLog error while using Serilog logging?

Question

I have an interesting error while using Serilog SelfLog. The error is:

Application: XXX.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.IO.IOException
   at System.IO.__Error.WinIOError(Int32, System.String)
   at System.IO.FileStream.Init(System.String, System.IO.FileMode, System.IO.FileAccess, Int32, Boolean, System.IO.FileShare, Int32, System.IO.FileOptions, SECURITY_ATTRIBUTES, System.String, Boolean, Boolean, Boolean)
   at System.IO.FileStream..ctor(System.String, System.IO.FileMode, System.IO.FileAccess, System.IO.FileShare, Int32, System.IO.FileOptions, System.String, Boolean, Boolean, Boolean)
   at System.IO.StreamWriter.CreateFile(System.String, Boolean, Boolean)
   at System.IO.StreamWriter..ctor(System.String, Boolean, System.Text.Encoding, Int32, Boolean)
   at System.IO.StreamWriter..ctor(System.String, Boolean, System.Text.Encoding)
   at System.IO.File.InternalAppendAllText(System.String, System.String, System.Text.Encoding)
   at Serilog.Debugging.SelfLog.WriteLine(System.String, System.Object, System.Object, System.Object)
   at Serilog.Sinks.PeriodicBatching.PeriodicBatchingSink+<OnTick>d__16.MoveNext()
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)
   at Serilog.Sinks.PeriodicBatching.PortableTimer+<OnTick>d__8.MoveNext()
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()

I do not have an idea what happens. I have .Net framework 4.6.1, Serilog version 2.9.0 and I cannot produce the error again.

Please Can you help me to describe the error? Why did I get the error? Do you know any solutions for this error?

I use libraries below:

• Serilog v2.9.0
• Serilog.Enrichers.Context v2.4.0
• Serilog.Extensions.Logging v2.0.4
• Serilog.Settings.AppSettings v2.2.2
• Serilog.Sinks.Console v3.1.1
• Serilog.Sinks.File v4.1.0
• Serilog.Sinks.Http v5.2.1
• Serilog.Sinks.PeriodicBatching v2.2.0
• Serilog.Sinks.RollingFile v3.3.0
• Microsoft.Extensions.Logging.Abstractions v1.0.0

EDIT: My app conf here:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <appSettings>
    <add key="serilog:minimum-level" value="Verbose" />
    <add key="serilog:using:Console" value="Serilog.Sinks.Console" />
    <add key="serilog:write-to:Console" />
    <add key="serilog:using:Http" value="Serilog.Sinks.Http" />
    <add key="serilog:write-to:Http.requestUri" value="http://log.XXX.com:8080/TestEngine" />
    <add key="serilog:write-to:Http.batchPostingLimit" value="1" />
    <add key="serilog:write-to:Http.batchFormatter" value="Serilog.Sinks.Http.BatchFormatters.ArrayBatchFormatter, Serilog.Sinks.Http" />
    <add key="serilog:enrich:with-property:application" value="TestEngine" />
  </appSettings>
    <startup> 
    ...

Serilog integration here:

var config = new LoggerConfiguration()
    .Enrich.FromLogContext()
    .Enrich.WithMachineName()
    .Enrich.WithUserName()
    .ReadFrom.AppSettings();

if (CustomLogContext == null)
{
   CustomLogContext = new Dictionary<string, object>();
}

foreach (var logContext in CustomLogContext)
{
   config.Enrich.WithProperty(logContext.Key, logContext.Value);
}

if (!string.IsNullOrEmpty(CustomLogFileFullName))
{
   config = config.WriteTo.File($"{CustomLogFileFullName}");
}

Serilog.Log.Logger = config.CreateLogger();

Serilog.Debugging.SelfLog.Enable(msg => File.AppendAllText("internallog.log", msg, Encoding.UTF8));

ILoggerProvider loggerProvider = new SerilogLoggerProvider(Serilog.Log.Logger);

_logger = loggerProvider.CreateLogger("XXX.Logging.Serilog");

SOLUTION: As @RubenBartelink says, if you use Selflog but you use custom log files, you take a few risks. Because Serilog may not write a custom file and may be Serilog throw an IO exception. This problem does not belong to Serilog. The problem is actually File.AppendAlltext operation. The solution is as follows:

Serilog.Debugging.SelfLog.Enable(msg => 
{
    try
    {
        File.AppendAllText("internallog.log", msg, Encoding.UTF8);
    }
    catch (Exception ex)
    {
        Console.WriteLine(ex.ToString());
    }
});

Answer 1

As alluded to in the comment from @Daniel A. White, you are doing a risky thing -- trying to write to a file, in a handler that's provided on an "if all else fails" basis. Some examples:

• if the disk is full and the File Logger can't write (File sinks dont necessarily do that, but if they wanted to communicate failure, it would be via the SelfLog)
• if a message string is malformed (Serilog logging calls will never throw; this is based on a fundamental tenet in the wiki about the logging not being important enough to stop a working app from working)

While the Serilog debugging and diagnostics Wiki page currently shows an example of writing to a file, that's simply not the nature of the contract -- it must not fail.

Hence, if you actually want to emit the SelfLog to a file, you will need to add a try/catch and swallow the exception in the handler.

I would say its pretty questionable value to have a file as a backup when the File Sink is your primary output. This is doubly the case as you don't have any mechanism to ensure it gets trimmed (imagine you had a tight loop logging with a malformed message string - it would fill your disk eventually).

I personally have handled this tradeoff by echoing the SelfLog to my Console Sink (which logging won't throw, per the above) on the basis that the operating environment (think Kubernetes) can be trusted to capture it, or alert.