I have a Microsoft Asp.Net Web Api project, in which I am attempting to setup serilog logging. I have installed the Nuget packages for Serilog, Serilog.Sinks.File, SerilogWeb.Classic, and SerilogWeb.Classic.WebApi. Note, that I am NOT able to use .Net Core.
My problem is that I am attempting to use the enrichers from the SerilogWeb.CLassic.WebApi package, but they aren't changing my output. I am sure that what I am doing is a simple mistake, but I cannot find any examples of others using this same enricher online (everything I find is on .Net Core).
Log.Logger = new LoggerConfiguration()
.Enrich.WithWebApiActionName()
.WriteTo.File("D:/mytestresults.txt")
.CreateLogger();
The code snippet above is from my Startup.cs file. When I run the http requests are logged to the file, but adding and removing the Enrich line makes no difference. Below is a sample file output
2019-03-26 10:09:11.215 -04:00 [INF] HTTP GET /api/actions/ responded 200 in 17ms
2019-03-26 10:09:13.621 -04:00 [INF] HTTP GET /api/actions/ responded 200 in 9ms
Note, that I do want to use other enrichers, but I have simplified this down some for figuring out what I am doing wrong.
For clarity about the packages that I am using, the following is some of my packages.config
<package id="Microsoft.AspNet.WebApi" version="5.2.3" targetFramework="net461" />
<package id="Microsoft.AspNet.WebApi.Client" version="5.2.3" targetFramework="net461" />
<package id="Microsoft.AspNet.WebApi.Core" version="5.2.3" targetFramework="net461" />
<package id="Microsoft.AspNet.WebApi.Owin" version="5.2.3" targetFramework="net461" />
<package id="Microsoft.AspNet.WebApi.WebHost" version="5.2.3" targetFramework="net461" />
<package id="Serilog" version="2.8.0" targetFramework="net461" />
<package id="Serilog.Sinks.File" version="4.0.0" targetFramework="net461" />
<package id="Serilog.Sinks.MSSqlServer" version="5.1.2" targetFramework="net461" />
<package id="Serilog.Sinks.PeriodicBatching" version="2.1.1" targetFramework="net461" />
<package id="SerilogWeb.Classic" version="5.0.48" targetFramework="net461" />
<package id="SerilogWeb.Classic.WebApi" version="4.0.5" targetFramework="net461" />
EDIT
The following is my code after changes suggested, and while some enrichers are working, I am not getting the action and controller names:
Log.Logger = new LoggerConfiguration()
.Enrich.FromLogContext()
.Enrich.WithUserName()
.Enrich.WithWebApiRouteData()
.Enrich.WithWebApiControllerName()
.Enrich.WithWebApiRouteTemplate()
.Enrich.WithWebApiActionName()
.Enrich.WithHttpRequestUrl()
.WriteTo.MSSqlServer(connectionString, tableName, restrictedToMinimumLevel: Serilog.Events.LogEventLevel.Information, autoCreateSqlTable: true)
.WriteTo.File("D:/mynewlog.txt", outputTemplate: "<{WebApiAction}> Time: {Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} Level:[{Level:u3}] Message:{Message:lj}Properties:{Properties}{NewLine}{Exception}")
.CreateLogger();
The following is what is being logged to the file at this point (sql is the same)
<> Time: 2019-03-27 10:34:47.842 -04:00 Level:[INF] Message:HTTP GET /api/actions/reviews responded 200 in 7msProperties:{ SourceContext: "SerilogWeb.Classic.ApplicationLifecycleModule", UserName: "theUsernameWasHere", HttpRequestUrl: "http://localhost:61111/api/actions/reviews" }
I think that what is happening right now is that your "log events" are properly enriched with all the information, but the File sink is not configured properly to display that information.
The default output template of the File sink is {Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} \[{Level:u3}\] {Message:lj}{NewLine}{Exception} , which means that it will properly display the "rendered message" (the message template + the value of the properties that are referenced in the message template).
What you need to do is to configure it in a way that all the extra properties (the ones that are added to each log event when it is enriched) are also displayed.
For the File sink, you can for instance add the special {Properties} directive in you output template, and that will show all the properties that are attached to the event, but are not rendered as part of the message template.
That would look like :
Log.Logger = new LoggerConfiguration()
.Enrich.WithWebApiActionName()
.WriteTo.File("D:/mytestresults.txt", outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} \[{Level:u3}\] {Message:lj}{Properties}{NewLine}{Exception}")
.CreateLogger();
(or {Properties:j} to have them formatted as JSON).
This will output all the properties attached to the event but not located anywhere else in the output template.
If you are only interested in the WebApiAction, you could also do something like :
Log.Logger = new LoggerConfiguration()
.Enrich.WithWebApiActionName()
.WriteTo.File("D:/mytestresults.txt", outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} \[{Level:u3}\]<{WebApiAction}> {Message:lj}{NewLine}{Exception}")
.CreateLogger();
... and then you would end up with lines like this in the output :
2019-03-26 10:09:13.621 -04:00 [INF]<MyActionName> HTTP GET /api/actions/ responded 200 in 9ms
UPDATE
It looks like this is not an "output formatting" issue, as you can properly display some attached properties ...
.WithUserName and .WithRequestUrl are not WebApi specific and can be easily collected for any ASP.NET application. The .WithWebApi* extensions rely on an IAuthenticationFilter that we declare in Web API on start up thanks to this line ...
Here are possible scenarios that could explain the lack of enrichment :
- for some reason the PreApplicationStartMethod assembly attribute does not work as expected
- for some reason registering the StoreWebApInfoInHttpContextAuthenticationFilter in Web API does not work
- for some reason we cannot extract the information from the ActionContext
Are you possibly doing "strange" things with the registered AuthenticationFilters on start up ?
It's probably better to try and track it down as part of the issue your reported here : https://github.com/serilog-web/classic-webapi/issues/18 ;)