Correct way to use Serilog with WebApi2

Question

I am in search of the correct way to use serilog with aspnet webapi2. As for now I initialize the global Log.Logger property like that :

   public static void Register(HttpConfiguration config)
    {

        Log.Logger = new LoggerConfiguration()
            .WriteTo.Elasticsearch(new ElasticsearchSinkOptions(new Uri("http://localhost:9200"))
            {
                IndexFormat = IndexFormat,
                BufferBaseFilename = outputLogPath,
                AutoRegisterTemplate = true,
                AutoRegisterTemplateVersion = AutoRegisterTemplateVersion.ESv6,
                CustomFormatter = new ElasticsearchJsonFormatter(renderMessageTemplate: false),
                BufferFileCountLimit = NbDaysRetention
            })
            .MinimumLevel.ControlledBy(new LoggingLevelSwitch() { MinimumLevel = LogEventLevel.Information})
            .Enrich.FromLogContext()
            .Enrich.WithWebApiRouteTemplate()
            .Enrich.WithWebApiActionName()
            .CreateLogger();

        //Trace all requests
        SerilogWebClassic.Configure(cfg => cfg.LogAtLevel(LogEventLevel.Information));


        config.MapHttpAttributeRoutes();

        config.Routes.MapHttpRoute(
            name: "DefaultApi",
            routeTemplate: "api/{controller}/{id}",
            defaults: new { id = RouteParameter.Optional }
        );
    }

Is there a more cleaner way to do it? I am wondering, if this might be a problem if I have to put some test in place for my controllers.

Answer 1

I have used the following code organization quite a lot for apps with Web API (and/or MVC). (note that it may be a bit outdated, as it is based on old versions of some packages, but you should be able to adapt it without too much work ...)

You will need quite a few packages, that you should be able to guess from the namespaces, but most importantly, install the WebActivatorEx package which provides a way to have code running at different moment of the app lifecycle

Our Global.asax.cs ended up looking like this :

    public class WebApiApplication : System.Web.HttpApplication
    {
        // rely on the fact that AppPreStart is called before Application_Start
        private static readonly ILogger Logger = Log.ForContext<WebApiApplication>();

        public override void Init()
        {
            base.Init();
        }

        protected void Application_Start()
        {
            // WARNING :  Some code runs even before this method ... see AppPreStart

            Logger.Debug("In Application_Start");
            // Mvc (must be before)
            AreaRegistration.RegisterAllAreas(); 
            // Web API
            // ... snip ...     
            // some DependencyInjection config ...
            // ... snip ...  
            // MVC
            FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters);
            RouteConfig.RegisterRoutes(RouteTable.Routes);
            BundleConfig.RegisterBundles(BundleTable.Bundles);

            Logger.Information("App started !");
        }


        protected void Application_End(object sender, EventArgs e)
        {
            Logger.Debug("In Application_End");
            ApplicationShutdownReason shutdownReason = System.Web.Hosting.HostingEnvironment.ShutdownReason;
            Logger.Information("App is shutting down (reason = {@shutdownReason})", shutdownReason);

            // WARNING : Some code runs AFTER Application_End ... see AppPostShutDown
        }
    }

and then several classes under the App_Start folder (some of which you can just ignore :P ) :

• AppPreStart.cs

using XXX;
using Serilog;


[assembly: WebActivatorEx.PreApplicationStartMethod(typeof(AppPreStart), nameof(AppPreStart.PreApplicationStart))]
namespace XXX
{
    /// <summary>
    /// This runs even before global.asax Application_Start (see WebActivatorConfig)
    /// </summary>
    public class AppPreStart
    {
        public static void PreApplicationStart()
        {
            LogConfig.Configure();
            var logger = Log.ForContext<AppPreStart>();
            logger.Information("App is starting ...");

            // ... snip ...
            // very early things like IoC config, AutoMapper config ...
            // ... snip ...

            logger.Debug("Done with AppPreStart");
        }
    }
}

• AppPostShutDown.cs

using XXX;
using Serilog;

[assembly: WebActivatorEx.ApplicationShutdownMethod(typeof(AppPostShutDown), nameof(AppPostShutDown.PostApplicationShutDown))]
namespace XXX
{
    /// <summary>
    /// This runs even before global.asax Application_Start (see WebActivatorConfig)
    /// </summary>
    public class AppPostShutDown
    {
        private static ILogger Logger = Log.ForContext<AppPostShutDown>();

        public static void PostApplicationShutDown()
        {
            Logger.Debug("PostApplicationShutDown");

            // ... snip ...
            // very late things like IoC dispose ....
            // ... snip ...

            // force flushing the last "not logged" events
            Logger.Debug("Closing the logger! ");
            Log.CloseAndFlush();
        }
    }
}

• LogConfig.cs

using Serilog;
using Serilog.Events;
using SerilogWeb.Classic;
using SerilogWeb.Classic.Enrichers;
using SerilogWeb.Classic.WebApi.Enrichers;

namespace XXX
{
    public class LogConfig
    {
        static public void Configure()
        {
            ApplicationLifecycleModule.LogPostedFormData = LogPostedFormDataOption.OnlyOnError;
            ApplicationLifecycleModule.FormDataLoggingLevel = LogEventLevel.Debug;
            ApplicationLifecycleModule.RequestLoggingLevel = LogEventLevel.Debug;

            var loggerConfiguration = new LoggerConfiguration().ReadFrom.AppSettings()
                    .Enrich.FromLogContext()
                    .Enrich.With<HttpRequestIdEnricher>()
                    .Enrich.With<UserNameEnricher>()
                    .Enrich.With<HttpRequestUrlEnricher>()
                    .Enrich.With<WebApiRouteTemplateEnricher>()
                    .Enrich.With<WebApiControllerNameEnricher>()
                    .Enrich.With<WebApiRouteDataEnricher>()
                    .Enrich.With<WebApiActionNameEnricher>()
                ;

            Log.Logger = loggerConfiguration.CreateLogger();
        }
    }
}

and then read the variable parts of the Log configuration from Web.config that has the following keys in AppSettings :

    <!-- SeriLog-->
    <add key="serilog:level-switch:$controlSwitch" value="Information" />
    <add key="serilog:minimum-level:controlled-by" value="$controlSwitch" />
    <add key="serilog:enrich:with-property:AppName" value="XXXApp" />
    <add key="serilog:enrich:with-property:AppComponent" value="XXXComponent" />
    <add key="serilog:enrich:with-property:Environment" value="Dev" />
    <add key="serilog:enrich:with-property:MachineName" value="%COMPUTERNAME%" />
    <add key="serilog:using:Seq" value="Serilog.Sinks.Seq" />
    <add key="serilog:write-to:Seq.serverUrl" value="http://localhost:5341" />
    <add key="serilog:write-to:Seq.apiKey" value="xxxxxxxxxxx" />
    <add key="serilog:write-to:Seq.controlLevelSwitch" value="$controlSwitch" />

(and then we had Web.config transforms to turn it into a "tokenized" file for production

Web.Release.config

    <!-- SeriLog-->
    <add key="serilog:enrich:with-property:Environment" value="__Release_EnvironmentName__"
         xdt:Transform="Replace" xdt:Locator="Match(key)"/>

    <add key="serilog:write-to:Seq.serverUrl" value="__app_serilogSeqUrl__"
         xdt:Transform="Replace" xdt:Locator="Match(key)"/>
    <add key="serilog:write-to:Seq.apiKey" value="__app_serilogApiKey__"
         xdt:Transform="Replace" xdt:Locator="Match(key)"/>

Some of the most important parts of this configuration is :

• configure your logger as soon as possible
• call Log.CloseAndFlush(); at the very end to be sure all your log events are stored/pushed
• add Enrich.FromLogContext() from Serilog, and some enrichers from SerilogWeb.Classic and SerilogWeb.WebApi, they can turn out to be super useful.
• logging to a log server that properly supports structured logging (writing to files just has too many drawbacks) ... we used Seq and were very very happy about it (installed locally on every dev machine, and then a centralized instance in production). It supports searching/querying and dashboards and also dynamic log level control.