Daily Driving CachyOS - Local Services Woes

It was DNS!

Wow - that's a long time between posts!

So I've been daily driving CachyOS for a few days now, and on the whole it's been pretty good - easy setup, runs (mostly) stably on my Mid-2010 Mac Pro, an I can even play my Steam / Epic games on it!

Then I tried to open my UniFi controller at unifi.my-home-domain and both Firefox and Chromium refused to find it.

The odd part - dig resolved the name perfectly, and my MacBook Air on the same network opened the page without complaint. Everything in my homelab sits behind an HAProxy reverse proxy, with a pair of Pi-holes serving local DNS records for services like UniFi.

There's an old sysadmin haiku: It's not DNS. There's no way it's DNS. It was DNS. I spent most of an evening proving it right.

Suspect #1: the browsers' own DNS

Modern browsers love to bypass the system resolver. Firefox's "Default Protection" DNS-over-HTTPS will happily send your lookups to Cloudflare, which knows nothing about your Pi-hole's local records. Chromium has Secure DNS and its own async resolver too.

So I switched them all off:

• Firefox: Settings → Privacy & Security → DNS over HTTPS → Off (or network.trr.mode = 5 in about:config)
• Chromium: Settings → Privacy and security → Security → Use secure DNS off, and cleared the host cache at chrome://net-internals/#dns

No change. Both browsers still couldn't find the host. Worth ruling out, but not our culprit.

Suspect #2: IPv6 (a detour)

Next theory: the CachyOS box was picking up IPv6 DNS servers from router advertisements that didn't point at the Pi-holes. That sent me off giving the Pi-hole hosts static ULA addresses (fd12:3456:789a:1::53 and friends) and pointing the UniFi IPv6 DNS settings at them.

When that got fiddly, I took the blunt route and disabled IPv6 on the client entirely:

sudo nmcli con mod "<conn>" ipv6.method disabled
sudo nmcli con up "<conn>"

Still broken. In hindsight IPv6 was involved, just not the way I thought.

Meet 127.0.0.53

dig was reporting SERVER: 127.0.0.53#53, which is not one of my Pi-holes. It's the stub listener for systemd-resolved, running locally on the CachyOS box:

$ sudo ss -lunp 'sport = :53'
UNCONN 0 0 127.0.0.54:53     0.0.0.0:* users:(("systemd-resolve",pid=465,fd=24))
UNCONN 0 0 127.0.0.53%lo:53  0.0.0.0:* users:(("systemd-resolve",pid=465,fd=22))

$ cat /etc/resolv.conf
# Generated by NetworkManager
search my-home-domain
nameserver 127.0.0.53

$ grep ^hosts /etc/nsswitch.conf
hosts: mymachines resolve [!UNAVAIL=return] files myhostname dns

So every lookup on the box goes through resolved. dig talks to its stub over DNS. The browsers call glibc's getaddrinfo(), which hits resolved through the resolve NSS module and, thanks to [!UNAVAIL=return], never falls back to anything else.

resolvectl status showed resolved forwarding to both Pi-holes (192.168.1.53 and 192.168.1.54). Same resolver, same upstreams. So why did one path work and not the other?

The smoking gun

The answer came from asking for one address family at a time:

$ resolvectl query -t A unifi.my-home-domain
proxy.my-home-domain IN A 192.168.1.80   -- link: enp10s0

$ resolvectl query -t AAAA unifi.my-home-domain
unifi.my-home-domain: resolve call failed: ... does not have any RR of the requested type

$ getent ahosts unifi.my-home-domain
$                                      # nothing at all

$ curl -sv -o /dev/null https://unifi.my-home-domain/
*   Trying 192.168.1.80:443...
< HTTP/2 200

unifi is a Pi-hole CNAME to the box where HAProxy lives  (proxy.my-home-domain). That host had an A record but no AAAA record.

• dig and curl only asked for A records (curl, because IPv6 was off on the box), so they got an answer.
• getent ahosts and the browsers ask for IPv4 and IPv6 in a single call. The AAAA half came back empty, and resolved failed the whole lookup rather than returning just the IPv4 address.

The Mac's resolver queries A and AAAA separately and uses whichever comes back, which is why it never noticed.

The fix

I gave every CNAME target an AAAA record, so both halves of the lookup succeed. In each Pi-hole, under Settings → Local DNS → DNS Records, I added a ULA address for each homelab host that services are CNAMEd to. For example, proxy.my-home-domain → fd12:3456:789a:1::80. It has to go on both Pi-holes, because resolved will happily ask either one.

Use stable addresses: I gave each host a static ULA. The MAC-derived EUI-64 SLAAC address would also work, but not the temporary privacy addresses, which rotate.

Then flush and check:

resolvectl flush-caches
getent ahosts unifi.my-home-domain

getent returned addresses, and Firefox and Chromium both opened the controller straight away. With that sorted, I turned IPv6 back on for the client.

There were two other ways out, if adding AAAA records doesn't suit you:

• Replace each CNAME with a plain A record pointing at the HAProxy box.
• Change nsswitch.conf to hosts: mymachines files myhostname dns, so glibc's classic DNS client handles A and AAAA separately. This is a per-machine hack, and a package update may undo it.

Lessons learned

The big one: dig working proves very little on a systemd-resolved box. dig asks for one record type. Your applications ask glibc for every address family at once, and glibc goes a different way to get them. Always test the way your applications resolve.

The second: if you CNAME local services to a host, make sure that host has both A and AAAA records, on every Pi-hole you run.

Diagnostic cheat sheet

Command	What it tells you
getent ahosts <name>	What glibc, and so your browsers, actually get. Test with this, not dig.
getent ahostsv4 <name>	IPv4-only lookup. If this works and ahosts doesn't, suspect AAAA.
resolvectl query -t A <name> / -t AAAA	Each record type through resolved, separately.
resolvectl status	Which upstream servers resolved is using, per link.
resolvectl flush-caches	Clears cached negative answers between tests.
dig @<pihole-ip> <name> AAAA	What a specific Pi-hole returns, bypassing resolved.
grep ^hosts /etc/nsswitch.conf	Whether the resolve NSS module is in the path.
chrome://net-internals/#dns / about:networking#dns	The browsers' own view of DNS, plus cache clearing.

It was DNS. It's always DNS.

Thursday Quickie: Fixing NCrunch for Azure Functions

So I'm a big fan of NCrunch - Remco Mulder's continuous testing plug-in for Visual Studio.

I'm not a true adherent to TDD, so I find it really helps in ensuring that you've got proper coverage of my code, particularly of conditionals, and pushes me to write more tests generally. All good.

But it doesn't (yet) support Azure Functions projects properly - the post-build oddities of Functions project just don't play well with NCrunch.

However, there's a pretty easy fix that seems to work the majority of the time.

Just add the following to the Azure Function project .csproj file:

<PropertyGroup Condition="'$(NCrunch)' == '1'">  

    <ExcludeRestorePackageImports>true</ExcludeRestorePackageImports>

</PropertyGroup>

Pretty simple. 

Thanks have to go to Clement on the NCrunch Forums for this fix.

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;
        }

        [FunctionName("MyFunctionName")]
        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! 

Seemples!

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 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 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?

WRONG!

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 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:

KUBECONFIG=c:\users\joel\.kube\config

Restart your powershell instance and try again... Simple. (see also this issue in github)

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=4.1.1.2, 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 4.0.0.0 reference, then successfully loaded 4.1.1.3 from the app directory (the one from the NuGet package I referenced).

But when it was trying to load 4.1.1.2 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"?>

<configuration>

  <runtime>

    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">

      <dependentAssembly>

        <assemblyIdentity name="System.Net.Http" publicKeyToken="b03f5f7f11d50a3a" culture="neutral" />

        <bindingRedirect oldVersion="0.0.0.0-4.2.0.0" newVersion="4.1.1.2" />

      </dependentAssembly>

    </assemblyBinding>

  </runtime>

</configuration>

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!