"Lost Connection to API" every Day at 11AM

TimLux · May 6, 2021, 9:45am

Expected Behaviour:

Working DNS Service except I stop or restart it
OS: Latest Raspberry Pi OS (releases March 4th 2021)
Hardware: Raspberry Pi 2

Actual Behaviour:

Around 11AM every day I loose connection to the Internet. at first I resolved it with a power cycle of the Raspberry because I thought it might be faulty, but after a while I figured that I can still log in to the web interface of the pihole using the IP and restart the DNS resolver via the settings tab. It took me a few days to figure out what to look for, but I think I found the issue within the /var/log/pihole-FTL.log.1:

...SNIP...
[2021-05-05 10:55:00.977 21195/T21199] Compiled 1 whitelist and 101 blacklist regex filters for 16 clients in 108.1 msec

[2021-05-05 11:00:11.558 21195M] Shutting down...
[2021-05-05 11:00:11.885 21195M] Finished final database update
[2021-05-05 11:00:11.885 21195M] Waiting for threads to join
[2021-05-05 11:00:11.885 21195M] Thread telnet-IPv4 (0) is idle, terminating it.
[2021-05-05 11:00:11.886 21195M] Thread telnet-IPv6 (1) is idle, terminating it.
[2021-05-05 11:00:11.887 21195M] Thread telnet-socket (2) is idle, terminating it.
[2021-05-05 11:00:11.887 21195M] Thread database (3) is idle, terminating it.
[2021-05-05 11:00:11.889 21195M] Thread housekeeper (4) is idle, terminating it.
[2021-05-05 11:00:11.889 21195M] Thread DNS client (5) is idle, terminating it.
[2021-05-05 11:00:11.890 21195M] All threads joined
[2021-05-05 11:00:11.899 21195M] ########## FTL terminated after 23h 41m 3s (code 0)! ##########

Around this time yesterday I figured DNS querys did no longer work and restarted the DNS Resolver via web interface
[2021-05-05 11:24:27.032 2847M] Using log file /var/log/pihole-FTL.log
[2021-05-05 11:24:27.032 2847M] ########## FTL started! ##########

Today the same happend around the same time:
---SNIP...
[2021-05-06 07:42:11.067 5365/T5369] Compiled 1 whitelist and 101 blacklist regex filters for 17 clients in 142.2 msec
[2021-05-06 07:42:49.564 5365M] Resizing "FTL-dns-cache" from 53248 to (3584 * 16) == 57344 (/dev/shm: 2.8MB used, 484.6MB total, FTL uses 2.8MB)
[2021-05-06 08:02:50.643 5365M] Resizing "FTL-dns-cache" from 57344 to (3840 * 16) == 61440 (/dev/shm: 2.8MB used, 484.6MB total, FTL uses 2.8MB)
[2021-05-06 08:14:04.898 5365M] Resizing "FTL-domains" from 36864 to (2560 * 16) == 40960 (/dev/shm: 2.8MB used, 484.6MB total, FTL uses 2.8MB)
[2021-05-06 08:28:51.062 5365M] Resizing "FTL-dns-cache" from 61440 to (4096 * 16) == 65536 (/dev/shm: 2.8MB used, 484.6MB total, FTL uses 2.8MB)
[2021-05-06 11:00:22.095 5365M] Shutting down...
[2021-05-06 11:00:23.174 5365M] Finished final database update
[2021-05-06 11:00:23.175 5365M] Waiting for threads to join
[2021-05-06 11:00:23.175 5365M] Thread telnet-IPv4 (0) is idle, terminating it.
[2021-05-06 11:00:23.176 5365M] Thread telnet-IPv6 (1) is idle, terminating it.
[2021-05-06 11:00:23.177 5365M] Thread telnet-socket (2) is idle, terminating it.
[2021-05-06 11:00:23.177 5365M] Thread database (3) is idle, terminating it.
[2021-05-06 11:00:23.179 5365M] Thread housekeeper (4) is idle, terminating it.
[2021-05-06 11:00:23.181 5365M] Thread DNS client (5) is idle, terminating it.
[2021-05-06 11:00:23.184 5365M] All threads joined
[2021-05-06 11:00:23.197 5365M] ########## FTL terminated after 23h 10m 8s (code 0)! ##########
[2021-05-06 11:12:43.889 30681M] Using log file /var/log/pihole-FTL.log
[2021-05-06 11:12:43.928 30681M] ########## FTL started! ##########
[2021-05-06 11:12:43.928 30681M] FTL branch: master
[2021-05-06 11:12:43.929 30681M] FTL version: v5.8.1
[2021-05-06 11:12:43.929 30681M] FTL commit: b90ab8b1
[2021-05-06 11:12:43.929 30681M] FTL date: 2021-04-21 20:03:47 +0100
[2021-05-06 11:12:43.929 30681M] FTL user: pihole

The only thing different from a standard setup is that I deleted the user Pi a few weeks ago and replaced it with another user. Could this be the issue?

Thanks in advance for any help

Debug Token:

https://tricorder.pi-hole.net/2e0gwjmilk

DanSchaper · May 6, 2021, 6:29pm

Something is asking pihole-FTL to shut down. Do you have some kind of cron job or third party script that is intended to work with Pi-hole but is instead breaking Pi-hole?

DanSchaper · May 6, 2021, 6:32pm

Does this look familiar to you?

TimLux · May 6, 2021, 9:01pm

Hi Dan,

Thanks for your help. Indeed I'm using this script, but it is tasked for 3AM. However I've commented it out within crontab to check if this is the issue.
I will get back to you as soon as 11AM passes, which is about 12 hours from now

DanSchaper · May 6, 2021, 9:06pm

Sounds good. Also to let you know, the IPv6 addresses are not correct for your setup.

[✓] IPv6 address(es) bound to the eth0 interface:
   2003:<REDACT>:3586 does not match the IP found in /etc/pihole/setupVars.conf (https://discourse.pi-hole.net/t/use-ipv6-ula-addresses-for-pi-hole/2127)
   fe80::ba27:ebff:fe56:3586 does not match the IP found in /etc/pihole/setupVars.conf (https://discourse.pi-hole.net/t/use-ipv6-ula-addresses-for-pi-hole/2127)
111

*** [ DIAGNOSING ]: Name resolution (IPv6) using a random blocked domain and a known ad-serving domain
[✗] Failed to resolve lifeshine.net via localhost (::1)
[✗] Failed to resolve lifeshine.net via Pi-hole (fd26:7157:5484:0001::1)
[✓] doubleclick.com is 2a00:1450:4001:82a::200e via a remote, public DNS server (2001:4860:4860::8888)

The ULA address fd26 doesn't seem to be used by the Pi-hole device.

TimLux · May 7, 2021, 6:38am

Hi Dan, thanks for the heads up

I've followed this guide to solve this issue: How-To: Using Pi-Hole with Telekom Speedport routers
Sorry for the (possibly) stupid question, but is there a way I can check the IPv6 configuration myself?
I did run the pihole -d command again and found this, which seems like I configured it correctly:

I will keep you updated about the "11AM DNS issue" of course. Thanks again for your help

DanSchaper · May 7, 2021, 3:13pm

That looks like you've added in the ULA address that was missing previously. You'll also need to check further down the log output that shows the local and remove DNS tests.

*** [ DIAGNOSING ]: Name resolution (IPv6) using a random blocked domain and a known ad-serving domain

TimLux · May 7, 2021, 6:18pm

Hi Dan,

thanks, I took a look and it looks fine to me:

Regarding the 11AM Issue: No issue today, but I rebooted the Pi to get the IPv6 adress configuration right, so I'd like to wait for tomorrow.
However, if it was the whitelist script I'm wondering why it doesn't restart the FTL Service after the Update and why it runs at 11AM instead of 3AM like tasked in crontab -e...

DanSchaper · May 7, 2021, 6:58pm

The only thing that comes to mind is possibly different time zones being set.

Can you run cat /etc/timezone on the Pi-hole server?

TimLux · May 7, 2021, 8:07pm

sure:

:~ $ cat /etc/timezone
Europe/Berlin

to be honest, I would have been shocked if that was the reason because these are the contents of Contab -e:

# For more information see the manual pages of crontab(5) and cron(8)
# 
# m h  dom mon dow   command
0 11 1 * * sudo /media/Backup.sh
0 11 6 * * sudo /media/Backup.sh
0 11 11 * * sudo /media/Backup.sh
0 11 16 * * sudo /media/Backup.sh
0 11 21 * * sudo /media/Backup.sh
0 11 26 * * sudo /media/Backup.sh
#55 3 * * * git clone https://github.com/anudeepND/whitelist.git
#0 4 * * * sudo python3 whitelist/scripts/whitelist.py

as mentioned, i commented the whitelist script out to rule it out as the culprit, but the backup script runs at 11AM without any issues.
Yes, 11AM rings a bell, but I checked the backup and ran it at other times to be sure that it isn't the backup. The contents of the Backup script are rather boring:

!/bin/bash
#Festplatte einbinden
sudo mount -o username=tlux,password=Hh1737628! //192.168.2.254/Backup /media/N$
#Variablen
BACKUP_PFAD="/media/NAS-Backup/Geräte/RaspberryPi/Backup"
BACKUP_ANZAHL="7"
BACKUP_NAME="Backup"
#Backup erstellen
dd if=/dev/mmcblk0 of=${BACKUP_PFAD}/${BACKUP_NAME}-$(date +%Y%m%d).img bs=1MB
#Alte Sicherung löschen
pushd ${BACKUP_PFAD} || exit; ls -tr ${BACKUP_PFAD}/${BACKUP_NAME}* | head -n -$
#Festplatte auswerfen
umount /media/NAS-Backup
exit 0

Or did I do something rather stupid and don't see the issue?
To be honest I'm a Windows administrator and Unix is more of a newly found hobby

TimLux · May 10, 2021, 10:38am

Hello Dan,
an update as promised:
There has not been a single Issue with the Pihole setup over the weekend. So it was the whitelist script and I will stop using it via crontab and only execute it manually in a planned and controlled enviroment.
Thanks again for your quick help

system · May 31, 2021, 10:39am

This topic was automatically closed 21 days after the last reply. New replies are no longer allowed.