Stubby crashes when pihole cleanup is run via cron?

Using :

Pi-hole version is v5.8.1 (Latest: v5.8.1)
AdminLTE version is v5.10.1 (Latest: v5.10.1)
FTL version is v5.13 (Latest: v5.13)

and

Stubby 0.2.5 (upstream NextDNS)


  • Issue

Pihole dashboard says SERVFAIL for DNS queries
Internet is cut off (naturally due to DNS not resolving)
Stubby logs show this weird error :

Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.

Frequency : once every 2 days.

  • Fix : Restarting stubby daemon helps and DNS starts resolving.

Syslog in R-Pi :

Jan 13 14:39:24 raspberrypi systemd[1]: Starting Clean php session files...
Jan 13 14:39:25 raspberrypi systemd[1]: phpsessionclean.service: Succeeded.
Jan 13 14:39:25 raspberrypi systemd[1]: Started Clean php session files.
Jan 13 14:40:01 raspberrypi CRON[8740]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 14:50:01 raspberrypi CRON[8813]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 14:53:01 raspberrypi CRON[8851]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker remote)
Jan 13 14:56:11 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 14:56:11 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 14:56:11 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 14:56:11 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:00:01 raspberrypi CRON[8918]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 15:09:01 raspberrypi CRON[8987]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Jan 13 15:09:24 raspberrypi systemd[1]: Starting Clean php session files...
Jan 13 15:09:25 raspberrypi systemd[1]: phpsessionclean.service: Succeeded.
Jan 13 15:09:25 raspberrypi systemd[1]: Started Clean php session files.
Jan 13 15:10:01 raspberrypi CRON[9045]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 15:17:01 raspberrypi CRON[9105]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jan 13 15:20:01 raspberrypi CRON[9132]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 15:30:01 raspberrypi CRON[9209]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 15:35:09 raspberrypi rngd[404]: stats: bits received from HRNG source: 7880064
Jan 13 15:35:09 raspberrypi rngd[404]: stats: bits sent to kernel pool: 7827168
Jan 13 15:35:09 raspberrypi rngd[404]: stats: entropy added to kernel pool: 7827168
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2 successes: 394
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2 failures: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: HRNG source speed: (min=338.967; avg=512.547; max=535.954)Kibits/s
Jan 13 15:35:09 raspberrypi rngd[404]: stats: FIPS tests speed: (min=10.993; avg=12.881; max=31.371)Mibits/s
Jan 13 15:35:09 raspberrypi rngd[404]: stats: Lowest ready-buffers level: 2
Jan 13 15:35:09 raspberrypi rngd[404]: stats: Entropy starvations: 0
Jan 13 15:35:09 raspberrypi rngd[404]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jan 13 15:39:01 raspberrypi CRON[9279]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Jan 13 15:39:24 raspberrypi systemd[1]: Starting Clean php session files...
Jan 13 15:39:25 raspberrypi systemd[1]: phpsessionclean.service: Succeeded.
Jan 13 15:39:25 raspberrypi systemd[1]: Started Clean php session files.
Jan 13 15:40:01 raspberrypi CRON[9335]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:43:36 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:43:36 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:43:36 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:43:36 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:45:43 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:45:43 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:45:43 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:45:43 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:49:03 raspberrypi systemd[1]: Started Session c86 of user pi.

I tried running the same update commands mentioned in logs above and Stubby is not impacted.

Documentation for this error is present here | Under section GETDNS_RETURN_NO_SUCH_DICT_NAME

Is it caused by Pihole update cron or could be due to upstream provider?

I don’t know. Maybe you can check the status of stubby when the internet is down.

systemctl status stubby

You can add Restart=on-failure as here , if not present in /lib/systemd/system/stubby.service.

systemctl stop stubby
nano /lib/systemd/system/stubby.service
systemctl daemon-reload
systemctl start stubby

Thank you for the suggestion, I am going to try it and update in case it changes things for me.

Also, when the internet goes down, the stubby service show running but in the syslog and also in systemctl status check logs at the bottom I get the exact same string I mentioned in my post :

Jan 13 15:43:36 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.

At that time, all DNS queries show SERVFAIL in pihole panel.

I'm not following you here. What cleanup or update cron are you referring to?

I pasted the logs in the question, here are the lines :

Jan 13 14:40:01 raspberrypi CRON[8740]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 14:50:01 raspberrypi CRON[8813]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 14:53:01 raspberrypi CRON[8851]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker remote)
Jan 13 14:56:11 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 14:56:11 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.

And this :

Jan 13 15:39:24 raspberrypi systemd[1]: Starting Clean php session files...
Jan 13 15:39:25 raspberrypi systemd[1]: phpsessionclean.service: Succeeded.
Jan 13 15:39:25 raspberrypi systemd[1]: Started Clean php session files.
Jan 13 15:40:01 raspberrypi CRON[9335]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 13 15:41:27 raspberrypi stubby[19413]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.

Yes I had also checked that.

The response there mentions this :

Looks like a non-DNS message was received by your Stubby deamon. Downstream that is.

"Downstream that is" - Did they mean upstream?

I mean PiHole > Stubby > NextDNS (I would call NextDNS upstream).

Do they mean there is an non-DNS answer from whatever upstream is being used in this case NextDNS?

And how is it possible that a DNS server return non-DNS response?

From what I know, SERVFAIL / NODATA / NXDOMAIN / CNAME / A / AAAA are all DNS records only.

These are the major ones in my pihole logs, with some more, here is an imgur link.

Yes

Possibly, you'd have to ask to see.

Maybe it's not a DNS server responding but something else on the same port as Stubby.

You've confused a few things.

SERVFAIL, NODATA, NXDOMAIN are DNS server response statuses.

A, AAA, SRV, SOA.... are DNS record types.

You mention a cleanup process but the one shown in the logs is not Pi-hole, it's the operating system itself. It's doing PHP cleanup. And the timestamps show the php session cleanups are pretty far away from the times that stubby is generating it's messags.

I don't see anything there that would be related to Pi-hole. I'd ask Stubby and/or NextDNS what they have to say.

Thanks @DanSchaper

I would ask on the Stubby github issues page now.

Let us know what you find out...

Thanks @DanSchaper for your excellent suggestion in one of the replies above.

Maybe it's not a DNS server responding but something else on the same port as Stubby.

I made Stubby listen on port 5300 and here is a netstat of the same :

 ----- Stubby port  : -----

tcp        0      0 127.0.0.1:5300          0.0.0.0:*               LISTEN      18093/stubby
tcp6       0      0 ::1:5300                :::*                    LISTEN      18093/stubby
udp        0      0 127.0.0.1:5300          0.0.0.0:*                           18093/stubby
udp6       0      0 ::1:5300                :::*                                18093/stubby

I ran a tcpdump to capture packets on both tcp and udp port 5300, the tcp port came empty but there were logs on udp filter on tcpdump when I did use internet for a minute.

It was clear that Stubby was using the UDP port 5300 to listen for DNS queries.

Then I started a netcat udp session using :

nc -u localhost 5300

and wrote random strings and pressed enter 4-5 times.

As soon as I pressed enter for each string, stubby logs went like :

Jan 15 18:42:32 raspberrypi stubby[18093]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 15 18:42:33 raspberrypi stubby[18093]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 15 18:42:34 raspberrypi stubby[18093]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.
Jan 15 18:43:40 raspberrypi stubby[18093]: Could not get qname from query: A helper function for dicts had a name argument that for a name that is not in the dict.

It is now clear the that non-DNS request query is causing this. There are no other tools / utilities installed on the the Pi machine, so it might be a probe / heartbeat or something else send to port 5300 (not sure though but making this assumption because my netcat test packets didn't get reflected on NextDNS side, nor did any non-DNS test packets sent to local port 53 [pihole dnsmasq] in hopes of successful redirection to 5300 [Stubby] )

Even when these logs appeared, Stubby didn't crash and is continuing to forward and respond with DNS records.

Future debugging should this issue of Stubby crash occurs again will take this course :

  • Will check syslog for application activities
  • Will optionally run tcpdump for extended time to replicate this issue to get atleast the port from where alleged non-DNS packets are send
  • In any case, would present my findings on this thread for future reference / lurkers here.
1 Like