App Insights trace correlation

Application Insights is the application performance monitoring feature of Azure Monitor, and can be used to monitor deployed applications both in the cloud and on premises. App Insights supports W3C Trace Context standard headers to correlate tracing information across different components.

The features of App Insights, and Azure Monitor, are quite broad, whereas developers may want in some cases to filter down and focus on application-specific logging. Trace correlation is an important part of this, to get and end-to-end overview of operations.

To view logs, connect your App Insights instance to a Log Analytics workspace. Within the workspace, General > Logs will provide access to the query editor — you can either user one of the default Queries pop-up or write your own.

For example, to see all recent traces, and the correlation between them you can use a query like:

union AppTraces, AppDependencies, AppRequests
| where TimeGenerated > ago(30m)
   and Properties.CategoryName !startswith "Microsoft"
| sort by TimeGenerated desc
| project TimeGenerated, Type, OperationId, Id, Properties.SpanId, 
   ParentId, ClientType, Message, Name, SeverityLevel, Properties, 
   Properties.CategoryName, OperationName, SessionId,
   UserId, AppRoleInstance

Example output:

This example shows all the traces from one operation are linked to the same OperationId 029c3..., and the parent-child relationship between two tiers client (Browser) and server (PC) can also be determined:

  1. Client (Browser) AppTraces have a ParentId 7d65e...
  2. The client has a link from this parent to a child AppDependency with Id 73676...
  3. On the server (PC) the dependency is recorded as the parent if the AppRequest Id 15c7e...
  4. Additional traces on the server show the request as the ParentId (and there may be further parent-child links depending on the number of tiers).

There are many other types of records that can be queried, for example developers may often be interested in exceptions and traces that feature a particular keyword:

union AppExceptions, AppTraces
| where TimeGenerated > ago(30m)
| sort by TimeGenerated desc
| search "Password"
Continue reading App Insights trace correlation

A Guide to W3C Trace Context

Earlier this year the W3C Trace Context Recommendation was finally published. A standard way of passing distributed trace correlation has been needed for a long time, and it is good to see there is finally a standard, and many vendors have already moved to adopt it.

The Recommendation defines what a distributed trace is:

A distributed trace is a set of events, triggered as a result of a single logical operation, consolidated across various components of an application. A distributed trace contains events that cross process, network and security boundaries. A distributed trace may be initiated when someone presses a button to start an action on a website – in this example, the trace will represent calls made between the downstream services that handled the chain of requests initiated by this button being pressed.

What constitutes a single logical operation depends on the system. In the example above it is a single button press on a website, whereas in a batch processing system it might be for each item processed, or in a complex UI it might consist of both a button press and a subsequent confirmation dialog.

The W3C Trace Context Recommendation describes how the correlation information — an identifier for the operation, and the parent-child relationships between components — is passed in service calls, but doesn’t cover what to do with that information, apart from how to pass it to the next component.

This is a guide mostly how to use Trace Context for logging, although it also applies to metrics and other telemetry.

Continue reading A Guide to W3C Trace Context

Elasticsearch-Logstash-Kibana (ELK) LoggerProvider for .NET Logging

This ElasticsearchLoggerProvider, for Microsoft.Extensions.Logging, writes direct to Elasticsearch, using the Elasticsearch Common Schema (ECS), and has full semantic logging of structured data from message and scope values.

To use, add the Essential.LoggerProvider.Elasticsearch package to your project:

PS> dotnet add package Essential.LoggerProvider.Elasticsearch

Then add the logger provider to your host builder, and the default configuration will write to a local Elasticsearch service:

using Essential.LoggerProvider;

// ...

    .ConfigureLogging((hostContext, loggingBuilder) =>
    {
        loggingBuilder.AddElasticsearch();
    })

Once you have logged some events, open up Kibana (e.g. http://localhost:5601/) and define an index pattern for dotnet-* with the time filter @timestamp.

You can then discover the log events for the index. Some useful columns to add are log.level, log.logger, event.code, message, tags, and process.thread.id.

Structured message and scope values are logged as labels.* custom key/value pairs, e.g. labels.CustomerId.

Example: Elasticsearch via Kibana
Continue reading Elasticsearch-Logstash-Kibana (ELK) LoggerProvider for .NET Logging

Rolling file LoggerProvider for .NET Logging

I have just released version 1.0 of the Rolling File Logger Provider as part of Essential Logging on Github, a port of my .NET diagnostics library across to Microsoft.Extensions.Logging.

To use, add the Essential.LoggerProvider.RollingFile package to your project via Nuget:

dotnet add package Essential.LoggerProvider.RollingFile

Then reference the namespace, and add the logger provider during host construction:

using Essential.LoggerProvider;

// ...

    .ConfigureLogging((hostContext, loggingBuilder) =>
    {
        loggingBuilder.AddRollingFile();
    })
Continue reading Rolling file LoggerProvider for .NET Logging

Syslog Structured Data for Microsoft Extensions Logging

The first part of logging I have polished up Microsoft.Extensions.Logging is structured data support with a Syslog Structured Data package that contains a component which will render as syslog RFC 5424 structured data.

Diagnostics Logo

To use the Syslog StructuredData component, install the nuget package:

dotnet add package Syslog.StructuredData

You can then use the structured data via BeginScope() on an ILogger:

using (_logger.BeginScope(new StructuredData
{
    Id = "origin", ["ip"] = ipAddress
}))
{
    // ...
}

For default logger providers, that don’t understand structured data, the ToString() method on the StructuredData object will render out the data in RFC 5424 format. This format can still be easily parsed by log analyzers, although the surrounding context won’t be a syslog message.

Example output: Using the default console logger, with scopes and timestamp
Continue reading Syslog Structured Data for Microsoft Extensions Logging

Alpha of Essential Logging RollingFile

The new Microsoft.Extensions.Logging system has some improvements over the previous System.Diagnostics, with built in support for dependency injection and semantic logging (although I tend to think a singleton-type pattern, like TraceSource, is better than cluttering up every constructor with a logger).

Strangely, however, Microsoft did not include a basic file logger; they have App Insights, and even a file logger that works on Azure-only, but no basic logger. I guess they thought between Serilog/NLog/log4net/etc that there were enough third parties.

The only problem with these is that each of then is an entire logging systems, so you end up going through one framework (Microsoft.Extensions.Logging) to get to another framework (e.g. NLog) before you end up at an actual logger (e.g. a file logger). Why two frameworks?

With the old .NET Framework I never understood this either, which is why I wrote a range of TraceListeners, that each independently plugged into System.Diagnostics directly.

And finally I have started to port it across to Microsoft.Extensions.Logging, with an alpha release of Essential.Logging.RollingFile

This won’t be another framework, just a bunch of logger providers that plug into the provider system.

It is only alpha; it works — I mostly just copied it across from Essential.Diagnostics and commented out the invalid parts, but the infrastructure is still in flux while I sort things out.

Structured logging with .NET Framework System.Diagnostics

Structured logging (also sometimes called semantic logging) is a useful addition to the software development toolkit.

The latest release (2.2.0, and some 2.1.728) of Essential.Diagnostics adds structured tracing capabilities to the .NET Framework System.Diagnostics. It integrates seamlessly with existing tracing, including from the .NET Framework, and includes both producer-side extensions (to include in your application) and trace listener changes (to integrate with structured tracing systems).

The key new and updated packages are:

While the packages can be used independently, using both a producer and consumer in combination multiplies the benefits.

Continue reading Structured logging with .NET Framework System.Diagnostics

Seq TraceListener for System.Diagnostics

Following hot on the heels of v2 of Essential.Diagnostics, work on the beta version of the Essential.Diagnostics.SeqTraceListener has been completed, and it has been published to NuGet.

PM> Install-Package Essential.Diagnostics.SeqTraceListener

This provides a trace listener implementation that forwards messages to a Seq logging server. For performance it forwards messages in batches (with the first message being sent immediately, so you know the system is up and running), with automatic back off and retry when there are interruptions to the network communication.

This component can be used with the new Microsoft.Extensions.Logging for .NET 4.5.1 and above, or with Sytem.Diagnostics.TraceSource for .NET 2.0 through 4.5.

Essential.Diagnostics v2

I have made significant changes in the organisation of the Essential.Diagnostics project; although none of the actual implementations have changed, the project has been split into separate packages for each trace listener, available via NuGet.

The packages are available on NuGet (Essential.Diagnostics), and the source code on CodePlex (Essential.Diagnostics).

The project also has a new logo:

essential-diagnostics-64

Continue reading Essential.Diagnostics v2

XML Logging in the .NET Framework

This was originally going to be some guideline instructions for a CodePlex project, Essential.Diagnostics that I work on, but it ended up being more an opinion piece so I thought it would fit better on a blog.

There are several trace listeners (loggers) in the .NET Framework that can produce XML output. Outputting to XML results in more complex (verbose) files than, say, a simple text file output, but usually has the benefit of being better processed by tools, correlated across tiers, etc.

There are three main XML listeners, plus one extension in Essential.Diagnostics:

  • XmlWriterTraceListener
  • RollingXmlTraceListener (in Essential.Diagnostics)
  • EventSchemaTraceListener (in System.Core)
  • EventProviderTraceListener (in System.Core)

Examples of how to configure and use each one (used to produce the output below) is provided in the Essential.Diagnostics project.
Continue reading XML Logging in the .NET Framework