Three Bugs Wearing One Trench Coat

For about four months, DNS on my network died in ways that didn’t make sense. Sometimes after a reboot, sometimes during config changes, or sometimes at 4 AM with nobody touching anything. Each incident got diagnosed, fixed, and written up, and the outages kept coming, which should’ve rung the bell that something major was wrong.

After four months, this should be a difficult bug. Disappointingly, it turned out to be at least three. There was a hardware fault, a multiplier in my configuration, and a recovery command that planted impostors. The hardware fault forced the configuration, and the configuration widened a race window. On top of that, my recovery command kept planting more. Fixing one of them didn’t fix the issue.

Some background from the lab writeup. The firewall runs pfSense with Unbound as a recursive resolver for the whole network, and a DNS blocklist of roughly 534,000 entries sits in front of resolution. Every device in the house depends on this one daemon. When it dies, the internet is down.

Bug one: the port that wouldn’t hold a link

The first incident cluster traced to hardware. One of the two 10G ports on the firewall’s NIC developed a link flap condition which made the port go up, down, up, down. It’s all over the console, link state changing through the login loops:

I moved the trunk to the surviving port, flap detection got tuned on the switch side, and the link has been solid since. Case closed.

Except link flaps on a firewall aren’t just a connectivity issue. Every interface event on pfSense fires hooks, and some of those hooks restart services, the resolver included. When the port was flapping, Unbound was being restarted by pfSense.

The flap also forced the blocklist integration to reload constantly. The blocklist has two modes, and the modern python module mode kept failing into a reset loop under the restart churn, so I went to ole reliable, the legacy mode, the one that caused the second bug. The port swap fixed the churn, and I left legacy mode in place for another three or four months, because it was “the config that works”, and the failed python attempt had become “the thing that doesn’t.” Both labels were artifacts of a hardware fault that no longer existed, and I never went back to try again.

Bug two: the multiplier

A resolver restart should be harmless, a couple of seconds of cached lookups falling through. Mine wasn’t, because of how the blocklist was setup. In the legacy integration mode, all ~534k DNSBL entries are compiled into the resolver’s own config as local zones, which means every single restart re-parsed and re-loaded the entire list, which took about 27 seconds of CPU before the resolver answered its first query, and the resolver sat at about 1.3GB of memory once it was up.

Even worse, the integration reloads on every config save. Saving an unrelated firewall setting fires a “restarting DNSBL” cascade. Two saves close together produce overlapping reloads, and overlapping reloads were the reliable way to wedge the resolver into a state where it held port 53 and answered nothing.

The arithmetic here took me months to do. On boot, pfSense’s rc starts Unbound, and an interface event hook fires a second start roughly 25 seconds later. With legacy mode’s 27-second initialization, that second start lands inside the first one’s startup window on nearly every boot. Sometimes the survivor came up serving, and often it didn’t, and my experience of that was rebooting the firewall two or three times to end up with a resolver that answered.

Reboots were not rare, because my ISP line was dropping constantly that spring (upstream transmit power pinned above spec, a separate saga), and my standing remedy for a dead WAN was rebooting the firewall. Every one of those reboots re-ran the race.

Bug two broke nothing alone, it multiplied. Every restart from any source became a 27-second outage with a wedge risk attached, and the boot race went from unlucky to near-certain.

Bug three: the right service, the wrong command

Here’s the one that took four months, and it fit in a single shell command.

pfSense manages Unbound with its own configuration at its own path. But the underlying FreeBSD package also ships a standard rc script, and that script knows nothing about pfSense. So when the resolver was down and I did the obvious thing:

service unbound onestart

It started an Unbound instance, just not mine. The stock rc script launches the package resolver with the package’s default config, bound to localhost only, no blocklist, none of my settings. From the shell it looks like a successful recovery. From the LAN, DNS is still dead, because the thing answering on 127.0.0.1 isn’t listening anywhere else.

The status check made it worse. It went through the same rc script:

service unbound onestatus

and onestatus reads the package’s pidfile, which the real pfSense-managed instance never writes. So it lied in both directions. It reported impostor instances as a healthy running service, and it reported the genuine resolver as not running even when it was serving the whole network. Every diagnostic I ran through that command returned an answer about the wrong daemon.

Another time I caught the third bug, from March 24th, months before any of this was understood. My recovery ritual runs onestart, sockstat shows the resulting resolver bound to loopback only, and onestatus vouches for it:

Every address in that sockstat output is the impostor’s signature, and I screenshotted it that morning believing it showed a successful fix.

In June, the console scrollback shows the old instance dumping its shutdown stats and the new one logging start of service, and one prompt later onestatus reports it not running. That denial is how you spot the real one. An impostor writes the package pidfile, so onestatus vouches for it. Only the real resolver gets reported dead while it’s visibly serving the network:

Beginning in April, if the resolver died for any reason my fix was to use service unbound onestart. That planted an impostor, a localhost only Unbound now squatting alongside whatever pfSense eventually starts, two daemons fighting over port 53, producing exactly the running but LAN dead symptom that triggers another recovery. Every attempted fix since April had been planting another impostor. My recovery command was the third bug.

The most Unbounds I’ve seen on one machine

Who doesn’t like a race? rc starts Unbound, a hook fires a second start ~25 seconds later, and legacy mode’s init window made the collision routine. The resolver log’s tell for it:

remote control failed ssl: Connection reset by peer

The reasonable fix was a boot time retry. Wait out the race window, check whether Unbound is running, start it if not. My first version checked with onestatus. Since onestatus reads a pidfile the real instance never writes, it reported it wasn’t running on every boot, and my retry dutifully ran the start command, and the start command it ran planted an impostor. On every single boot.

The corrected retry gates on the actual process with the actual config path, and starts through pfSense’s own machinery instead of the package script:

sleep 90; pgrep -qf "unbound -c /var/unbound/unbound.conf" \
  || pfSsh.php playback svc start unbound

The old retry was just wrong, it checked the wrong pidfile and started the wrong daemon. Not all my ideas are winners, clearly.

The audit

Untangling this for good took an evening of forensics rather than another fix. First, a storm as evidence. During recovery testing that weekend, the resolver started 200 times in 33 minutes, and the densest stretch ran 61 starts in eight minutes, averaging 7.9 seconds apart, as queued reload events killed each instance the previous event had just brought up, with my manual onestart recoveries adding impostors into the log. From the syslog archive, verbatim:

2026-08-02T11:20:41+00:00 daemon.info unbound: [53872:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:20:44+00:00 user.notice kea2unbound: Unbound fast reloaded: /var/unbound/unbound.conf
2026-08-02T11:20:50+00:00 daemon.info unbound: [53872:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:20:58+00:00 daemon.info unbound: [21298:0] info: start of service (unbound 1.25.1).
2026-08-02T11:20:58+00:00 daemon.info unbound: [21298:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:21:03+00:00 daemon.info unbound: [51462:0] info: start of service (unbound 1.25.1).
2026-08-02T11:21:10+00:00 user.notice kea2unbound: Unbound fast reloaded: /var/unbound/unbound.conf
2026-08-02T11:21:25+00:00 daemon.info unbound: [51462:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:21:31+00:00 daemon.info unbound: [51462:0] info: start of service (unbound 1.25.1).
2026-08-02T11:21:31+00:00 daemon.info unbound: [51462:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:21:38+00:00 daemon.info unbound: [23864:0] info: start of service (unbound 1.25.1).
2026-08-02T11:21:38+00:00 daemon.info unbound: [23864:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:21:45+00:00 daemon.info unbound: [67187:0] info: start of service (unbound 1.25.1).
2026-08-02T11:21:45+00:00 daemon.info unbound: [67187:0] info: service stopped (unbound 1.25.1).
2026-08-02T11:21:51+00:00 daemon.info unbound: [67187:0] info: start of service (unbound 1.25.1).
2026-08-02T11:21:51+00:00 daemon.info unbound: [67187:0] info: service stopped (unbound 1.25.1).

11:21:31 starts and stops in the same second. Then 11:21:38, same. Then 11:21:45, 11:21:51. Instances born and dead inside one log timestamp, four in a row, while the reload queue worked through its backlog.

Then the audit. Kill every Unbound on the box. List everything that could possibly start one, the rc scripts, cron, boot config, device event hooks, my own retry. Trace where each observed impostor had come from. Every one of them traced back to onestart, via manual recoveries and the broken first draft retry, and the boot infrastructure was clean. Reboot, and watch a clean boot. A single instance, 37 seconds from kernel to answering queries, no collision.

That clean boot mattered for an uncomfortable reason. By audit time, with impostors purged, the archive said clean boots were the norm and the race, absent its multiplier, was probabilistic rather than certain, while a number of incidents I’d confidently blamed on the race were actually impostors presenting as it. My multi-reboot mornings had been real, but they were the race and the impostors taking turns wearing the same clothes. I had been blaming all of it on one culprit. The lab writeup mentions the syslog archive settling arguments with my own incident notes. This is the saga it settled, and several of my reports lost.

The health check that came out of the audit asks the process instead of asking a status command that lies:

ps auxww | grep "unbound -c"     # must show -c /var/unbound/unbound.conf
sockstat -l | grep :53           # must show ONE pid, bound on *:53

The real resolver runs the real config path. An impostor shows the package path and a localhost bind. Two pids on :53 means two instances fighting for one port. drill @127.0.0.1 separates dead from alive but not serving. A wedged or impostor instance still answers on loopback, while the same query against the LAN address times out.

The recovery runbook got rewritten to match. A polite restart doesn’t work on a wedged or impostor instance, so the sanctioned recovery is blunt:

killall -9 unbound; sleep 3; pfSsh.php playback svc start unbound

Kill everything claiming to be the resolver, then start exactly one, through pfSense’s own machinery. One more decision came out of this that sounds backwards at first. Unbound is deliberately excluded from the firewall’s service watchdog feature. An auto-restarter that can’t tell a blocklist reload from a crash would fight the reload cycle and manufacture exactly the restart storms this whole saga was about.

Making restarts cheap

Now that the impostors were caught, bug two was still sitting there making every legitimate restart expensive, and the fix was migrating the blocklist integration to its python module mode, where the DNSBL lives in a module instead of being compiled into the resolver’s config. The same mode the flapping port had chased me away from at the start, working fine now, months after the reason for avoiding it had been unplugged. The before and after:

The boot race row is the important one. The race was never fixed in the sense of removing the second start; it was defused, because a 1.2-second initialization is finished and stable more than twenty seconds before the late start arrives. The multi-reboot mornings ended with the migration.

That last row is its own small lesson. For months, 1.3GB of resident memory was the signature of a healthy resolver, and after the migration the identical number means the python module failed to engage and the system has silently fallen back to the expensive path. After a config change it was the same number with the opposite meaning.

Four months later

This took four months because the three bugs cross covered for each other, which is also why it’s worth a writeup.

Fix the port, and the multiplier keeps every reboot expensive while the recovery bug keeps planting impostors, so the port fix looks like it didn’t take. Fix the boot race handling, and the fix plants more impostors. Every partial repair kept the symptom alive, which kept re-implicating the things already fixed. Instead of using bandaid logic, I decided to look for the root cause with log evidence, every starter mechanism audited, every theory checked against the syslog archive.

I wish I could say these bugs were easy to find, but the reality is this took me months. Even my recovery procedure had a bug in it, and recovery bugs hide behind the bug that caused the recovery. I left legacy mode in place long after the flapping port that forced it was gone, because I treated my firewall server like it was made of glass once it was up and running. I didn’t learn my lesson from this either. The backup audit found the same bug shape, success reported at one layer while the layer above went unmet.

The recovery machinery that grew out of all this, the watchdog ladder that reboots the box and once panicked the kernel, is its own writeup.