Logging traces in ASP.NET Core 2.0 with Application Insights

Application Insights (AI) is a great way to gather diagnostic information from your ASP.NET app, and with Core 2.0, itʼs even easier to get started. One thing that the tutorials don’t seem to cover is how to see your trace logs in AI. By “tracing”, I mean things like:

_logger.LogInformation("Loaded entity {id} from DB", id);

This can be an absolute life-saver during production outages. In simpler times, we might have used DebugView and a TraceListener to view this information (in our older, on-prem apps, we used log4net to persist some of this information to disk for more permanent storage). In an Azure world, this isn’t available to us, but AI in theory gives us a one-stop-shop for all our telemetry.

Incidentally, itʼs worth putting some care into designing your tracing strategy — try to establish conventions for message formats, what log levels to use when, and what additional data to record.

You can see the tracing data in the AI query view as one of the available tables:

tracing_table
The AI “traces” table

For our sample application, we’ve created a new website by using:

dotnet new webapi

We’ve then added the following code into ValuesController:

public class ValuesController : Controller
{
  private ILogger _logger;

  public ValuesController(ILogger<ValuesController> logger)
  {
    _logger = logger;
  }

  [HttpGet]
  public IEnumerable Get()
  {
    _logger.LogDebug("Loading values from {Scheme}://{Host}{Path}", Request.Scheme, Request.Host, Request.Path);
    return new string[] { "value1", "value2" };
  }
}

We have injected an instance of ILogger, and we’re writing some very basic debugging information to it (this is a contrived example as the framework already provides this level of logging).

Additionally, we’ve followed the steps to set our application up with Application Insights. This adds the Microsoft.ApplicationInsights.AspNetCore package, and the instrumentation key into our appsettings.json file. Now we can boot the application up, and make some requests.

If we look at AI, we can see data in requests, but nothing in traces (it may take a few minutes for data to show up after making the requests, so be patient). What’s going on?

By default, AI is capturing your application telemetry, but not tracing. The good news is that itʼs trivial to add support for traces, by making a slight change to Startup.cs:

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory logger)
{
  loggerFactory.AddApplicationInsights(app.ApplicationServices, LogLevel.Debug);
}

We have just added AI into our logging pipeline; the code above will capture all messages from ILogger, and, if they are at logging level Debug or above, will persist them to AI. Make some more requests, and then look at the traces table:

tracing_results1.PNG

One further thing that we can refine is exactly what we add into here. You’ll notice in the screenshot above that everything is going in: our messages, and the ones from ASP.NET. We can fine-tune this if we want:

loggerFactory.AddApplicationInsights(app.ApplicationServices, (category, level) =>
{
   return category.StartsWith("MyNamespace.") && level > LogLevel.Trace;
});

You’re free to do any filtering you like here, but the example above will only log trace messages where the logging category starts with one of your namespaces, and where the log level is greater than Trace. You could get creative here, and write a rule that logs any warnings and above from System.*, but everything from your own application.

Traces are one of the biggest life-savers you can have during a production issue — make sure that you donʼt lose them!

Advertisements

Using the TryGet pattern in C# to clean up your code

Modern C# allows you to declare output variables inline; this has a subtle benefit of making TryFoo methods more attractive and cleaning up your code. Consider this:

public class FooCollection : ICollection<Foo>
{
  // ICollection<Foo> members omitted for brevity
  public Foo GetFoo(string fooIdentity)
  {
    return this.FirstOrDefault(foo => foo.Identity == fooIdentity);
  }
}

// somewhere else in the code
var foo = foos.GetFoo("dave");
if (foo != null)
{
  foo.Fight();
}

Our GetFoo method will return a default of Foo if one isn’t found that matches fooIdentity — code that uses this API needs to know that null indicates that no matching item was found. This isn’t unreasonably, but it does mean that we’re using two lines to find and assign our matching object. Instead, let’s try this approach:

public class FooCollection : ICollection<Foo>
{
  public bool TryGetFoo(string fooIdentity, out Foo fighter)
  {
    figher = this.FirstOrDefault(foo => foo.Identity == fooIdentity);
    return fighter != null;
  }
}

We’ve encoded the knowledge that null means “not found” directly into our method, and there’s no longer any ambiguity about whether we found our fighter or not. Our calling code can now be reduced by a line:

if (foos.TryGetFoo("dave", out foo))
{
  foo.Fight();
}

It’s not a huge saving on its own, but if you have a class of several hundred lines that’s making heavy use of the GetFoo method, this can save you a significant number of lines, and that’s always a good thing.

Dependency Injection with Model State Validation in ASP.NET Core

(caveat: this may or may not work in normal ASP.NET, I haven’t tried it yet)

“Validation” is a wonderfully ambiguous term. Usually, in simple examples, it’s restricted to ensuring that required fields are present, that dates are in the correct format, and so on. All of these only require access to the object being validated, which can be very easily done using data annotations:

using System;
using System.ComponentModel.DataAnnotations;

public class ValidateMe
{
  [Required]
  [StringLength(50)]
  public string ImARequiredField { get; set; }
}

You can take this a step further if, for example, you want to run rules on the data in the object by implementing IValidatableObject. An example:

using System;
using System.ComponentModel.DataAnnotations;

public class ValidateMe : IValidatableObject
{
  [StringLength(50)]
  public string ImARequiredField { get; set; }

  public bool TheFieldIsRequired { get; set; }

  public IEnumerable<ValidationResult> Validate(ValidationContext validationContext)
  {
    if (TheFieldIsRequired)
    {
      yield return new ValidationResult("The field is required", new string[] { nameof(ImARequiredField) });
    }
  }
}

Great! Now we can wire this up in our controller:

public IActionResult DoStuff(ValidateMe model)
{
  if (ModelState.IsValid)
  {
    // do stuff!
  }
  else
  {
    return View(model);
  }
}

Fantastic! But wait, what’s this? Oh dear, it’s the Real World(TM) come to burst our bubble.

Let’s take a more realistic example. Let’s say that we have a model that needs to set up a new user account. In our system, email addresses must be unique, and so we need to validate this before saving the user. We want to have a nice, clean, de-coupled architecture with injected dependencies, but where can we inject the dependencies into our validation system? Without them, we’d end up like this:

public IActionResult AddUser(AddUserModel model, [FromServices] IEmailValidator emailValidator)
{
  if (!emailValidator.IsEmailAvailable(model.Email))
  {
    ModelState.AddModelError("Email", "Email address is taken");
  }

  if (ModelState.IsValid)
  {
    // do stuff!
  }
  else
  {
    return View(model);
  }
}

Well, that’s ugly – it’s not terrible, but it’s bloating our controller, and, it turns out, we don’t need to do it at all, because enter ValidationContext!

public IEnumerable<ValidationResult> Validate(ValidationContext validationContext)
{
  // magic happens here!
  var emailValidator = validationContext.GetService(typeof(IEmailValidator));

  // now I has dependency, I can use ftw!
  if (!emailValidator.IsEmailAvailable(Email))
  {
    yield return new ValidationResult("Email address is taken", new string[] { nameof(Email) });
  }
}

Without doing anything special, ASP.NET is clever enough to pass its IServiceProvider into ValidationContext, and so we now have access to any dependencies that our application needs. The only slight downside is that the Validate method isn’t async, and so we’ll need to wrap any async calls in Task.Run(...) calls, but that’s a small price to pay for keeping our controllers slim.