periodic packet loss with new if_pppoe backend + high interrupts (post CE 2.8.0 upgrade)

eldest

The plot thickens. I was able to catch the system in the state of high cpu usage prior to losing internet:

last pid: 38892;  load averages:    2.65,    2.53,    2.46  up 1+09:32:04    07:38:38
316 threads:   6 running, 292 sleeping, 17 waiting, 1 lock
CPU:  0.7% user,  0.9% nice,  6.6% system,  0.3% interrupt, 91.5% idle
Mem: 196M Active, 837M Inact, 993M Wired, 1778M Free
ARC: 281M Total, 92M MFU, 170M MRU, 50K Anon, 2058K Header, 16M Other
     221M Compressed, 606M Uncompressed, 2.74:1 Ratio
Swap: 1024M Total, 1024M Free

  PID USERNAME    PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
   11 root        187 ki31     0B    64K CPU3     3  32.6H 100.00% [idle{idle: cpu3}]
   11 root        187 ki31     0B    64K RUN      1  32.4H 100.00% [idle{idle: cpu1}]
   11 root        187 ki31     0B    64K CPU0     0  32.3H  99.56% [idle{idle: cpu0}]
10039 unbound     -56    0    92M    60M RUN      2 280:19  66.80% /usr/local/sbin/unbound -c /var/unbound/unbound.conf{unbound}

It starts with unbound at extremely high usage, then slowly degrades from there. No anomalies in the DNS resolver logs. In fact, the only warning I can see in logs at all is from KEA:

WARN [kea-dhcp4.dhcpsrv.0x4db1bc12000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled.

WARN [kea-dhcp4.dhcp4.0x4db1bc12000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first.

Maybe this is the issue described in this post:

https://forum.netgate.com/topic/197613/pfsense-ce-2-8-0-kea2unbound-causes-high-cpu-load-even-when-dns-registration-is-disabled? Same CPU and similar symptoms.

stephenw10

Do you have pfBlockerNG enabled with a bunch of DNS-BL lists? That can cause a problem.

If you do then try using Python mode in pfBlocker. That would prevent it.

That's unrelated to if_pppoe though. Maybe it just a coincidence?

eldest

@stephenw10 I do have pfblocker installed but DNSBL is disabled. Is it possible wan events are triggering DHCP lease renewal causing kea2unbound to cause the same issues in the post linked previously? It's an awesome coincidence that it's the same hardware and same issue.

stephenw10

Mmm, it is. And I hate coincidences.

How many DHCP leases do you have? What lease time?

To hit that issue it has to see a renewal rate that eventually exceeds the reload rate that Unbound can manage. Which seems unlikely on that hardware.

eldest

@stephenw10 I just checked. 11 leases, default lease time of 7200 seconds. I haven't changed my network topology or devices since the upgrade so I don't think I'm getting anywhere near the reload rate limit.

stephenw10

Mmm, yeah that's nothing on that hardware.

Does Unbound log a bunch of restarts in the DNS log when it happens?

eldest

@stephenw10 nothing at all in the logs. I've now tried all permutations of KEA/ISC, if_pppoe and original and I'm running into the same issue so this is a mystery that no longer aligns with the title of this post. Moving off if_pppoe only seems to prolong the time before the crash. I tried a fresh install last night and restore of the config - saw the same system lockup within 10 hours. The symptoms are now very consistent and I can catch the system in this locked state. Unbound first consumes a core and all devices lose internet access. Then the large traffic flow appears from WAN according to the monitoring graphs.

stephenw10

Hmm. So how do you have Unbound configured? There's got to be something it's doing that most people don't hit.

You could try turning up the logging in Unbound.

Is it accidentally listening on WAN? Are you being used as part of a DNS amplification attack maybe?

eldest

@stephenw10 I'll try increasing the log verbosity - I've actually never touched the unbound settings so they should be default.

I surely hope it's not some sort of attack - these problems coincide to within a few hours of upgrading from 2.7.2 -> 2.8.0 and also occur on a fresh install using the installer.

Is there anything you suggest I do while the system is locked up in this state to get some more information? I'm returning home to the system in this state right now and I can occasionally reach the gui.

stephenw10

Check the Unbound Status page (Status > DNS Resolver). Compare those values when this is happening and normal running.

But if you turn up the logging you would see some huge flood of requests if that's what's happening.

eldest

@stephenw10 Its currently stuck in this state, and this is all I see in DNS Resolver status (no data):

After a reboot I see this:

stephenw10

Hmm, so it can't pull stats data from Unbound at that time. It must be very highly loaded.

I would try turning up the logging. It will probably create a very large ammount of logs.

You could also check the states or run a packet capture to try and see what the traffic spike is.

Also check the number of states shown in the monitoring graphs. Does that also spike at the time?