Every Sunday at 4am pi-hole stops responding to DNS queries

[Kevin_Donnelly]

For the past three Sundays I have woke up to a broken pi-hole, three Sundays since I updated to v5.1.1.

Looking at the logs it is right after the gravity is updated.

From pihole_updateGravity.log:

  [i] Neutrino emissions detected...
  [✓] Pulling blocklist source list into range

  [✓] Preparing new gravity database
  [i] Target: https://raw.githubusercontent.com/StevenBlack/hosts/master/hosts
  [✓] Status: Retrieval successful
  [i] Received 58507 domains

  [i] Target: https://mirror1.malwaredomains.com/files/justdomains
  [✓] Status: No changes detected
  [i] Received 26853 domains

  [i] Target: http://sysctl.org/cameleon/hosts
  [✓] Status: No changes detected
  [i] Received 20567 domains

  [i] Target: https://zeustracker.abuse.ch/blocklist.php?download=domainblocklist
  [✓] Status: Retrieval successful
  [i] Received 0 domains

  [i] Target: https://s3.amazonaws.com/lists.disconnect.me/simple_tracking.txt
  [✓] Status: No changes detected
  [i] Received 34 domains

  [i] Target: https://s3.amazonaws.com/lists.disconnect.me/simple_ad.txt
  [✓] Status: No changes detected
  [i] Received 2701 domains

  [✓] Storing downloaded domains in new gravity database
  [✓] Building tree
  [✓] Swapping databases
  [i] Number of gravity domains: 108662 (96063 unique domains)
  [i] Number of exact blacklisted domains: 1
  [i] Number of regex blacklist filters: 0
  [i] Number of exact whitelisted domains: 115
  [i] Number of regex whitelist filters: 0
  [✓] Cleaning up stray matter

  [✓] DNS service is running
  [✓] Pi-hole blocking is Enabled

The last few entires from pihole.log

Aug  2 04:01:04 dnsmasq[4267]: query[AAAA] grafana.com from 127.0.0.1
Aug  2 04:01:04 dnsmasq[4267]: cached grafana.com is 2600:1901:0:bae2::
Aug  2 04:01:04 dnsmasq[4267]: query[A] grafana.com from 127.0.0.1
Aug  2 04:01:04 dnsmasq[4267]: cached grafana.com is 35.241.23.245
Aug  2 04:01:04 dnsmasq[4267]: query[A] raw.githubusercontent.com from 127.0.0.1
Aug  2 04:01:04 dnsmasq[4267]: cached raw.githubusercontent.com is <CNAME>
Aug  2 04:01:04 dnsmasq[4267]: cached github.map.fastly.net is 151.101.204.133
Aug  2 04:01:04 dnsmasq[4267]: query[AAAA] raw.githubusercontent.com from 127.0.0.1
Aug  2 04:01:04 dnsmasq[4267]: cached raw.githubusercontent.com is <CNAME>
Aug  2 04:01:04 dnsmasq[4267]: cached github.map.fastly.net is NODATA-IPv6

And finally the contents of pihole-FTL.log

[2020-08-02 00:28:45.743 4267M] Resizing "/FTL-dns-cache" from 1335296 to 1339392
[2020-08-02 02:08:13.729 4267M] Resizing "/FTL-dns-cache" from 1339392 to 1343488
[2020-08-02 03:59:52.453 4267M] Resizing "/FTL-dns-cache" from 1343488 to 1347584
[2020-08-02 04:01:05.747 4267M] Reloading DNS cache
[2020-08-02 04:01:05.748 4267M] Blocking status is enabled

Before I resort to putting in an automated reboot of the server at 4:15am every Sunday what might be wrong with pi-hole?

[Bucking_Horn]

Your log file excerpts show Pi-hole to answer some DNS queries at about 04:01.
Why do you think Pi-hole has not answered any DNS queries from 4 am to 4:01 am?

[yubiuser]

Sounds a lot like this issue:

DNS resolution unexpectedly stops after upgrade to 5.0

Please follow the below template, it will help us to help you! If you are Experiencing issues with a Pi-hole install that has non-standard elements (e.g you are using nginx instead of lighttpd, or there is some other aspect of your install that is customised) - please use the Community Help category. Expected Behaviour: DNS resolution should work continuously. Hardware: Raspberry Pi 3 Model B Plus Rev 1.3 OS: Raspbian 9.11 Actual Behaviour: Periodically pihole will stop responding to DNS quer…

Background: gravity update runs every sunday, afterwards the the regex entries are re-read. Somehow sometimes this takes very long and DNS resolution fails for that time.

[jfb]

Please post the token generated by

pihole -d

or do it through the Web interface:

Tools > Generate Debug Log

[Kevin_Donnelly]

That is the end of the logs. I captured that log at 9:03. There were no entires to any of those logs beyond what I posted.

And I don't know the exact time it broke the past two Sundays, but it does appear to be breaking after the gravity is updated.

[Kevin_Donnelly]

https://tricorder.pi-hole.net/zoufweskh8

[Bucking_Horn]

It's hard to parse anything out of the absence of log messages, so there are virtually no leads from your before 4 am logs.

From your debug log, it would seem you've encountered some database related errors when restarting at about 9 am:

*** [ DIAGNOSING ]: contents of /var/log

-rw-r--r-- 1 pihole pihole 6606 Aug  2 09:47 /var/log/pihole-FTL.log
   -----tail of pihole-FTL.log------
   [2020-08-02 09:05:19.094 1566M] SQLite3 message: no such table: message in "DELETE FROM message;" (1)
   [2020-08-02 09:05:19.094 1566M] ERROR: SQL query "DELETE FROM message;" failed: SQL logic error
   [2020-08-02 09:06:00.143 1566/T1571] SQLite3 message: no such table: network_addresses in "SELECT name FROM network WHERE id = (SELECT network_id FROM network_addresses WHERE ip = ?);" (1)
   [2020-08-02 09:06:00.143 1566/T1571] getDatabaseHostname("2600::<redacted>") - SQL error prepare: SQL logic error

The tables your log complains about are part of pihole-FTL.db, while a gravity update would touch gravity.db, of course.

Let's check both databases by running the following commands on your Pi-hole machine:

sqlite3 pihole-FTL.db "PRAGMA integrity_check"

sqlite3 gravity.db "PRAGMA integrity_check"

[Kevin_Donnelly]

kdonnel@home : /etc/pihole$ sqlite3 pihole-FTL.db "PRAGMA integrity_check"
ok
kdonnel@home : /etc/pihole$ sqlite3 gravity.db "PRAGMA integrity_check"
ok

I did follow the directions in the post linked in this thread to create a new pihole-FTL.db so that is run against the new one.

When run against the old one:

kdonnel@home : /etc/pihole$ sqlite3 pihole-FTL-old.db "PRAGMA integrity_check"

*** in database main ***

On tree page 15091 cell 9: Rowid 718697 out of order
On tree page 15201 cell 76: 2nd reference to page 15090
On tree page 15201 cell 75: Rowid 718776 out of order
On tree page 15201 cell 75: 2nd reference to page 15089
row 718726 missing from index idx_queries_timestamps
row 718727 missing from index idx_queries_timestamps
row 718728 missing from index idx_queries_timestamps
row 718729 missing from index idx_queries_timestamps
row 718730 missing from index idx_queries_timestamps
row 718731 missing from index idx_queries_timestamps
row 718732 missing from index idx_queries_timestamps
row 718733 missing from index idx_queries_timestamps
row 718734 missing from index idx_queries_timestamps
row 718735 missing from index idx_queries_timestamps
row 718736 missing from index idx_queries_timestamps
row 718737 missing from index idx_queries_timestamps
row 718738 missing from index idx_queries_timestamps
row 718739 missing from index idx_queries_timestamps
row 718740 missing from index idx_queries_timestamps
row 718741 missing from index idx_queries_timestamps
row 718742 missing from index idx_queries_timestamps
row 718743 missing from index idx_queries_timestamps
row 718744 missing from index idx_queries_timestamps
row 718745 missing from index idx_queries_timestamps
row 718746 missing from index idx_queries_timestamps
row 718747 missing from index idx_queries_timestamps
row 718748 missing from index idx_queries_timestamps
row 718749 missing from index idx_queries_timestamps
row 718750 missing from index idx_queries_timestamps
row 718751 missing from index idx_queries_timestamps
row 718752 missing from index idx_queries_timestamps
row 718753 missing from index idx_queries_timestamps
row 718754 missing from index idx_queries_timestamps
row 718755 missing from index idx_queries_timestamps
row 718756 missing from index idx_queries_timestamps
row 718757 missing from index idx_queries_timestamps
row 718758 missing from index idx_queries_timestamps
row 718759 missing from index idx_queries_timestamps
row 718760 missing from index idx_queries_timestamps
row 718761 missing from index idx_queries_timestamps
row 718762 missing from index idx_queries_timestamps
row 718763 missing from index idx_queries_timestamps
row 718764 missing from index idx_queries_timestamps
row 718765 missing from index idx_queries_timestamps
row 718766 missing from index idx_queries_timestamps
row 718767 missing from index idx_queries_timestamps
row 718768 missing from index idx_queries_timestamps
row 718769 missing from index idx_queries_timestamps
row 718770 missing from index idx_queries_timestamps
row 718771 missing from index idx_queries_timestamps
row 718772 missing from index idx_queries_timestamps
row 718773 missing from index idx_queries_timestamps
row 718775 missing from index idx_queries_timestamps
row 718776 missing from index idx_queries_timestamps
row 718777 missing from index idx_queries_timestamps
row 718778 missing from index idx_queries_timestamps
row 718779 missing from index idx_queries_timestamps
row 718780 missing from index idx_queries_timestamps
row 718781 missing from index idx_queries_timestamps
row 718782 missing from index idx_queries_timestamps
row 718783 missing from index idx_queries_timestamps
row 718784 missing from index idx_queries_timestamps
row 718785 missing from index idx_queries_timestamps
row 718786 missing from index idx_queries_timestamps
row 718787 missing from index idx_queries_timestamps
row 718788 missing from index idx_queries_timestamps
row 718789 missing from index idx_queries_timestamps
row 718790 missing from index idx_queries_timestamps
row 718791 missing from index idx_queries_timestamps
row 718792 missing from index idx_queries_timestamps
row 718793 missing from index idx_queries_timestamps
row 718794 missing from index idx_queries_timestamps
row 718795 missing from index idx_queries_timestamps
row 718796 missing from index idx_queries_timestamps
row 718797 missing from index idx_queries_timestamps
row 718798 missing from index idx_queries_timestamps
row 718799 missing from index idx_queries_timestamps
row 718800 missing from index idx_queries_timestamps
row 718801 missing from index idx_queries_timestamps
row 718802 missing from index idx_queries_timestamps
row 718803 missing from index idx_queries_timestamps
row 718804 missing from index idx_queries_timestamps
row 718805 missing from index idx_queries_timestamps
row 718806 missing from index idx_queries_timestamps
row 718807 missing from index idx_queries_timestamps
row 718808 missing from index idx_queries_timestamps
row 718809 missing from index idx_queries_timestamps
row 718810 missing from index idx_queries_timestamps
row 718811 missing from index idx_queries_timestamps
row 718812 missing from index idx_queries_timestamps
row 718813 missing from index idx_queries_timestamps
row 718814 missing from index idx_queries_timestamps
row 718815 missing from index idx_queries_timestamps
row 718816 missing from index idx_queries_timestamps
row 718817 missing from index idx_queries_timestamps
row 718818 missing from index idx_queries_timestamps
row 718819 missing from index idx_queries_timestamps
row 718820 missing from index idx_queries_timestamps
row 718821 missing from index idx_queries_timestamps
row 718822 missing from index idx_queries_timestamps
kdonnel@home: /etc/pihole$

[jfb]

In addition to the items being discussed, I note in your debug log that you are using the six default lists we used to offer. The latest release has reduced the offerings to two, as some of the lists were no longer maintained and/or no longer available. You might consider reducing your lists to the two lists currently offered as defaults:

Restoring default Pi-hole adlist(s)

Pi-hole ships with optional adlist(s) (publicly maintained block lists), which you can enable if you choose. If you find that you need to restore the default list(s), they are as follows - current as of the V5.2 release and a pending change to remove a discontinued list. https://raw.githubusercontent.com/StevenBlack/hosts/master/hosts To restore these lists to your Pi-hole, you have several options: Pi-hole V4: From the web Admin GUI > Settings > Blocklists you can paste any of the URL's …

[Kevin_Donnelly]

I have removed the previously configured adlists and added just the two mentioned in the Restoring default Pi-hole adlists post.

[El_Topo]

I also noticed this problem because my pihole stops working on Sunday too (today, and 2 previous Sundays)

I manually run the cron command from pihole (/etc/cron.d/pihole) as root:

PATH="$PATH:/usr/local/bin/" pihole updateGravity >/var/log/pihole_updateGravity.log || cat /var/log/pihole_updateGravity.log

and saw this problem immediately:
$ dig @10.10.5.5 +short google.com
;; connection timed out; no servers could be reached

I have to run
pihole restartdns
to make pihole working again:
$ dig @10.10.5.5 +short google.com
172.217.0.46

pihole is running on 10.10.5.5
$ pihole -v
Pi-hole version is v5.1.1 (Latest: v5.1.1)
AdminLTE version is v5.1 (Latest: v5.1)
FTL version is v5.1 (Latest: v5.1)

my adlists (/etc/pihole/migration_backup/adlists.list):

# The below list amalgamates several lists we used previously.
# See `https://github.com/StevenBlack/hosts` for details
##StevenBlack's list
https://raw.githubusercontent.com/StevenBlack/hosts/master/hosts

##MalwareDomains
https://mirror1.malwaredomains.com/files/justdomains

##Cameleon
http://sysctl.org/cameleon/hosts

##Zeustracker
https://zeustracker.abuse.ch/blocklist.php?download=domainblocklist

##Disconnect.me Tracking
https://s3.amazonaws.com/lists.disconnect.me/simple_tracking.txt

##Disconnect.me Ads
https://s3.amazonaws.com/lists.disconnect.me/simple_ad.txt

https://dbl.oisd.nl

[yubiuser]

It would be interesting to see the log of
/var/log/pihole-FTL.log when the stop happened. Interesting are especially the lines between

Reloading DNS cache
[...]
Compiled XX whitelist and XX blacklist regex filters in YYY msec

[ToWn3r]

I also just experienced the 4am RPi / PiH issue last night.

https://tricorder.pi-hole.net/e89w4ybq6f

Should this be a new separate post or is in here ok?

[Bucking_Horn]

@Kevin_Donnelly

On tree page 15201 cell 75: 2nd reference to page 15089
row 718726 missing from index idx_queries_timestamps

At least, no malformed error. Those db warnings are not too bad, probably could have been fixed by simple reindexing.

But since you've already started afresh:
Did using a new database alleviate your issue?

[Kevin_Donnelly]

I really won't know until Sunday.

Since my /etc/crond.d/pihole indicates that my gravity update runs at 4:01am on Sunday, I have added another entry in /etc/cron.d/pihole.local:

4 4 * * 7 root PATH="$PATH:/usr/local/bin/" pihole restartdns >/var/log/pihole_restartdns.log || cat /var/log/pihole_restartdns.log

If that works then I will have a temporary fix that leaves me without DNS for only a minute or so every Sunday instead of until I wake up.

[Kevin_Donnelly]

Just to follow up. I was missing the path to /usr/sbin so the pihole restartdns cron entry I put in place did not do anything useful, yet I had a working pihole the last two Sundays when I woke up.

My problem was solved either by creating a new pihole-FTL.db or by setting my pihole to only use the two current default adlists.