An IStartup Gotcha – The Curious Incident of the Missing Log Provider

In this post I look at a problem I had with injecting values into the constructor of a class that implemented IStartup and why doing this does not work as expected.

Background

When learning a new technology, I like to get to know the inner workings of it to try and understand how my code will work and develop a set of my own best practices.

Two areas of ASP.Net Core that I have a lot of interest in are the startup pipeline and configuration. The latter of these has been the focus of my previous posts about how to set up configuration using a SOLID approach.

For the former, I have been reading several blog posts, the most illuminating of which has been Steve Gordon’s blog which I highly recommend a read of. (Full disclosure – Steve runs the local .Net South East user group that I regularly attend).

In particular, I found his post on the Startup process illuminating as it reveals a whole load of reflection work being done by the ConventionBasedStartup class when using a convention based Startup class.

Now whilst I appreciate that Microsoft wants to make the Startup class as simple as possible to implement out-of-the-box in a new project, I am not a massive fan of this approach once you know what you are doing. After reading Steve’s blog post, it seemed logical to refactor my Startup classes to implement the IStartup interface as this is the first thing that is checked when instantiating the class (as shown in Steve G’s gist here)

On reading through how the ConventionBasedStartup class constructs an implementation of IStartup, I came to the following conclusions:

  • There is a lot of reflection going on that, if IStartup was used, would not be required
  • It is not statically typed, so if signatures are incorrect in some way such as a typo, it will fail at runtime but not be caught at compile time
  • The ability to have multiple versions of the same method for different environments in the same class differentiated by name E.g. ConfigureServicesDevelopment, ConfigureServicesStaging and relying on the ASPNETCORE_ENVIRONMENT environmental variable feels clunky and doesn’t feel like a SOLID approach.

I can see why Microsoft has taken this approach as it is easy to provide boilerplate code that is easy to extend, but for me, the convention approach does not feel right for the Startup process (though I reserve the right to be hypocritical in that I have been using the convention based approach for years in letting ASP.Net MVC work out which controller is being used in routing, but hey, I’m not perfect! ).

Therefore, in my ASP.Net Core projects, I started to refactor the Startup classes to implement the IStartup interface.

This was the approach I took on a project I was working on for a client. I had recently added NLog and this was working nicely using the convention based Startup, but in an effort to clean up the code, I wanted to refactor to IStartup. However, for some strange reason, the NLog logger stopped working after refactoring.

Time to get the deerstalker and magnifying glass out.

How Using IStartup Differs from Convention Based Startup

At first glance, the Startup classes used in both approaches appear to be the same, but there is one significant difference.

In the convention based approach, you are free to add as many parameters as you want to the Configure method, safe in the knowledge that as long as you (or rather in most cases, the WebHost.CreateDefaultBuilder) have registered the interfaces or classes you require with the Dependency Injection services, then they will be injected into the method.

This is thanks to the ‘magic’ inside the ConventionBasedStartup. When implementing IStartup yourself, the signatures are set in the contract

Of particular note is the signature for the Configure method which only accepts a single parameter of type IApplicationBuilder.

Therefore, if you want to inject other types, you can’t just add them to the method parameters, so you need to find another way.

Adding ILoggerFactory to the Startup Constructor – Don’t Do This At Home

TL;DR You can skip this bit if you want as it describes how I got to the bottom of the problem. If you just want to know how to correctly access the ILoggerFactory, go to here

When writing code that implements an interface, if I need extra class instances that are not provided for in the method signature, my usual approach is to make an instance variable that is assigned from a constructor parameter.

So when I no longer had access to ILoggerFactory in the Configure method, I added it to the Startup constructor and created an instance variable that I could then accessed from inside the Configure method. So far, so normal. I did the NLog configuration in the Configure method and just expected things to work as they had before.

Alas, twas not to be …

At first I thought that I must have messed up something in the NLog configuration, but couldn’t see anything different. So I stepped through the code. I looked at the ILoggerFactory that had been injected into the constructor of the Startup.

There were two providers present, Console and Debug. I then ran through the code to where NLog had been added, and looked at the providers collection again. Yup, three providers with NLog being the last. All good.

I then ran though to the constructor of the controller where I was doing some logging where I had declared a parameter of ILogger. I looked at the Loggers collection on the logger and there were four loggers, but no sign of the NLog logger.

Somewhere along the pipeline, the ILoggerFactory had lost NLog and added two loggers, both of which were the ApplicationInsights logger.

For the client’s project I reverted back to the convention based approach so as not to hold up the development, but my curiosity got the better of me and decided to dig a bit more.

Compare and Contrast

At home, I created a simple project where I created two copies of the Startup class. One using the convention approach where ILoggerFactory is injected into the Configure method and one where I have the ILoggerFactory injected into the constructor of the Startup class and saved in an instance variable. I then used a compilation symbol to run with one or the other.

I created a dummy class that implemented ILoggerProvider rather than muddy the waters by using NLog and having to worry about its configuration. I then implemented the constructor based code as I had previously done, as shown below:

I ran through both scenarios using the Visual Studio debugger and got the same result.

  • When using convention based Startup class, there were five loggers, Debug, Console, 2 x Application Insights and my DummyProvider.
  • When using the IStartup implementation, there were just the four loggers – DummyProvider was missing.

So somehow, the logging factory instance in my Startup class is not the one that makes it to the controller.

The Correct Way to Access the Logger Factory

OK, so the constructor approach does not work. It then dawned on me – is there another way to get to the ILoggerFactory instance through the IApplicationBuilder that is provided via the IStartup.Configure(IApplicationBuilder app) method?

In short, yes! The app.ApplicationServices provides access the the IServiceProvider container where we can resolve services.

I ran the test again, and there was the DummyLogProvider.

Problem solved.!

Related

Bir Cevap Yazın

E-posta hesabınız yayımlanmayacak. Gerekli alanlar * ile işaretlenmişlerdir

TOP