This article introduces briefly the design of the logging infrastructure in general. Although some part of the article is written in the the context of Xamarin with MvvmCross, Serilog is available across .NET Framework and .NET Standard, so most of the following content can apply to the whole .NET ecosystem in general.
Logging Infrastructure
Below are the common components involved when you do logging.
- Logger This is the object your logic code hold to interact with the logging infrastructure. The object is normally an ILogger (for .NET Standard) or MvxLog (for MvvmCross).
It normally has the following functions: Trace/Verbose, Debug, Info, Warning, Error, Fatal. Those functions are actually a shorthand for a common Log function with a corresponding Log Level parameter (more on Log Level in the next subsection).
Application logic never creates a logger by itself. Instead, it gets a logger created by a Log Provider (usually via a dependency injection). - Log Sink A sink indicate the actual destination of the logs (e.g. debug output, console, file, etc.). It is usually configured in the Log Provider instead of embedded inside the logger logic. This separation of Sinks from Logger is extremely powerful, allowing you to change your log destination easily by swapping (or adding) Sinks without ever touching your Logger. You can even setup different filters and limits for each sinks (see example below).
- Log Provider This component connects everything together based on the requested configuration and creates an appropriate logger object. It is usually configured at application start up.
Log Level
Log Level is a way for developer to indicate the criticality of each log entry, allowing appropriate minimum level filtering for each sink. Below are my own convention for using Log Level.
- Trace/Verbose This level is usually used to trace each step of your logic implementation. I rarely log at this level, and usually reserve this for logs from the underlying platform.
- Debug This level can be used as a replacement for any Debug.WriteLine() or Console.WriteLine() in your code. Keep in mind that this level is usually used for logs that should be excluded from production/release build.
- Information This level is similar to Debug level with the exception that those logs should still show up in production/release build. Those are the logs that should help you in troubleshooting production issue.
- Warning I usually use this level to indicate recoverable problem, for example, networking issue with a retry later.
- Error This is usually used to indicate a more critical problem, especially those that need user intervention, e.g. database corruption. You can think of this level as something that should automatically send an email to support team.
- Fatal This should be only used to indicate a crash.
In general, lower log level should give you more in-depth details of the application logic, however, can generate a large amount of log entries. So you should take care of your filters so as to not exhaust your sinks.
Structured Logs
If you are logging formatted string like below, you might not fully utilize the capability of your logging framework:
1 |
logger.Debug(string.Format("Cannot fetch data for user {0}", userId)); |
Instead, try to do this:
1 |
logger.Debug("Cannot fetch data for user {0}", userId); |
Basically you don’t pre-format your log, and instead give the template and all the parameters to the logger directly.
The logger can create the same formatted string on its own, so you don’t lose any feature. In addition, it passes all the parameters to your sinks. If you setup a sink that support structure logs, you can easily filter your logs later on using those parameter value (e.g. userId) instead of have to use Regex on your formatted strings.
Most of the logging framework nowadays support structured logging, so there are really no reason not to use it.
Serilog
Serilog provides us with a Log Provider that works well with both ASP.NET Core for your server and MvvmCross for your Xamarin App. Serilog also has a large number of sinks available as Nuget packages.
Serilog also has some additional facilities that you should learn about and utilize:
- Enricher: add context information into each log entry
- Filter: fine tune which log entry can go to each sink
Below is an example configuring Serilog for MvvmCross:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 |
// Logging is set up in Setup class, which will be run at application startup. public class Setup : MvxAndroidSetup { // Select one of the supported log provider public override MvxLogProviderType GetDefaultLogProviderType() => MvxLogProviderType.Serilog; protected override IMvxLogProvider CreateLogProvider() { // Configure Serilog Log.Logger = new LoggerConfiguration() // Set default log level limit to Debug .MinimumLevel.Debug() // Enrich each log entry with memory usage and thread ID .Enrich.WithMemoryUsage() .Enrich.WithThreadId() // Write entries to Android log (Nuget package Serilog.Sinks.Xamarin) .WriteTo.AndroidLog() // Write entries to Splunk server .WriteTo.EventCollector("http://127.0.0.1:8088/services/collector", token) // Create a custom logger in order to set another limit, // particularly, any logs from Information level will also be written into a rolling file .WriteTo.Logger(config => config .MinimumLevel.Information() .WriteTo.RollingFile("Errors.log", retainedFileCountLimit: 7) ) // And create another logger so that logs at Fatal level will immediately send email .WriteTo.Logger(config => config .MinimumLevel.Fatal() .WriteTo.Email(new EmailConnectionInfo { MailServer = "smtp.test.com", EmailSubject = "Fatal error", }) ) // Errors relating to purchase (using a custom filter by log message template) will also immediately send email .WriteTo.Logger(config => config .MinimumLevel.Error() .Filter.ByIncludingOnly(e => e.MessageTemplate.Text == "Purchase failed") .WriteTo.Email(new EmailConnectionInfo { MailServer = "smtp.test.com", EmailSubject = "Purchasing error", }) ) .CreateLogger(); return base.CreateLogProvider(); } } |
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
public class MyViewModel : MvxViewModel { private readonly MvxLog logger; // logger is created by MVVM Cross IoC provider and inject into this class via the constructor. // logger is then stored in a read-only field to allow accessing through the class public MyViewModel(MvxLog logger) { this.logger = logger; } public void ClickPurchaseButton() { // Using the logger is straight forward logger.Info("Purchasing flow is trigger."); } } |
More examples can be found in the reference links at the end.
Some Recommendations
- Log Level and log Filter allow you to control how much log is actually stored without touching your logging calls. Hence, you should not hesitate to log frequently in the app. Just remember to set appropriate log level and use structured log instead of formatted string.
- If you are building an Xamarin/mobile app without Internet access to logging services such as Azure Event Hubs or Application Insights, you can write your logs into file (should be rolling to prevent filling up storage) and provide a button in app to automatically zip up the logs, open a new email composer and attach the zip file. You might also automatically filling in appropriate information for the user such as support email, subject, app versions. This should also happen after the app is restarted from a crash.
- If you are writing mobile app, do NOT write logs into your application database, even for error logs. On a bad day, a bad bug in the clients (or even a surge of users) may generate huge amount of logs and affect your server. If you have ample disk space, you can consider using Rolling File sink.
An even better choice is to use external services on a separate server/container for your log sink, especially if you want to analyze your low level logs. One very good service that can be installed on-premise is https://www.splunk.com. - Filter level switching is another useful feature of Serilog https://nblumhardt.com/2017/10/logging-filter-switch/. This allows turning on more detailed logging as and when needed without the need of restarting the application.
Links
- https://github.com/serilog/serilog/wiki/Getting-Started
- https://merbla.com/2018/04/02/exploring-serilog-v2—lets-go/
- https://www.ctrlaltdan.com/2018/08/14/custom-serilog-enrichers
- https://nblumhardt.com/2016/07/serilog-2-0-json-improvements/
- https://github.com/serilog/serilog-filters-expressions
- https://nblumhardt.com/2017/10/dispatching-on-serilog-property-values
- https://nblumhardt.com/2019/06/selective-enrichment
For anyone coming here trying to configure Seq on the Android Emulator, use the address of your dev machine ASSIGNED BY THE EMULATOR.
localhost
will just loop to the emulator itself!Windows Phone assignes to the dev machine
http://169.254.80.80:5341
while Android works withhttp://10.0.2.2:5341
. 5341 is the default port for Seq