Search code examples
ninjectserilog

Serilog only logging the first time it is called after build


I have an ASP NET MVC project which uses Ninject for IoC. Have added a Serilog logger

  public class LoggingModule : BaseModule
  {
    public override void Load()
    {
      var fileName = "c:\path\file.log";
      var loggerConfiguration = new LoggerConfiguration()
        .WriteTo.RollingFile(fileName, LogEventLevel.Debug)
        .MinimumLevel.Verbose();
      var logger = loggerConfiguration.CreateLogger();

      Log.Logger = logger;
      Bind<ILogger>().ToConstant(logger);
    }
  }

And am injecting this into a Controller.

When I exercise the code that uses it to log it will log once and then never again until I restart the web app.

I'm using the same configuration code (without ninject) in a windows service which works fine.

Versions installed are

<package id="Serilog" version="2.3.0" targetFramework="net45" />
<package id="Serilog.Sinks.File" version="3.1.0" targetFramework="net45" />
<package id="Serilog.Sinks.RollingFile" version="3.2.0" targetFramework="net45" />
<package id="Ninject" version="3.2.2.0" targetFramework="net45" />
<package id="Ninject.MVC3" version="3.2.1.0" targetFramework="net45" />
<package id="Ninject.Web.Common" version="3.2.3.0" targetFramework="net45" />
<package id="Ninject.Web.Common.WebHost" version="3.2.3.0" targetFramework="net45" />
<package id="Microsoft.AspNet.Mvc" version="5.2.3" targetFramework="net45" />

Update:

Following on from Caio's answer. I added in the SelfLog and see...

2016-11-22T14:29:25.6317957Z Caught exception while emitting to sink Serilog.Core.Sinks.RestrictedSink: System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'The rolling log file has been disposed.'.
   at Serilog.Sinks.RollingFile.RollingFileSink.Emit(LogEvent logEvent)
   at Serilog.Core.Sinks.SafeAggregateSink.Emit(LogEvent logEvent)

Update 2:

This turned out to be a bug in the way that IDependencyResolver had been implemented in our project. IDependencyResolver implements IDisposable and our implementation called dispose on the kernel. (Un?)luckily this had just never caused an issue before.

I've marked Caio's answer as the answer because him pointing me to the SelfLog gave me the tool to unwind what was happening. Thanks to all the helped though!


Solution

  • Have you tried checking the output from Serilog's self log, to see if there's any error occurring internally?

    e.g.

    Serilog.Debugging.SelfLog.Enable(msg => Console.WriteLine(msg));
    

    https://github.com/serilog/serilog/wiki/Debugging-and-Diagnostics