C# 6 string interpolation and Serilog

It’s easy to spot the similarity between Serilog message templates:

// Serilog
var loggedInUserId = "nblumhardt";
Log.Information("Logged in {UserId}", loggedInUserId);

and C# 6 interpolated strings:

// C# 6
Log.Information($"Logged in {loggedInUserId}");

This is naturally because of their shared common ancestor, the .NET format string. Under the hood, interpolated strings in C# are converted by the compiler into a struct with the classic format string and argument values, logically along the lines of:

// C# 6 desugared
Log.Information(new FormattableString
  {
    Format = "Logged in {0}",
    Args = new object[] { loggedInUserId }
  });

The similarity has led a few of us, since seeing the new C# feature, to wonder whether a few keystrokes might be shaved off of the Serilog API if only the C# compiler would preserve the names of the “holes” in the interpolated string, i.e. loggedInUserId in this example.

There was initially mention of Serilog on the design thread for the feature, and more recently Andrey Shchekin most graciously raised a ticket on the Roslyn issue tracker as a prompt for some support in C# 7.

I’ve had some time to think about this feature now, and while the concision is appealing, I’m no longer convinced string interpolation (name preservation or not) is a good fit for Serilog.

1. A good variable name is not necessarily a good property name

Let’s take the example above; in our hypothetical C# 6 example the complete snippet would look like:

var loggedInUserId = "nblumhardt";
Log.Information($"Logged in {loggedInUserId}");

The variable name loggedInUserId obviously reflects what this value is being used for by the program. But, if that name was carried through to the log event, e.g.:

{ { "Properties": { "loggedInUserId": "nblumhardt",

This would lead us to query the log with filters like:

loggedInUserId == "nblumhardt"

Fine if we only want to find events where the user was logged in, but in the context of a larger and more complex application, we’ll often want to find as many events as possible that are related to a specific user (who might be having some technical trouble!).

In that case, a more general property name is a better fit:

Log.Information("Logged in {UserId}", loggedInUserId);

// Elsewhere
Log.Information("Password for {UserId} successfully changed", loggedInUserId);

This small change allows us to query UserId == "nblumhardt" and find both matching events.

Log event property names are important enough for diagnostics that they deserve their own identity, separate from the variable names around them.

2. Holes don’t always have obvious names

What does the property name for this statement look like?

Log.Information($"Enabling categories {new[]{1, 2, 3}}");

Here the hole is filled with an expression that’s not a simple name, so some kind of munging would be necessary in order to turn it into a valid log event property name (a JSON identifier or similar).

Going down this path would definitely reduce the overall quality of log events, and elevating log events to first-class status is what Serilog’s all about.

So what’s the relationship between Serilog and C# 6, then?

String interpolation is a great feature, one I’ve looked forward to in C# for a long time. The idea of providing direct support for Serilog is a very interesting one and worth exploring, but I’m increasingly convinced it’s unnecessary.

Interpolation is nice when it keeps code DRY, cutting out the redundant clutter of {0} and {1} and preventing parameter mismatches.

In the case of Serilog, I think it’s incorrect to consider the property names like {UserId} as redundant; in a well-implemented logging strategy they’re an incredibly important part of the picture that deserve their own consideration. You wouldn’t let variable names determine the table and column names in a relational database – it’s exactly the same trade-off being considered here.

What do you think? I’d love to be convinced there’s more synergy to be found here, but I’m not seeing it at present.

Tagging log events for effective correlation

Correlation, at least when we’re talking diagnostic logs, is the process of finding events that are related to each other in some way. It’s typical to correlate events raised during a transaction, on a specific thread, on a machine or from steps in some kind of process.

Correlation is king in the world of operating complex, distributed and asynchronous apps: it’s how the signal is picked out of the noise – the wheat from the irrelevant chaff – the diamonds that will help you solve a critical issue from the mud of day-to-day happenings.

I gave a presentation a few weeks back at DDD Brisbane on building better apps by taking an active approach to logging. The last post should give you an idea of the flavor of it. After the talk some nice folks approached me and said I’d filled in a missing link for them – it made me realize I’ve been using a little strategy for correlation without really thinking about it, and you might find this useful too.

Contextual correlation

For a long time, diagnostic logs have incorporated contextual information into events. Context tells you what was happening when an event was raised, or where the event was raised from. In its earliest form it might be the thread ID you sometimes see formatted into text logs:

2015-01-22 10:55:05.776 INFO [22] Serving catalog index
2015-01-22 10:55:05.902 WARN [8] Query took 109 ms
2015-01-22 10:55:05.902 INFO [22] Responding with OK

The thread ID in this case is included in each log message between brackets after the level. It tells us that the warning on the second line was raised on thread 8, which isn’t the same thread as was concurrently serving the product catalog (thread 22), so the source of the warning was elsewhere.

Searching a simple text log like this we could grep for /[8]/ to see what else was happening on thread 8 and hopefully narrow down on the source of the slow query.

Serilog does contextual correlation in a few different ways.

Enrichers can be used to attach different contextual properties to events:

var log = new LoggerConfiguration()
  .Enrich.With<ThreadIdEnricher>()
   // Other config here, then…
  .CreateLogger();

Enrichers work well when the context of an event can be determined statically – i.e. it’s something ambient like the thread id, machine name, the logged-in user, and so-on.

For context that’s more localized, there’s a special enricher that can be added to enable the Log Context:

  .Enrich.FromLogContext()

Once the log context is enabled, a block of related messages can be tagged using the methods on the LogContext class:

using (LogContext.PushProperty("MessageId", GetCurrentMessageId()))
{
  Log.Information("Processing {OrderId}", message.Order.Id);

  // Later
  Log.Information("Order processing complete");
}

If we look at these logs in Seq, we’ll see an MessageId property attached to each event within the using block:

1-MessageId

This can be used as a filter, e.g. MessageId == 12345, to view the events raised when processing the message.

Contextual correlation is bread-and-butter stuff. If your application processes work asynchronously, you need to be able to filter down to a single task, and properties tagging events from a context make this as painless as possible.

It’s worth noting that contexts overlap – an event can belong to a thread as well as to a message. (This is one of the arguments for structured logs – it’s much easier to work with events with real, named properties than it is to devise readable, unambiguous ways to embed all of these into the format of a text log message.)

Setting up and using the log context does add some noise to application code, so it’s something to be used judiciously. To tag events for correlation without additional machinery, another technique is useful.

Lateral correlation

If you think about all the contexts in your running application, you might come up with a mental picture like this:

Contextual

The green lines show sequences of events tagged with the same RequestId property, while blue shows a MessageId property that might be added to events during back-end processing. There’s some simplification here, given the way contexts overlap, but essentially each context is a temporal sequence of correlated events.

When it comes time to use these logs however, scenarios frequently cross these little islands of navigability, so something else is needed.

Let’s say we’ve received an issue report tagged with an exception message. We find the exception using the text:

2-InvOrder

And then follow the MessageId contextual property to see what happened in the message handler that failed.

3-Mid

Now, we know somehow we were sent an order without any items – where did it come from? This is where a lateral correlation identifier comes in handy. The second event in the three above implements this:

Log.Information("Processing {OrderId}", message.Order.Id);

OrderId is a business-domain identifier included in the message itself that links the event across lines of causality to others related to the same order.

Once we jump across contexts using the OrderId:

4-Find

We can now see an event from the HTTP request that initiated the order.

5-Req

(A keen-eyed reader might note here that searching on ItemCount == 0 would have narrowed things down a little faster – but identifying this opportunity still requires some navigation through the logs from the point of failure too.)

Correlating by HTTP request Id we get all of the events from the request and should (on a real event stream) be able to get to the bottom of the issue:

6-Final

Patching this into our mental model, OrderId let us navigate laterally between the two sequences of events.

Lateral

Logging in two dimensions

Armed with a tool like structured logging that can easily be overused and create clutter, the last thing anyone wants to do is bung every possible property onto every event in an attempt ease diagnostics later on.

Keeping a clear distinction between the contextual and lateral correlation links makes it possible to navigate effectively through events raised by the app with a minimum of syntactic noise.

It turns out that in most situations I’ve encountered, architectural and infrastructural concerns dominate the notion of context. HTTP request id, thread id, message id – these are all mechanical concerns that get buried into plumbing and attached using enrichers or the log context. This is pretty convenient – the noisier APIs for adding contextual properties are best kept in infrastructural code when possible.

Identifiers from the business domain provide lateral navigation through logs – customer ids, order ids and the like – letting you skip between the various contexts in which an entity was referenced. Using structured logging these links can be created without much fanfare – just logging an event with the identifier in its message text is enough to make the connection.

It’s a simple perspective that helps me use structured logs more effectively, and it can be a nice foundation for guidelines shared with a team. If you use this strategy already, or another similar one, I’d love to hear more about your experiences!

Using Serilog with F# Discriminated Unions

Serilog

This week GitHub user vlaci called us out on awful F# support in Serilog. In their issue report they show how a nice clean discriminated union type like “Option” is represented hideously in structured data:

type Shape =
    | Circle of Radius : double
    | Rectangle of Width : double *  Height : double
    | Arc // ...
let shape = Circle 5.
Log.Information("Drawing a {@Shape}", shape)

Prints:

2015-01-14 16:52:06 [Information] Drawing a Circle { Radius: 5, Tag: 0, IsCircle:
   True, IsRectangle: False, IsArc: False }

The verbosity gets worse for types with more values.

I took this as a chance to crank up Visual Studio and get reacquainted with F#, using the example from @vlaci as a starting point. Using Serilog.Extras.FSharp you can now enjoy your discriminated unions encoded pleasantly like:

2015-01-14 16:58:31 [Information] Drawing a Circle { Radius: 5 }

Depending on the log storage you use you’ll be able to query on the tag as well as the fields (like Radius) from the union.

You can enable this by installing the package and adding Destructure.FSharpTypes() to your logger configuration:

open Serilog

[<EntryPoint>]
let main argv =

    Log.Logger <- LoggerConfiguration()
        .Destructure.FSharpTypes()
        .WriteTo.ColoredConsole()
        .CreateLogger()

    Log.Information("Drawing a {@Shape}", Circle 5.)

    0

Thanks again to vlaci for kicking this off. I was especially keen to see this in because I’m sure someone with better F# skills than mine can add a lot to the Serilog/F# experience. If you have ideas we’d love to hear from you on the project site!

Querying collection properties in Seq 1.5

Seq implements a filtering syntax that’s loosely based on C#. The following expression matches the events you’d expect it to, if you’re used to working with C# or a similar language:

Tag == "seq"

Which is to say: “Match events where the Tag property has the value "seq". Sub-properties of objects can be accessed using the familiar dotted syntax (Property.Subproperty.Subproperty) and so-on.

Seq 1.5, currently a preview, steps into some new territory.

What about a collection of tags?

It’s not uncommon for Serilog events to carry properties that are collections. For example we might log events on a Q&A site like:

Log.Information("User {Username} posted a question tagged {Tags}", username, tags);

Resulting in events like:

Event with Collection Property

Instead of being marked with a single tag, each event carries a collection of zero-or-more.

Matt Hamilton asks:

This is where Seq 1.4 draws a blank. Translating this to the Q&A example, about the best we can manage is a text search for "seq" and requiring the existence of the Tags property using Has(Tags).

This is a bit of a shame – the promise of Seq and structured logging in general is to make querying log events precise – so why aren’t collections covered?

The C# way

Seq isn’t only about precise queries; the whole foundation of the app is the idea that it should also be easy and natural to query log data.

I’d thought about collection queries quite a lot when putting the original filtering syntax together. C#-style the query would look something like:

Any(Tags, tag => tag == "seq")

Seq doesn’t use extension method-style calls, but this is pretty close to the Enumerable.Any() call you’d write using Linq.

I don’t like it!

In a full-featured programming language this syntax makes sense, but it’s too noisy, complex, and easy to mistype to make a good filtering syntax for Seq. And so, that’s where things have sat for the last twelve months.

Pattern matching

With a bit more thought, Matt and I both ended up thinking the problem might be better suited to a pattern-matching syntax like:

Tags[?] == "seq"

So, this is what Seq 1.5 provides. The question mark wildcard ? matches any element in the collection, while an asterisk * wildcard only matches if all elements satisfy the condition.

Questions tagged seq

Wildcards work in any comparison where one side is a property path (including indexers and dotted sub-properties). Multiple wildcards along the path are supported.

You can write the following expression to find questions where all answers are "Yes!":

Answers[*].Content == "Yes!"

(Under the hood, Seq rewrites these expressions into the equivalent lambda-style syntax – much the same way as the C# compiler transforms Linq query comprehensions. Working through implementing this reminded me just how fantastic the C# compiler really is!)

Try it out!

You can download a preview build of Seq 1.5 here. It’s not ready for production use yet, but should be just fine for dev/non-mission-critical servers. We’d love to hear what you think!

Can we change the face of JavaScript logging, too?

If you use Serilog in .NET and write code for the web, chances are you’ve wondered whether similar hybrid “structured/text” loggers exist for the browser and Node.js

serilog-js

If you haven’t tried Serilog, here’s a one-minute primer (using JavaScript syntax) so you can follow the rest of this post. Using Serilog is similar to every logging framework, ever:

var name = "Nick";
var wait = 45;
log("Hi {name}, your flight leaves in {wait} minutes", name, wait);

Look carefully at the string formatting though – particularly the way we give names to each of the parameters. The “message” part isn’t destructively rendered into text, but preserved as an object with property values. It can be formatted to the console etc. as usual:

[inf] Hi Nick, your flight leaves in 45 minutes

But more interestingly, it can be serialized in a format like JSON for processing and querying:

{
  "message": "Hi Nick, your flight leaves in 45 minutes",
  "messageTemplate": "Hi {name}, your flight leaves in {wait} minutes",
  "properties":  {
    "name": "Nick",
    "wait": 45
  }
}

Preserving the structure of log data, and making it trivially easy to enrich that data with more contextual information, makes it possible to do some really clever things with the resulting logs.

Try finding all messages where the user’s name starts with “N”, or where the wait time is greater than one hour in a traditional log file if you’re skeptical here. In some trivial cases a regular expression might handle this cleanly, but it quickly becomes complex and cumbersome when more data is involved. Using Serilog it can be as simple as startswith(name, "N") or wait > 60.

Preserving the message template itself ("Hi, {name}...") also has some interesting and very useful results: the message template becomes a kind of “message type” that can be used to find – or exclude – messages of a specific type. Again very hard, often impossible with traditional loggers.

What’s going on in JavaScript?

In JavaScript as elsewhere, there are already some sophisticated logging frameworks, with varied levels of structured data support. A fairly new project called node-bunyan interests me the most, with its clever DTRACE integration and support for serializing objects instead of messages, but even here the new hybrid-style API and DSL provided by Serilog is missing. With node-bunyan it’s possible to log an object and/or a message, but messages are still formatted out in a lossy manner like the earlier loggers on .NET did.

Whether it grows into a standalone project in its own right, or encourages more established frameworks to take a look at this new style of logging, bringing Serilog’s API to JavaScript seems like a fun and worthwhile thing to try.

serilog.js

Tinkering away over a month of so I’ve sketched out what I think serilog.js should look like.

serilog.js-example

Yes, serilog.js terminal output is type-aware, just like syntax highlighting in an IDE! It’s useful when dealing with structured events to see the difference between a number 5 (magenta for numbers) and a string "5" (cyan for strings). In itself this feature is a nice trimming, but it’s not just a party-trick; below the surface, the event is carrying all of this information.

Getting started – installing from NPM

All the code is currently published to NPM. At the command line:

npm install serilog

Then in your node application:

var serilog = require('serilog');
var terminal = require('serilog/src/serilog-terminal-sink');
var file = require('serilog/src/serilog-file-sink');

Serilog “sinks” are destinations for log events. This example uses the terminal sink, which writes to the system terminal/console. At the moment, the sinks are all zipped up directly in the serilog package, but they need to be split out.

Tour of the API

At present, with very little of the back end ‘sinks’ built, serilog.js is all about the API.

Configuring the pipeline

One of the first things to notice is that the logger is a pipeline. Thinking of log events as structured data leads naturally to an API more like what you’d find in event processing frameworks than the typical logging library.

var log = serilog.configuration()
  .writeTo(terminal())
  .minimumLevel('WARNING')
  .writeTo(file({path: 'log.txt'}))
  .createLogger();

Each element is applied in turn:

  • serilog.configuration() kicks things off by creating a new configuration object
  • .writeTo(terminal()) emits all events to the terminal sink
  • .minimumLevel('WARNING') filters out any that are below the WARNING level (we’ll cover levels below)
  • .writeTo(file({path: 'log.txt'}) emits the events that reach it to a log file, and
  • .createLogger() takes all of these pipeline stages and bundles them up into an efficient logger object

The result is log, which we’ll use below. (As in Serilog for .NET, there’s no “global” logger – multiple loggers can be created and are completely independent, unless you link them together with something like .writeTo(log2)).

You might be wondering – why not Node.js streams or RxJS etc.? Simple really – generic APIs are great for glueing together solutions, but for something that’s used extensively in a codebase, maintaining complete control over dependencies, performance and semantics is a good idea long-term, and that’s the path taken here.

Logging levels

serilog.js has four simple logging levels, listed here in order of importance:

log.trace('This is a lot of detail');
log.information('Something of note happened');
log.warning('Look out, wheels are coming off!');
log.error('Something's broken');

If log.information() looks like a bit of a mouthful, don’t worry: the log object itself is a function that can be called as a synonym for information:

log('This is an information-level event');

The default level for a new logger is INFORMATION; using .minimumLevel('TRACE') at the start of the pipeline will bump this up.

Message templates

The syntax of message templates is carried over directly from Serilog. Event properties are named by including them in braces, and the values are provided as positional arguments:

log('{a} + {b} = {c}', 1, 2, 3);
// -> {properties: {a: 1, b: 2, c: 3}}

I’ve left the message/template/timestamp out of the example output (// -> ...) to keep the focus on the structured part of the event, but these other parts of the event exist too.

If you pass an object to the log, e.g.:

var mail = {to: 'nblumhardt', subject: 'Is the post finished?'};
log('Sending {mail}', mail);
// -> {properties: {mail: '[Object] object'}}

You might be surprised that it’s stored using toString(). We haven’t missed a great opportunity to serialize here – the problem is that it is very easy to serialize too much data by mistake this way.

If you know that what you’re passing into a log method is a nice little chunk of data to work with later, prefix the property name with @ to say “I know what I’m doing – serialize this!”:

var mail = {to: 'nblumhardt', subject: 'Is the post finished?'};
log('Sending {@mail}', mail);
// -> {properties: {mail: {to: 'nblumhardt', subject: 'Is the post finished?'}}}

serilog.js can handle structured storage of objects and arrays nicely, and these can support some really cool processing scenarios – just don’t forget the @ (if you watch the events roll by on the terminal, you’ll notice the difference too – objects are colored green, while strings render in cyan).

Context and enrichment

The strength of structured logs is in correlation; this is one of the great challenges when instrumenting distributed apps, and probably the #1 reason that interest in structured logs has picked up again in recent times.

When searching a large number of events produced across many machines, it’s vital to have properties to filter on so that a single location or thread of interaction can be followed.

In a simple case, you might want to instrument all events with the name of the machine producing them. This can be done when configuring the logger:

var log = serilog.configuration()
  .enrich({machine: env.HOSTNAME})
  ...

Events created by the logger will all carry the specified properties:

log('Hello, {name}', 'Nick');
// -> {properties: {name: 'Nick', machine: 'NBLUMHARDT-RMBP'}}

More often though, it’s desirable to tag events produced within a part of the application, or in a transaction. For this the using() method is provided on the logger itself:

var smtpLog = log.using({subsystem: 'SMTP'});
smtpLog('About to send mail to {name}', 'Nick');
// -> { properties: {subsystem: 'SMTP', name: 'Nick'}}
Filtering

A final part of the API to check out is filtering. While most filtering will happen server-side wherever you collect your logs, it can be useful to apply some filters in the logging pipeline if you have a component producing a lot of noise, or if you need to avoid passing events with sensitive data to logs.

This fits in as you’d expect:

var log = serilog.configuration()
  .filter(function(evt){
    return evt.messageTemplate.raw !== 'Making {noise}' &&
      evt.properties.subsystem !== 'SMTP';
  })
  .writeTo(terminal())
Building serilog.js

If you want to tinker with the project, you can grab the source from GitHub. The build process uses gulp to drive some mocha tests. Just type:

npm install
gulp

…and you’re away!

The browser

serilog.js also runs in the browser (though version support will be patchy and is completely untested!). There are some notes on the GitHub site linked above on how to do this, and a test.html page in the repository that sets some of it up.

The catch

Serilog in .NET is out there in production use today. It’s being extended and refined by a core group of contributors and takes what time I have available to coordinate.

I’ll be using serilog.js in a few small JavaScript projects and extending it for my own needs, and I’ll be building a sink that writes to Seq at some point. But, I don’t have the capacity to really drive this project beyond the prototype that it is right now.

If you’re interested in JavaScript, event processing, application monitoring and/or API design, serilog.js needs you. Kick the tyres, check out the code, send a pull request! It’s a project “up for grabs” in the largest sense. Can you help change the face of JavaScript logging?

Seq 1.4 preview is out!

The features planned for Seq 1.4 are starting to come together. There’s a new preview available to download on the Seq website (direct download).

While 1.4 is still a little way off “done”, many of the improvements we’ve made are usable today; here’s a run through what you can expect from the new version.

What’s Seq? Seq is the fastest way for .NET teams to improve visibility using structured application logs. If you’re using Serilog, you’ll find Seq is the perfect partner – trivially easy to set up, and built for structured log events so querying them is simple from “day 1” of a project. You already use CI and automated deployment: Seq is the next piece of the puzzle, closing the loop to show your team what’s happening in development, testing and production.

Charts

New in 1.4:

Counters-Downloads

Charts show the count of matching events in a time period. You can view the last day (by hour), last week (by day), last month (by day) or last year (by week). It’s a simple feature that I’m sure we’ll expand on, but already a great way to keep a “finger on the pulse”.

To add a chart, filter the “events” view to show just what you want to chart, then drop down the “refresh” button and select “Add to dash”. By default, queries are shown on the dash as counters; to toggle between the counter and chart display, there’s a little icon in the top left that appears on hover.

HowToChart

(If you’re already using counters with Seq 1.3, you’ll need to recreate them before historical data will be indexed by the 1.4 preview.)

Quick(er) switching between views

A much-requested improvement: when no view is selected, the first 10 views will be shown in a list (saving a few clicks when switching between views).

ViewSwitching

Extended text operators

A bunch of work has gone into better string comparison functions in this version. Seq queries now support:

  • Contains(text, pattern)
  • StartsWith(text, pattern) and EndsWith(text, pattern)
  • IndexOf(text, pattern), and
  • Length(text)

In each of these, “pattern” can be case-insensitive, case-sensitive, or a regular expression. There’s some more information and examples in the documentation.

Date functions and @Timestamp

Events in Seq now carry a queryable @Timestamp property, and we’ve added a DateTime() function that can be used with it. Check out the documentation for some examples here.

Keep the feedback coming!

Download the preview, try it out, and let us know what you think! You know where to find me :) – and there’s also a Seq discussion group we’d love you to join, and a Seq Twitter account if you’d like to keep in the loop.

Serilog gets a mention at NDC Oslo 2014

It was really cool to see this session from NDC about Elasticsearch/Logstash/Kibana featuring Serilog from just after 16:00.

Monitoring your app with Logstash and Elasticsearch from NDC Conferences on Vimeo.

It’s fun watching Serilog presented by people who obviously “get it”. And, compared with the alternatives shown earlier in the session, it’s great to see just how easy Serilog is for generating quality structured logs.

(If you’re not using Serilog and interested in the demo code, it’s on GitHub, but please check out this tiny PR if it hasn’t made it through yet.)

One year of Serilog

I just pushed the first build of Serilog 1.3 to NuGet. This one includes a more flexible JsonFormatter and support for width specifiers in format strings. Not huge changes, but both called for obsoleting some existing methods, and with 1.2 at the venerable age of “.53″ it was time to rev and get back to the nice simple version “1.3.1”.

It occurred to me that we’ve now hit the one year mark in the Serilog project. Version 0.1 was announced on March 29th, 2013 actually!

If there was any doubt back then of the viability of “yet another logger” in the .NET ecosystem, it’s been well and truly dispelled in my mind. Sixteen of us have now contributed to the project, and what’s most exciting to me is that the developers extending, using and discussing Serilog are some of the best and brightest I know. It’s the kind of momentum that makes me confident we’ll see more use and growth in the next year.

For those who follow it, the mention of structured logging as a technology to “trial” in the January 2014 ThoughtWorks Technology Radar is also a good indicator that Serilog is aligned with the facilities .NET developers will come to expect and use widely.

Our 1.0 came only six months ago, so these are still early days, but there are now 38 packages tagged “serilog” on NuGet, and despite the more-than-occasional glitches in the counter ;) the core Serilog package has over 7,400 downloads.

Visits to http://serilog.net are also looking healthy:

Serilog-One-Year

April’s been a visibly good month, with a lot of interest stirred up by a discussion on .NET Rocks! where I did my best to “get the word out” about how Serilog has totally transformed my thinking about logging.

If you’re using Serilog it would be great to hear more about how it has worked for you, and where you think the project should be aiming next – get in touch here or on our discussion list!

XML configuration for Serilog

Some issues hang on! Serilog’s #3 — XML configuration support — was still grimacing at us from the backlog alongside issues with three digits, until it was unceremoniously closed a few minutes ago.

If you’ve spent any time with Serilog you’ll have noticed the absence of built-in XML configuration support. Something about the project just wanted – and wants – to be a code-centric thing. I guess it is part of lifting the status of logging a bit – ORMs for example moved on from XML configuration to code-first/fluent configuration many moons ago. Instrumenting your app with an event stream is an important thing that deserves a modern configuration API.

XML’s not at all bad though. File paths change, servers have different addresses in different environments, logging levels go up and down. XML’s a great fit for this and we’ve known that all along with Serilog; we’ve just chosen to keep it in its place and write code like:

var logFile = ConfigurationManager.AppSettings["LogFilePath"];

var logger = new LoggerConfiguration()
  .WriteTo.File(logFile)
  .CreateLogger();

Over time this gets boring and repetitive I admit. Thats why we’ve now got the Serilog.Extras.AppSettings package.

XML configuration with a twist

As I said – we like XML configuration in its place, but that’s a pretty small place. When I open up App.config or Web.config in a modern .NET project the amount of gunk in there can be pretty confronting.

Most XML config implementations provide their own <configurationSection>s, and those need to be declared, and then the XML syntax used within them generally gets copied from a long list of arcana like the one in the log4net documentation that I’ve visited for years on end.

Serilog’s “app settings” support is different; we use a technique I first saw suggested for Autofac module configuration several years ago.

This revolves around the <appSettings> collection, an element that’s present in almost every .NET configuration file. Here’s an example to illustrate what we’re doing:

<appSettings>
  <add key="serilog:minimum-level" value="Verbose" />

Instead of our own custom <serilog> element, we cheat a bit and just look for <appSettings> elements that match a certain pattern (their names start with serilog:). Simple idea, but effective: I’m going to write this whole article without checking the documentation or sample code even once! Remembering a setting name or pattern is much easier for me than remembering a whole pile of custom XML syntax.

Going a bit further, here’s the configuation for two sinks, the console and a log file:

  <add key="serilog:write-to:ColoredConsole" />
  <add key="serilog:write-to:File.path" value="C:\Logs\myapp.txt" />

(Notice you don’t actually have to provide a value for an app setting? I didn’t until recently, but works nicely!)

Where do the magic names ColoredConsole and File.path come from? They’re just encodings of the following method calls:

  .WiteTo.ColoredConsole()
  .WriteTo.File(path: @"C:\Logs\myapp.txt")

The name of the path parameter obviously wouldn’t be specified in normal usage, but you can see how the XML and code-based configuration match up 1:1.

The extension methods are looked up dynamically using reflection, so you can configure your own sinks this way. You can include multiple parameters for the same sink using multiple keys – for both features check out the wiki page linked below.

Enabling the package

Two steps: 1. Install the Serilog.Extas.AppSettings package from NuGet; 2. add a call to ReadAppSettings() when you’re configuring your logger:

var logger = new LoggerConfiguration()
  .ReadAppSettings()
  ... // Other configuration here, then
  .CreateLogger()

You can mix and match app settings with code-driven config, but for each sink you need to use one or the other.

There’s much more detailed documentation here, on the wiki.

But isn’t this super-limited?

I’m happy to trade configuation power for something I can actually remember how to use. Someday we might have a more sophisiticated XML configuration option than this, but unless you can write the PR – I’m served pretty well by this one and not in a hurry.

But this is totally not my style!

That’s fine; it’s an ‘extra’, meaning we ship it separately from Serilog’s core and you’re free to install it if you like it and ignore it otherwise.

Still, I’ll be happy to hear if you do find it useful!

What’s to love about Seq 1.2?

The latest version of Seq is now ready to download from the site. It’s the best one yet, with a much smoother navigation experience and a bunch of small refinements that you’ll appreciate if you spend a lot of time with Seq each day.

Navigation

Digging into a lump of log data involves a lot of filtering – changing, adding and removing little search expressions to get a different cut of the events.

In Seq 1.0 we were at a bit of an impasse as to how this tied in with the browser’s history stack, so (I’m a bit ashamed to say!) we left it alone.

With the new version we’ve nailed this, I think.

First, filters typed into the filter box are included in browser history, so searching for “Alice”, then searching for “Bob”, then pressing back will again leave you at “Alice”. Simple win!

Bob

Furthermore, if you change views, this also is included in history. If you’re searching for an error message in Production and then switch to look for the same message in QA, pressing back will land you at Production again.
The final piece of the puzzle is the query, which remains as a saveable scratch area for filters that stay active regardless of browser navigation.

Viewport

In Seq 1.0 the initial result set returned for each query was 30 events regardless of your monitor size, and you had to click to see each additional page of 30 events.

No more in 1.2! The new version makes better use of the available space by filling the browser window with events.
Once you’ve requested more events with the “Older” button, Seq will start “infinitely scrolling” so events appear as you go further down the page.

The new version is ready and waiting at http://getseq.net.