Getting started with the Seq preview

A year ago, I started itching. Having accumulated a bunch of great logs on an online payments project, I wondered – just what useful information I could extract from them?

Working on a consulting gig, I wanted a quick way to get something useful in front of my client. “Quick” then meant minutes – not days or weeks. It had to be Windows-friendly, on premises and useful even if the only installation went onto my development laptop.

Coming away from that search unsatisfied, I started thinking about the fundamentals of the problem. Did I really need a log parsing and storage tool at all? Most of the challenge seemed to be in taking ugly log data and reliably extracting information. If the log data could be made less ugly, perhaps I could just use one of the tools I was already familiar with, like CouchDB or even SQL Server?

Somewhere down that line Serilog was born. It’s been out in the wild for a little while, and feedback has been very positive. Serilog solves the problem of log-ugliness for me, while maintaining the low up-front investment characteristic of successful logging tools. I’ve been less satisfied by the available back-ends, though. NoSQL databases are a good fit for storing structured events and have a gentle learning curve, but don’t really satisfy my second “enterprise consultant” requirement: being general-purpose, it is still necessary to invest time in learning their APIs and actually writing some code before getting at the juicy data inside.

Seq (as in ‘sequence’), released today as a very early preview, is my effort to scratch the itch for myself.

Seq web  UI

Seq is just getting started, but it assembles what I think are the right ingredients to build on:

  • Runs on-premises, as a console app without installation, or as a Windows service (no IIS to configure)
  • Provides queries over structured data using a simple C#-like syntax, with full-text search when it is needed
  • Takes exactly one line of code to configure via Serilog, which we’ll see below
  • Is built with .NET from the ground up

What can you do with Seq today?

Seq is a fun way to centralize logs from networked systems. You can set up views (“The eCommerce Site”, “Intranet Apps”, …) based on properties embedded in log events. You can write and save queries with multiple structured- and text-based filters, and you can export the results in CSV format for analysis in Excel (my preference!) or your traditional BI tools.

Export

And where is Seq going?

In the short term, there are a lot of performance, usability and feature requirements to implement before it will be ready for prime time. I hope Seq will stay simple as it grows, perhaps one day into the “developer’s tool of choice” for managing application events in .NET. First-class support for .NET programmability, and integration with the tools we use every day, are high on my list.

What Seq is not:

To clarify where Seq fits in, Seq is not an analytics tool. There are plenty of those out there, and chances are you can find one that meets your needs already. Seq is better described as a ‘staging ground’ for feeding those tools with quality data generated by applications.

Seq is also not “big data”. Big data capabilities come with trade-offs and usability issues that don’t make sense for everybody. Seq can theoretically handle terabytes of event storage, but takes a while to search more than a few hundred thousand events at a time (especially when ‘cold’). The number of useful information-level events emitted by an enterprise app in a week are generally orders of magnitude less than that; if you have big data you probably already know it, and have the motives and the resources to invest your time in learning something else.

Setting up – the client

To use Seq, you need to log events with Serilog. If you’re not using it already, you’re missing out! The Serilog site has some useful material to help you set up.

Seq provides a “sink” for Serilog, which we release via NuGet. It currently targets .NET 4.5 but support for .NET 4.0 is planned.

At the Visual Studio Package Manager console type:

PM> Install-Package Seq.Client.FullNetFx

Then, configure the logger and write some events:

using System;
using Serilog;
using Seq;

namespace SeqSimpleExample
{
    class Program
    {
        public static void Main()
        {
            Log.Logger = new LoggerConfiguration()
                .WriteTo.ColoredConsole()
                .WriteTo.Seq("http://localhost:5341")
                .CreateLogger();

            Log.Information("Hello, {Name}!", Environment.UserName);
            Console.ReadKey(true);
        }
    }
}

Run it now – there’s no Seq server listening, but the app will behave: as much as I love event data, collecting it can’t come at the expense of app stability.

SeqSimpleExample

Setting up – the server

The server requires .NET 4.5 and is tested on Windows 8. You should be fine with any .NET 4.5 machine. The web UI is tested with the latest Chrome, Firefox and IE10.

After downloading the Seq zip file from the site, extract it to a handy location – e.g. C:\Seq – and double-click the included Run.bat file. That’s it!

Seq - first run

Open a web browser at http://localhost:5341 to see your (empty) event stream.

Seq - Empty

By default Seq will create a Data folder next to the executable. You can change where data is stored and the URL that Seq will listen on, as well as install Seq as a Windows service, by running seq.exe from the command-line. Type seq help for a list of options.

Now, go back and run your client application again. Refresh the event stream with the little ‘o’ button in the toolbar, and voila! If everything went well your event will be displayed.

Hello

(If nothing showed up, make sure you didn’t terminate the console app “hard” with the close button before the event was published – the Windows console kills apps hard.)

Using Seq

The Seq interface is pretty simple and should be self-explanatory in most places. The best way to get started is to type some text in the Filter box and hit ‘Enter’ or press the ‘Filter’ button. Once you’ve found an event of interest, click on it. If you hover over a property value, you’ll see a selection of actions like the ‘Mark’, ‘Filter’ and ‘Exclude’ buttons shown here.

Hover

(If you haven’t used Serilog before, look closely – not just static properties tacked onto the events, but the tokens from the message itself like CustomerName are available as properties for searching on.)

Chances are the first thing you’ll use on “real” event data is the ‘Exclude’ button – there’s always more signal than noise! In this case though, press ‘Filter’ to drill down to events with matching property values.

Seq queries use a syntax that should feel comfortable to C# developers and natural to almost everyone else. For example, big checkouts might be found with a query like:

    "checkout" && TotalSpend > 500

To keep typing to a minimum, strings floating around on their own like "checkout" are treated as if they’re part of a Contains() function call. Pop over to the ‘doc’ tab in Seq to see some examples and a bit more information.

To export tabular data like one of the early screenshots show, use the ‘Mark’ button to pick out properties from events of interest.

Limitations

There are a lot! For example, event retention is fixed at 15 days (a proper retention policy implementation is in the works) and only one user account is supported (it is called ‘admin’). But, it is more fun to iterate in the open. Depending on the time available I hope to put an increment out every 2-4 weeks.

Licensing and all that stuff…

Unlike many of my other software obsessions, Seq is not an open source project. To follow through with the project is going to take time, so make that a reality a commercial release is more realistic.

The each preview build can be used for 30 days, after which I hope you’ll grab an updated preview build. At ‘RTW’ there will be a variety of licensing options that I hope will fit everyone who wants to use the app.

Feedback

I’d love to hear from you if you try Seq! Experiences good and bad are best shared on the issue tracker.

Thanks for help reaching this milestone go out to Jesse Beard, Jaben Cargman, and David Pfeffer who kindly provided feedback on the very first usable builds.

…and then 1.1

Serilog has been ticking along since our 1.0 release six weeks ago. We’ve added a few new faces to our Contributors page since then, including

We’ve had plenty of help keeping the project healthy with smaller pull requests, discussions and issue reports.

The current version on NuGet, now stamped ’1.1′, rolls up a few things that are worth a brief mention here too:

.NET 4.0 support

In case you missed the somewhat understated mention on Twitter, the Serilog package now adds support for .NET 4.0. This includes the logging pipeline and all of the built-in sinks (file, console, …). As of writing, some binary compatibility constraints mean that most of the “Extras” and add-on sinks will need to be modified or recompiled to use on .NET 4.0, so drop a line to the mailing list if there’s anything particular you need help with.

To get going with Serilog on .NET 4 all you need to run is:

PM> Install-Package Serilog

Improved byte[] handling

In Serilog 1.0, byte arrays are treated as scalar values. This is because many data stores have built-in support for simple binary values.

byte[] packet = ReadPacket();
Log.Information("Received {Packet}", packet);

This code would result in the contents of packet being passed through and serialized by any configured sinks that supported it (e.g. any of the JSON-based sinks).

Two problems came out of this:

  1. Big binaries could cause a nasty payload surprise
  2. Serilog’s asynchronous logging pipeline requires that scalar values are immutable, which byte arrays aren’t

1.1 makes a different set of compromises that will be a bit more friendly.

Byte arrays smaller than a kilobyte will continue to be passed through as scalar values, but internally we make a copy at the time of logging to protect from later mutations. There are a few use cases where small chunks of binary data are useful in logs – hopefully less than 1 kb is about the sweet spot for those.

Byte arrays larger than 1 kilobyte are now passed through the pipeline as descriptive strings, including the first 16 bytes in hex and the overall length. A large binary will look like:

"E67867EFA578A000AA78EF4D34AA3412... (4672096 bytes)"

Much more fun than 4 GB of base-64 encoded text in JSON. It is still possible to serialize arbitrarily-large binaries with Serilog using a custom type and destructuring policy. If you’re interested in doing this please mail the discussion list.

As part of this refresh, handling of Nullables and Delegates were also improved.

Diagnostic help

One tiny but crucial improvement, the Serilog package now includes PDBs for the Serilog.dll and Serilog.FullNetFx.dll binaries, increasing our chances of getting meaningful stack traces in error reports.

Along with this the SelfLog class, used for debugging Serilog itself, now flushes its output after writes making use with file streams easier.

That’s it for today, happy (Seri-)logging :)

Serilog hits 1.0

Serilog

Yesterday the core Serilog package quietly ticked over to become our “1.0” release. If you’ve never tried Serilog, now’s a great time to get started. To find out what it is all about, visit our documentation.

A huge effort has gone into our “serializing logger” over most of this year – I set out hoping to thank everyone involved personally, but quickly found that writing the list is a project in itself. Instead I’ll have to be content with pointing to the awesome contributions, extensions and integrations and helpful issue reports we’ve clocked up. Thanks also to everyone sharing in the vision of what Serilog can be – the ideas and encouragement have carried it a long way!

The project supports a lot of extensions; storage options like Azure Table Storage, CouchDB, MongoDB, RavenDB; broadcasting via SignalR and visualization with Glimpse. These are all in active development and use, but I’m waiting to collect more feedback on each individual package’s maturity before stamping the 1.0 version number on them.

Now seems like a good time to quickly mention Seq, a side project I have in the works to scratch a big itch for me: finding a simple way to capture, filter, correlate and consume structured events from Serilog. I’m intending a small preview in the next few weeks – if you’re using Serilog and interested in providing early feedback please contact me directly.

Lastly, Brisbaneites: find out more about Serilog this Tuesday, 15th October at the BNE.NET User Group.

Happy logging!

Serilog gets a “diagnostic context”

Serilog 0.9.2 includes a new feature that I’ve been holding off on committing to for some time. Those familiar with the NDC (“Nested Diagnostic Context”) in log4net and similar features elsewhere will recognise the basic idea behind LogContext:

log.Information("No contextual properties");

using (LogContext.PushProperty("A", 1))
{
    log.Information("Carries property A = 1");

    using (LogContext.PushProperty("A", 2))
    using (LogContext.PushProperty("B", 1))
    {
        log.Information("Carries A = 2 and B = 1");
    }

    log.Information("Carries property A = 1, again");
}

An application can push properties onto the context to tag events associated with some unit of work, perhaps identifying a specific transaction, customer, message and so-on. The properties can later be used to find messages of interest.

Serilog is all about easier filtering and correlation of events, so, why hold off on adding this feature until now? The reason is that for flexibility and reliability, Serilog’s logging pipeline is essentially stateless and is completely free of static or ambient state. Making all loggers dependent on a global, shared context stack seemed like the wrong thing to do.

Fortunately, it turned out to be easy to reconcile this feature with Serilog’s goals. To use properties from the context, loggers opt-in via a simple configuration method:

var log = new LoggerConfiguration()
    .Enrich.FromLogContext()
    // ...

This way, only loggers that explicitly take interest in the LogContext are affected by it.

Why is this supported only on the full .NET 4.5 framework?

A useful diagnostic context, in today’s .NET, has to play nicely with async/await. Properties pushed onto the stack need to be preserved when an awaited call completes, as below:

async Task Handle(Message message)
{
    using (LogContext.PushProperty("MessageId", message.Id))
    {
        var items = await LoadDataAsync();
       
        Log.Information("Loaded {ItemCount} items", items.Count);
    }
}

In this example, the thread that executes the Log.Information() call may be different from the one that pushed the MessageId property on the stack, because of the awaited call.

Because the thread that resumes execution after awaiting may be a different one from the one that pushed the property onto the stack, [ThreadStatic] variables aren’t suitable for implementing a diagnostic context anymore. Only .NET 4.5 has an async-aware CallContext.LogicalGetData() suitable for this purpose. Stephen Cleary has written a useful article with more discussion of the topic.

Serilog sink for Glimpse

Glimpse is a plugin for ASP.NET that renders server-side request information directly in the browser, in much the same way as Firebug or Google Chrome Developer Tools show client-side information.

With Glimpse and the Serilog Glimpse Sink installed in an ASP.NET project:

PM> Install-Package Glimpse.AspNet
PM> Install-Package Serilog.Sinks.Glimpse

And configured in Global.asax:

Log.Logger = new LoggerConfiguration()
    .WriteTo.Glimpse()
    .CreateLogger();

Log messages written to Serilog will appear in a new Serilog tab in the Glimpse UI:

Glimpse integration for Serilog

Serilog and Glimpse are a great match – when structured objects are used in Serilog events, Glimpse can render them in a nice expandable tree format.

Thanks to the awesome Robert Wagner for kicking off the Glimpse Sink.

More fresh Serilog updates…

WriteTo.Observers()

This tiny new sink in the core Serilog package supports processing Serilog events using Reactive Extensions for .NET (Rx).

var log = new LoggerConfiguration()
    .WriteTo.Observers(events => events
        .Do(evt => { Console.WriteLine(evt.Timestamp); })
        .Subscribe())
    .CreateLogger();

Rx enables some very interesting event processing scenarios on top of Serilog, which I hope to write more about in the future.

Serilog.Extras.Topshelf

A logging integration for the Topshelf Windows service hosting framework. To get started, first install the package:

PM> Install-Package Serilog.Extras.Topshelf

Before running the Topshelf host factory, set up the logger:

HostLogger.UseLogger(new SerilogHostLoggerConfigurator());

Serilog.Web renamed to Serilog.Extras.Web

The Serilog.Web package, providing some helpers for use with ASP.NET, has been renamed Serilog.Extras.Web – as in the Autofac project, we’re going to use the Extras designation to keep clear what is part of the core Serilog package, and what is provided and supported as a best-effort contribution.

Stupidly easy log queries with Serilog and RavenDB

Have you ever been frustrated with the tedious process of answering even simple questions using regular expressions over log file data?

In one of the early Serilog demos we wrote an event like:

20:08:43.232 [Information] Processed { Lat: 25, Long: 134.5 } in 34ms

Given this log data, for example,

Which sensor inputs took more than 100ms to process?

Regular expression-based searching is great for matching textual patterns, but not so much fun when richer data types (if you can call numbers “rich”) are involved.

By combining Serilog with RavenDB, a commercial document database for .NET, the answer can be derived as simply as issuing the query:

MessageTemplate: "Processed {@SensorInput}*" AND Properties.Elapsed_Range: [Ix100 TO NULL]

This query’s very specific about a) the event type, and b) the numeric range of the Elapsed property. Both of these aspects are tricky to replicate using traditional text-based logs.

Let’s walk through this scenario step-by-step.

Creating a database in RavenDB

If you’ve just downloaded RavenDB you’ll need to start a server. For quick and dirty experiments, the Start.cmd script in the root of the RavenDB zip file will run a local server bound to HTTP port 8080.

The Raven Studio web UI is the first place to go. I’ve created a database called Logs.

logs-database

There aren’t any documents in there yet; we’ll write those through Serilog’s RavenDB sink.

Configuring the RavenDB Sink

The Serilog.Sinks.RavenDB package has everything you need for getting log data into RavenDB.

PM> Install-Package Serilog.Sinks.RavenDB

In your application startup code (Main(), Application_Start() etc.) create a DocumentStore object describing the location of your logs database.

var documentStore = new DocumentStore
{
    Url = "http://localhost:8080",
    DefaultDatabase = "Logs"
};

Configure Serilog using the WriteTo.RavenDB() method.

Log.Logger = new LoggerConfiguration()
    .WriteTo.ColoredConsole()
    .WriteTo.RavenDB(documentStore)
    .CreateLogger();

That’s it! You’re ready to write some log events.

Writing to the log

If you’ve never used Serilog, there are only a couple of things you need to know up-front.

var sensorInput = new Position { Lat = 25, Long = 134.5 };
var elapsedMs = 34;
Log.Information("Processed {@SensorInput} in {Elapsed} ms", sensorInput, elapsedMs);

First, log methods use named rather than positional arguments in format strings. SensorInput and Elapsed are the property names given to the sensorInput and elapsedMs values, respectively.

Second, to capture the structure of a log event property (instead of just capturing it with ToString()) prepend @ to the property name. This is a safeguard against accidentally serializing large object graphs. An article in the documentation has more detail on writing structured data.

After writing a few events, they can be seen in the Raven Studio interface.

raven-showing-logs

If we peek into one of the log events, the preserved structure of the event data can be seen.

{
  "Timestamp": "2013-06-18T17:49:47.7947070+10:00",
  "MessageTemplate": "Processed {@SensorInput} in {Elapsed:000} ms",
  "Level": "Information",
  "Exception": null,
  "RenderedMessage": "Processed Position { Lat: 24.7, Long: 132.2 } in 037 ms",
  "Properties": {
    "SensorInput": {
      "Lat": 24.7,
      "Long": 132.2,
      "$typeTag": "Position"
    },
    "Elapsed": 37,
    "ThreadId": 9,
    "MachineName": "NBLUMHARDT-RMBP"
  }
}

RavenDB Dynamic Queries

The commonly-used query API on RavenDB is Linq, but the lesser-known Lucene syntax is apparently used as RavenDB’s internal representation.

Documentation is a little sparse but the syntax is quite intuitive after a few attempts. Jumping into the Indexes > Dynamic Query screen, our query finds the events we’re after.

raven-query

(I’ve had to drop the time threshold to 10ms to pick anything up in my data set.)

Concluding thoughts

Among the ‘NoSQL’ data stores I’ve tried so far as back-ends for Serilog, RavenDB seems to be a reasonably good fit for the job. What excites me most about the potential of Serilog is the ability to go ‘beyond grep’ and deal with log data in more useful types like numbers, dates and so-on. Through RavenDB we’ve been able to home in on a specific event type and a numeric range, and hardly broke a sweat.

Lucene itself is also very text-oriented, great for classic log searching scenarios. I’m not sure how much of that is surfaced by RavenDB, definitely something to explore.

Caveats

One thing to watch – the RavenDB sink writes events periodically, in batches on a background thread. In normal circumstances, Serilog will flush the current batch on shut-down of the AppDomain, so events will rarely be lost, if ever. Terminating the app “hard” by stopping the debugger may prevent some events from being written back to the database. Using remote sinks like RavenDB in conjunction with a local log file is recommended, anyway.

Also worth pointing out is that RavenDB is a sophisticated piece of software with specific capabilities and requirements. Dumping in and querying large volumes of log data will require some up-front planning and performance analysis that I haven’t done. If you’re using RavenDB in this way today I’d love to know more about the experience.

Acknowledgements

Thanks to Nick Van Eeckhout for figuring out and contributing the RavenDB sink!

Serilog.Sinks.Log4Net

Would you like to try Serilog, but have existing log4net infrastructure? On the journey to “1.0” Serilog needs your experiences and feedback. The Serilog.Sinks.Log4Net package may provide just what you need to kick the tyres of Serilog without turning your existing code and libraries upside-down.

This package lets you pipe structured log events off to suitable storage, while text representations are merged into log4net to be written to a consolidated flat log file.

Serilog.Sinks.Log4Net

To install the package:

PM> Install-Package Serilog.Sinks.Log4Net

Your existing log4net configuration remains unchanged, e.g. using the XmlConfigurator:

XmlConfigurator.Configure();

In your Serilog configuration, include both your choice of structured event storage (in this example the RavenDB sink), and the log4net sink:

Log.Logger = new LoggerConfiguration()
    .WriteTo.RavenDB(documentStore)
    .WriteTo.Log4Net()
    .CreateLogger();

Events written to a log4net logger will travel through the log4net pipeline only. Events written to Serilog will be emitted to RavenDB with full property structure intact, and to the log4net pipeline as regular text-based messages.

The sink is very simple, preserving log levels (Information, Warning, Error and so on) as well as the source class name if ForContext<TSource>() is used.

A running example can be found in the Serilog GitHub repo.

A discussion forum for Serilog

If you’re curious about Serilog (or have a rant that might take more than the humble comment boxes below can accommodate) please drop in and say “hello”!

A console sink with property colouring

The coloured console ‘appender’ is one of my favourites in log4net, so high on the list for inclusion in Serilog.

Smart property highlighting makes the result quite interesting:

ColoredConsoleSinkDemo

You can use it on the full .NET Framework using the out-of-the-box Serilog 0.2.8 package.

Log.Logger = new LoggerConfiguration()
    .WriteTo.ColoredConsole()
    .CreateLogger();

Simple at this stage, but fun! What do you think?

Changes in Serilog 0.2

Serilog

Thanks for all the feedback on Serilog, keep it coming! Version 0.2 is now on NuGet and introduces a couple of noticeable changes.

Phone and tablet support

The core of Serilog is now portable across .NET 4.5, Windows 8 and Windows Phone 8.

Serilog on WP8

The latter two platforms only include one ‘sink’ out of the box, that writes to a System.IO.TextWriter. I’d like to set up sinks for local storage on those platforms, if you’re knowledgeable (or brave!) and interested in helping out.

Revised configuration API

The first version of LoggerConfiguration used flat method chaining to drive the configuration process.

Log.Logger = new LoggerConfiguration()
    .MinimumLevel(LogEventLevel.Debug)
    .WithConsoleSink()
    .CreateLogger();

The number of methods on LoggerConfiguration became unwieldy quickly. On typing ‘.’, a user would be presented with everything including .WithKitchenSink().

0.2 aims at a cleaner IntelliSense experience by grouping options:

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console()
    .CreateLogger();

In addition to MinimumLevel and WriteTo, you can configure Serilog to Filter log events based on arbitrary rules, Enrich log events with properties calculated at runtime, and Destructure complex parameter types for serialization various ways.

There are advantages and disadvantages to any API, for the moment I’m happy with this direction but open to suggestions (give it a try!) Thanks @droyad, @uglybugger and @turtlator for the motivation and first round of feedback.

Control over ‘destructuring’

The new version survives the serialization of circular object graphs and offers more control over the serialization process. For example, only a selection of properties from HttpRequestMessage might be included in a log event:

Log.Logger = new LoggerConfiguration()
    .Destructure.ByTransforming<HttpRequestMessage>(
        m => new { Uri = m.RequestUri.AbsoluteUri,
                   m.Method,
                   m.Headers })
    ...

Log.Debug("Received {@Message}", httpRequestMessage);

Thanks @sandcastle_hq for putting the momentum behind this.

(Quick note on terminology, Serilog breaks down objects in two phases; destructuring controls the tree created out of regular .NET objects, while serialization is specific to the sink being used, for example converting that tree structure into JSON.)

What’s next?

Use, feedback, documentation, performance profiling and tuning, more sinks.