Tuesday, October 22, 2019

Tuesday Quickie: ILogger in Azure Functions done right

So we had a discussion at work yesterday about how to use ILogger from Microsoft.Extensions.Logging in our Azure Functions v2 projects.

All the samples have a hang-over from the v1 days where the function method takes an ILogger as a method dependency. I asserted that a cleaner way would be to have ILogger as a class-level dependency, injected via the constructor.

The only problem was that it didn't work - the MSDI wasn't resolving ILogger when constructing our functions class.

namespace MyFunctionApp
    public class MyFunctionClass
        private readonly ILogger logger;

        // DOESN'T WORK!
        public MyFunctionClass(ILogger logger)
              this.logger = logger;

        public async Task<IActionResult> MyFunctionMethod(
            [HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = null)]
            HttpRequest req,
            ILogger log) // WORKS!

A bit of a proof-of-concept later and I found the trick - use ILogger<T> as the constructor dependency - where T is the class that owns the method.!

    public class MyFunctionClass
        private readonly ILogger logger;

        // WORKS!
        public MyFunctionClass(ILogger<MyFunctionClass> logger)
              this.logger = logger;

But why? 

What's going on is that the Azure Functions v2 runtime sets up the DI to serve an ILogger when method-injection is used, but not for constructor injection. For constructor injection the runtime has set the DI to serve up only ILogger<T>.

Looking at the differences between the loggers that the two DI methods return, we can actually make sense of why the behaviours are different.

The ILogger returned for method injection is configured with the category "Function.MyFunctionName.User".

The ILogger<T> returned for constructor injection, however, gets a category of "MyFunctionApp.MyFunctionClass" instead. 

The Azure Functions v2 runtime is building a logger based on the FunctionName attribute for method injection - it's a special case hangover from v1!

So to get hold of an ILogger in your function class using constructor injection, you just need to ask for an ILogger<MyClass> instead! 


Update - 2019-11-05:

So I missed out a rather important part of this post... the pattern above is lovely, but it doesn't work

None of the logging to ILogger<MyClass> instances appear in Application Insights - but logging from the Azure Functions v2 runtime itself does.

Actually the problem isn't the pattern above at all, but another nasty little Azure Functions v1 hangover that Microsoft hasn't fixed yet.

By default, the Azure Functions v2 runtime filters out any logging that's not from the runtime itself, or from ILogger instances that the runtime provides (with the "Function.MyFunctionName.User" style category).

The fix is easy - but irritating. Add logging configuration to your
host.json file, thus:

  "version": "2.0",
  "logging": {
 "logLevel": {
   "MyFunctionApp": "Trace"
There's an issue that was openned on GitHub in April 2019 about this ( https://github.com/Azure/azure-functions-host/issues/4345 ), so I assume Microsoft will get around to removing the filtering at some point.

Thursday, May 16, 2019

Thursday Quickie: IoC Registrations done wrong broke my DbContext

TLDR: Using InjectionConstructors in Unity can give you singletons. Beware! (and TEST!)

So our tester at work spotted some InvalidOperationExceptions being logged from our data access library recently indicative of a DbContext being re-used across requests... 

Digging into the registration showed quite a few instance of this sort of code:

container.RegisterType<IService, ServiceImplementation>(
    new TransientLifetimeManager(),
    new InjectionConstructor(new Dependency()));

Spot the mistake?

Passing an InjectionConstructor into RegisterType to specify which constructor on the ServiceImplementation class to use is fine... 

Except that passing new Dependency() to the InjectionConstructor does not indicate that a new instance of the Dependency type should be created for each resolution of IService... instead it creates a singleton instance there and then that's subsequently shared across all instances of the IService. Which is bad.

Of course, for DBContext dependencies this is particularly bad - and is the source of the InvalidOperationException that was detected. It's an easy mistake to make, but one that's really hard to spot until you see those exceptions being logged.

The solution - use InjectionConstructor as it's intended:

container.RegisterType<IService, ServiceImplementation>(
    new TransientLifetimeManager(),
    new InjectionConstructor(
        new ResolvedParameter<Dependency>()));

The ResolvedParameter clause says clearly that you're letting the container decide on the lifetime of Dependency.

For bonus points - and to prevent regressions - write tests that verify both that your composition root / container bootstrapper registers types with the correct lifetimes, and that where you've got DBContexts involved that you get a separate DBContext instance when you resolve two instances of IService.

Whilst the above is specific to the Unity IoC framework, you can be sure that all IoC frameworks will have a similar gotcha - so watch out for your registrations!

Tuesday, April 09, 2019

Tuesday Quickie: When closure bites (or how not to configure Newtonsoft.Json)

TLDR: Be very careful using captured closures and anonymous methods - they can leak memory when you don't expect. Also copy-and-paste code is bad.

So yesterday we had an issue where a long-running service within our platform suddenly started throwing StackOverflowExceptions with a new version. It was a blocker to the next release, so inevitably I got tasked with fixing the issue.

A quick profile of a locally running copy replicated the error (phew!) and pointed to one of our HTTP based service clients being at fault. This was confusing, as those components hadn't changed. 

But what had changed was how those clients were being used - previously, they had accidentally been injected from the IoC container as singletons - now they were being injected as transients.

So why would the stack overflow?

It turns out that the service clients all had copy-and-paste code used to ensure that a custom JSON converter was added to the default JSONSerializerSettings used by the Newtonsoft JSON library, and that code was leaking memory and ultimately causing the StackOverflowException

But how? Here's the old code:

Pretty straightforward - and a static method in a static class shouldn't leak?


On lines 8 and 9 we're capturing a closure (defaultSettings) and then using that within an anonymous method that we're assigning back to JsonConvert.DefaultSettings

Because of the captured closure, the compiler couldn't make the anonymous method truly static - so you get a new instance every time the helper method is called - and those instances are pinned (again because of the captured closure) so that they can't be garbage collected.

Since this helper was being called every time a service client was being instantiated, and the clients were no longer singletons, the profile was showing tens of thousands of instances in memory of Func<JsonSerializerSettings>. Not good.

The solution is to be rather more defensive in adding the converter. Here's the corrected version:

We create our own default JsonSerializerSettings instance and a genuinely static Func<JsonSerializerSettings> helper method on lines 7 & 8.

If JsonConvert.DefaultSettings is null, we assign that helper (within a double-checked lock for safety) on line 18.

Finally, we use whatever helper factory was assigned to get the default JsonSerializerSettings instance (line 23) and add our converter if needed - again within a double-checked lock (line 32).

Re-running the repro resulted in exactly 1 instance of Func<JsonSerializerSettings> being created - and our bug is fixed.

The moral of the story? Watch out for anonymous methods and captured closures - they can bite! 

Friday, March 22, 2019

Friday Quickie: Fixing Kubernetes connectivity with Docker for Windows

Another aide-memoire - when using kubectl on Windows against Docker for Windows you get the following error:

Unable to connect to the server: dial tcp [::1]:8080: connectex: No connection could be made because the target machine actively refused it.

This might well just just be that the tool can't find it's config... and the fix is easy - just set an environment variable:
Restart your powershell instance and try again... Simple. (see also this issue in github)

Thursday, February 14, 2019

Thursday Quickie: When AssemblyBinding redirect doesn't... and how I fixed it

TLDR: If your csproj file has AutoGenerateBindingRedirects set to true, then you MUST include the xmlns on the assemblyBinding node for any custom binding redirects in app.config.

So I've been banging my head against the wall trying to get a piece of code delivered over the last few days, and kept hitting an issue where code runs perfectly locally, but when deployed to the target server was failing with the dreaded error
Could not load file or assembly 'System.Net.Http, Version=, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a' or one of its dependencies. The located assembly's manifest definition does not match the assembly reference. (Exception from HRESULT: 0x80131040)

I'd used Gertjan van Montfoort's excellent article as a guide, but whatever version of the NuGet package I installed, and whatever version I referenced in my binding redirects in app.config, it just would not fire up.

Looking at the Fusion logs (helped by Scott Hanselman's article) I could see that my app was initially loading System.Net.Http from the GAC for a reference, then successfully loaded from the app directory (the one from the NuGet package I referenced).

But when it was trying to load because of other dependencies Fusion was not honouring the binding redirect, and so the app was failing on startup.

Finally I found a comment on the net that hinted about case sensitivity within the app config, so I went looking for differences between my custom redirects and those generated on build into MyApp.exe.config.

And I found one - the generated redirects all have an xmlns attribute on the assemblyBinding node - and my custom one did not

The solution - add one in your app.config

<?xml version="1.0" encoding="utf-8"?>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
        <assemblyIdentity name="System.Net.Http" publicKeyToken="b03f5f7f11d50a3a" culture="neutral" />
        <bindingRedirect oldVersion="" newVersion="" />

Now your binding redirects get merged with the generated ones and it all works.

My interpretation is that Fusion appears to honour the redirects in assemblyBinding nodes only if all have xmlns attributes or none have them - but not if mixed. 

Hopefully others will find this useful - now I can get on and do some actual work!

Wednesday, June 06, 2018

Honey, I shrunk `ConfigureServices()`

The problem with all DI systems is that configuration generally is pulled in two polar-opposite directions. Either your container is configured by convention (with a few rare exception cases), or it's configured directly and declaratively with masses of registrations.
The latter configuration practice has the benefit of not having any side-effects as you bring in third party libraries - you'll not get random Controller classes added to your system, for example. And this is why it's my preference.
BUT, declaring every dependency in your container can lead to the dreaded "God Configuration Method" - where one method has hundreds of lines of container registration. This bad - it couples your application tightly to all dependencies at all levels, and makes it hard to maintain.
For the last few years, I've been using a discovery system for Unity that moves the registrations for dependencies away from the "God Configuration Method" and into individual "Bootstrappers" that live alongside the implementation of the service that they register.
This "magic" discovery pattern works well - reducing the "God Configuration Method" to a single line - and allowing (for example) client libraries to define the "right" lifecycles themselves, not relying on a programmer getting it right each time they use the client.
Today, I'm releasing an experiment - a port of "magic" bootstrapper discovery for ASPNet Core and the Microsoft DI framework.
It might be useful - it's certainly simple enough to use. The experiment is to see what sort of take-up it gets.

Note: I added the "magic" extensions under the Microsoft.Extensions.DependencyInjection.Discovery namespace deliberately.


Using the discovery library is simple. First install the NuGet package:
install-package CheviotConsulting.DependencyInjection.Discovery
Next, where previously you would add registrations into the Startup.ConfigureServices(...) method, you write a IServiceDiscoveryBootstrapper implementation
using Microsoft.Extensions.DependencyInjection;

public sealed class WebAppServiceBootstrapper : IServiceDiscoveryBootstrapper
        public void ConfigureServices(IServiceCollection services)
            services.AddTransient<IWebAppService, MyWebAppService>();
You can have as many of these as you like, in as many referenced projects as you like - which allows you to put a service registration alongside a service or service client itself.
Then in the Startup.ConfigureServices(...) method, you add the following single line:
using Microsoft.Extensions.DependencyInjection.Discovery;

public class Startup
    // This method gets called by the runtime. Use this method to add services to the container.
    public void ConfigureServices(IServiceCollection services)
And that's it. The discovery framework will load any assemblies referenced by your application, find all IServiceDiscoveryBootstrapper instances and execute the ConfigureServices(...) method on each in turn - bootstrapping the IServiceCollection used by ASPNet Core / Microsoft.Extensions.DependencyInjection.

Advanced Usage

Bootstrapper Dependencies

Unlike the Startup.ConfigureServices method, you can't pass dependencies in the method parameters. However, by default the bootstrapper classes themselves are resolved using the IServiceCollection as it stands just before the call to BootstrapByDiscovery() is made. So you can use constructor dependency injection in your bootstrapper.
public sealed class SampleServicesBootstrapper : IServiceDiscoveryBootstrapper
    private readonly IHttpContextAccessor contextAccessor;

    public SampleServicesBootstrapper(IHttpContextAccessor contextAccessor)
        this.contextAccessor = contextAccessor;

    public void ConfigureServices(IServiceCollection services)
        services.AddSingleton<MyCustomService>(new MyCustomService(contextAccessor));

Manual Bootstrapping

If you don't want to rely on the "magic" discovery, you can always bootstrap each of your bootstrappers individually within your Startup.ConfigureServices(...) method.
public class Startup
    // This method gets called by the runtime. Use this method to add services to the container.
    public void ConfigureServices(IServiceCollection services)

        // Bootstrap services manually
        services.BootstrapFrom(new WebAppServiceBootstrapper());

Tuesday, April 24, 2018

DDDSW 2018 - Retrospective

So it's now the Monday after the Saturday before and I've had time to chill and think back on the excellent event that was DDDSW 2018.

Held in the Redcliffe Sixth Form Centre again, my day started early as I was driving down and back in the day. Fortunately the M4 was clear and in spite of the roadworks around Bristol Temple Meads, I rolled into the car park just after 0830.

Once again, Landmark was sponsoring the Cream Teas, so I was able to bag a sponsors parking space behind the building (thanks Ross) and get the goodies in via the back door.

Setting up the Landmark stand-up and handing the box full of goodies for the delegate bags took but moments, and then it was up to the Speaker Room to do a quick run-through and check connectivity via my phone. 

I was scheduled for Track 5 just before lunch, so I would have had plenty of time to prepare had I needed it - as it was I could chat and catch up with old friends.

Speaker Briefing was followed by the usual intro and housekeeping talk in the main room. It was really good to see a strong turnout again too, right from the start

With these over, it was off to the sessions - and first up was one that was really just for me with no real bearing on my day-to-day job (tho' I've got a few ideas now).

Session 1 - Unity 101 with Andy Clarke

I was interested with this as I'd played a little with Unity 3d already, but hadn't really got past attaching standard behaviours to pre-fabs. Andy started simply with an intro to the product (used for everything from simple 3d games up to Neill Blomkamp's "Adam" series of shorts. He then gave a quick once over of UI (and the left-hand-coordinate-system), and soon had balls rolling and boxes bouncing off each other as they spun.

Next up was "Tank Dominoes", using pre-fabs from the Unity Store to indulge in a bit of monolith-toppling. 

With a tank. 😁 

It was only a shame that Andy's laptop refused to play the sound effect of the explosion.

Then Andy demonstrated the Inverse Kinematic Skeleton system available with a humanoid model.

By the end he had a two-player networked sample running where the characters could pass a batton between each other. The amount of code required - or rather the lack of it - is a real testament to what a powerful authoring environment Unity is.

Thoroughly enjoyable, Andy's talk will give me a good head-start against my 11 year old who wants to try Unity himself for game development (Scratch is so Junior School, apparently).

Session 2 - "Give it a REST - Tips for designing and consuming public APIs" with Liam Westley

You've got to give it to Liam - a day or so before DDDSW he'd been knocked off his bike (and had possibly broken a bone in his wrist), but that didn't stop him giving a polished presentation on the good, the bad and the ugly sides of public facing APIs.

Liam explaining (with video) his cycling accident
Liam started by describing some of the history and development of RESTful best practice - and how HATEOAS was a crucial upcoming technology. REST is not CRUD, and HATEOAS is a REST constraint, not an independent thing.

He described how Google ReCaptcha was exceptionally clever when deprecating service versions by using canary deployments to show a message designed to get users to prod web site owners to upgrade.

Versioning came under the microscope - here be dragons - as did effective patterns for genuinely asynchrons operations using HTTP 202 Accepted and a HATEOAS response payload.

Liam finally explained how a public API is effectively a contract between owner and user, and needs to be handled as such if you don't want to hack your users off.

Lots of good stuff to take back to work here, although I'm not sure I captured it all in my "sketchy" notes.

Next up was my own talk.

Session 3 - Azure in Action: CosmosDB, Functions and ServiceBus in perfect harmony

I'd had a humbling experience submitting this year - not one, but two talks accepted for DDDSW, with absolutely identical numbers of votes! I could only do one, so I'd decided to do my Azure talk rather than the soft-skills one.

Paraphrasing my own blurb, there's so many parts to Azure, it's sometimes hard to decide what to use and when. Do I use TableStore or CosmosDB? Would BlobStore be better? Should I host a full-fat .Net service in a VM, or stand up an ASP.Net Core WebApi? What about functions? The choices are myriad. 

Speaker's Eye View

I described how at Landmark we made these kind of decisions as we implemented some new features in our product. I talked about the questions you need to ask to make those decisions, where we went wrong, and how we succeeded in the end. 

Finally I described in detail how we used CosmosDB, Azure Functions and Service Bus together to provide a Compliance Audit trail feature that would scale properly, work reliably, be trivial to use, and that wouldn't break the bank, using a complete end-to-end sample code-base, lifted-and-shifted from the code we wrote at Landmark.

For a first outing, I'm really pleased with how this went - the slides gave the background and context I wanted, and the code demos pretty much all worked perfectly. 

Certainly the questions asked by the audience and the feedback I've received has been great. Thanks all.

It's been great to have such support from Landmark too - allowing me to effectively open-sourcing our Compliance Audit framework as the reference implementation to go along with this talk.

Once again, Ian Johnson captured the essence in one of his legendary sketchnotes - thanks, Ian!

For the curious, the slides and code are all available online:

After the obligatory pastie lunch (sponsored by Dyson this year), punctuated with interesting conversations as always, it was on to the next session:

Session 4 - "What's That Smell" with Anthony Dang

Anthony's session was an entertaining review of a series of "gotcha's" he's experienced in a Digital Agency environment, specifically when taking on other people's projects. 

Whilst focused a little on Umbraco (The CogWorks is an Umbraco Gold Partner), his advice is applicable to anyone scratching their head about web application performance.

One thing that jumped out at me was his suggestion that the simple act of turning off all caching can actually improve performance, and certainly show up the real underlying issues. It's all to easy as a developer to over-use (or over-engineer) caching in your application and bring in all sorts of un-testable issues.

Another break, more coffee, more chat and most importantly the Cream Teas (sponsored by Landmark). 

I was good and only had a couple. Really.

Then it was time for

Session 5 - "Lessions learned - ingesting, processing and securing 200 million messages / day" with Jess Panni

This was probably the talk most relevant to my day-to-day job, and boy did Jess deliver.
Jess described how Endjin ingest Radius data via a UDP-listener service, and pipe this to Azure Data Lake via Functions. He described the "Swiss Cheese" model of providing more and more security along the pipeline, how Shared Access Signature Tokens provide better security than Shared Access Policies (at the expense of somewhat more complicated code flows), particularly when used with Key Vault.

Jess also demonstrated how a "2-key launch control" could be implemented for software - requiring two independent operators to start an update to a system.

Finally, he showed how Azure Data Lake Analytics are used to process the 200 million events into useful data points for reporting and monitoring using uSQL.

All in all, a really interesting - and very fast paced - talk to finish up the day before the final wrap up and swag.

Wrap up and swag

Afterwards, it was off to Just Eat towers for more chat over beer and pizza - although I had to forgo both as I was driving home. 😞

All credit has to go to the DDDSW team - another excellent event this year - and to all the attendees and speakers who made it a great day.