as soon as I setup my Pihole as dhcp server, FTL crashes within an hour.
My debug token is: https://tricorder.pi-hole.net/57rjb0zfbz
(I had to edit resolv.conf to nameserver=8.8.8.8 to be able to upload the debug log)
I am not certain however the dhcp server is the cause as I also had some crashes with first install and I think dhcp was still off but I started using the raspberry's dns with a vpn client and a windows desktop were I manually edited the nameserver to the raspberry pi2.
In my network there is another pihole operating from a docker on a openmediavault server. But I am looking for a standalone openvpn en pihole solution, that's why I bought the pi2.
So it seems that the pihole FTL crashes when it has some work to do. when it is idle it does not crash.
At the moment of the crash I also found something about failing to create a listening socket for port 53 in syslog, see below.
What is going wrong here? I had the same problem with a full install of raspbian with NOOBS, so I started from scratch with raspbian lite but the problem remains. After setup of raspbian lite the first boot failed, the second one worked without problems. Could this be hardware or power problems? or is this a software bug. The pi does not crash an ssh and openvpn keep working.
Aug 24 16:34:09 raspberrypi systemd[1]: Stopping LSB: pihole-FTL daemon...
Aug 24 16:34:09 raspberrypi pihole-FTL[4932]: Stopped
Aug 24 16:34:09 raspberrypi systemd[1]: pihole-FTL.service: Succeeded.
Aug 24 16:34:09 raspberrypi systemd[1]: Stopped LSB: pihole-FTL daemon.
Aug 24 16:34:09 raspberrypi systemd[1]: Starting LSB: pihole-FTL daemon...
Aug 24 16:34:09 raspberrypi pihole-FTL[4961]: Not running
Aug 24 16:34:10 raspberrypi systemd[1]: Started Session c4 of user pihole.
**Aug 24 16:34:10 raspberrypi pihole-FTL[4961]: dnsmasq: failed to create listening socket for port 53: Address already in use**
**Aug 24 16:34:10 raspberrypi dnsmasq[5011]: failed to create listening socket for port 53: Address already in use**
**Aug 24 16:34:10 raspberrypi dnsmasq[5011]: FAILED to start up**
Aug 24 16:34:10 raspberrypi systemd[1]: session-c4.scope: Succeeded.
Aug 24 16:34:10 raspberrypi systemd[1]: Started LSB: pihole-FTL daemon.
Aug 24 16:34:10 raspberrypi systemd[1]: session-c1.scope: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[1]: Stopping User Manager for UID 999...
Aug 24 16:34:20 raspberrypi systemd[570]: Stopped target Default.
Aug 24 16:34:20 raspberrypi systemd[570]: Stopped target Basic System.
Aug 24 16:34:20 raspberrypi systemd[570]: Stopped target Sockets.
Aug 24 16:34:20 raspberrypi systemd[570]: gpg-agent-ssh.socket: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[570]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Aug 24 16:34:20 raspberrypi systemd[570]: gpg-agent-browser.socket: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[570]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
Aug 24 16:34:20 raspberrypi systemd[570]: gpg-agent-extra.socket: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[570]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Aug 24 16:34:20 raspberrypi systemd[570]: gpg-agent.socket: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[570]: Closed GnuPG cryptographic agent and passphrase cache.
Aug 24 16:34:20 raspberrypi systemd[570]: dirmngr.socket: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[570]: Closed GnuPG network certificate management daemon.
Aug 24 16:34:20 raspberrypi systemd[570]: Stopped target Paths.
Aug 24 16:34:20 raspberrypi systemd[570]: Reached target Shutdown.
Aug 24 16:34:20 raspberrypi systemd[570]: systemd-exit.service: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[570]: Started Exit the Session.
Aug 24 16:34:20 raspberrypi systemd[570]: Reached target Exit the Session.
Aug 24 16:34:20 raspberrypi systemd[570]: Stopped target Timers.
Aug 24 16:34:20 raspberrypi systemd[1]: user@999.service: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[1]: Stopped User Manager for UID 999.
Aug 24 16:34:20 raspberrypi systemd[1]: Stopping User Runtime Directory /run/user/999...
Aug 24 16:34:20 raspberrypi systemd[587]: run-user-999.mount: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[1]: run-user-999.mount: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[1]: user-runtime-dir@999.service: Succeeded.
Aug 24 16:34:20 raspberrypi systemd[1]: Stopped User Runtime Directory /run/user/999.
Aug 24 16:34:20 raspberrypi systemd[1]: Removed slice User Slice of UID 999.
From your debug log, pihole-FTL is not running (and should be), and thus the Pi-Hole cannot resolve DNS.
*** [ DIAGNOSING ]: Ports in use
*:22 sshd (IPv4)
*:22 sshd (IPv6)
[*:80] is in use by lighttpd
[*:80] is in use by lighttpd
*** [ DIAGNOSING ]: Name resolution (IPv4) using a random blocked domain and a known ad-serving domain
[✗] Failed to resolve signin.eby.de.ybvqnxmnmaoikjt.civpro.co.za via localhost (127.0.0.1)
[✗] Failed to resolve signin.eby.de.ybvqnxmnmaoikjt.civpro.co.za via Pi-hole (192.168.179.16)
[✓] doubleclick.com is 172.217.20.78 via a remote, public DNS server (8.8.8.8)
Let's check for processes running on ports used by Pi-Hole and see what is running on port 53:
This is what I get at the moment on a rebooted pi where FTL has not (yet) crashed.
(There is however a possibility that power fluctuations caused these problems.
I changed the Chinese power adapter model BX-502000 output 5v 2a for an ipad power adapter with a blackberry usb cable. I will keep you updated if this really solved the problem, but will only know this after a few days)
The Pi2 has not crashed yet and is now acting dhcp server in my network and slowly taking over all devices. I switched the dhcp server in the other pihole off.
Better. Run this again when Pi-Hole is not working and see what is using port 53. I suspect you have a separate dnsmasq process competing for the port, thus the error messages in your original post. .
I restarted the DNS to get /etc/lan.list working so I can use hostnames in my own lan.
But I tested again and it also crashes without 05-lan.conf in /etc/dnsmasq.d.
I can reproduce the crashes bij restarting DNS resolver and directly afterwards click another menu in the webgui. The pi gets too busy and then FTL crashes.
The syslog shows now that the pi2 cannot bind a dhcp server socket.
Aug 25 00:56:28 raspberrypi systemd[1]: Stopping LSB: pihole-FTL daemon...
Aug 25 00:56:28 raspberrypi pihole-FTL[9230]: Stopped
Aug 25 00:56:28 raspberrypi systemd[1]: pihole-FTL.service: Succeeded.
Aug 25 00:56:28 raspberrypi systemd[1]: Stopped LSB: pihole-FTL daemon.
Aug 25 00:56:28 raspberrypi systemd[1]: Starting LSB: pihole-FTL daemon...
Aug 25 00:56:28 raspberrypi pihole-FTL[9259]: Not running
Aug 25 00:56:29 raspberrypi systemd[1]: Started Session c6 of user pihole.
Aug 25 00:56:29 raspberrypi pihole-FTL[9259]: dnsmasq: failed to bind DHCP server socket: Address already in use
Aug 25 00:56:29 raspberrypi dnsmasq[9307]: failed to bind DHCP server socket: Address already in use
Aug 25 00:56:29 raspberrypi dnsmasq[9307]: FAILED to start up
Aug 25 00:56:29 raspberrypi systemd[1]: session-c6.scope: Succeeded.
Aug 25 00:56:29 raspberrypi systemd[1]: Started LSB: pihole-FTL daemon.
Aug 25 00:56:32 raspberrypi systemd[1]: session-c5.scope: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[1]: Stopping User Manager for UID 999...
Aug 25 00:56:43 raspberrypi systemd[529]: Stopped target Default.
Aug 25 00:56:43 raspberrypi systemd[529]: Stopped target Basic System.
Aug 25 00:56:43 raspberrypi systemd[529]: Stopped target Timers.
Aug 25 00:56:43 raspberrypi systemd[529]: Stopped target Paths.
Aug 25 00:56:43 raspberrypi systemd[529]: Stopped target Sockets.
Aug 25 00:56:43 raspberrypi systemd[529]: gpg-agent-extra.socket: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[529]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Aug 25 00:56:43 raspberrypi systemd[529]: gpg-agent-browser.socket: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[529]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
Aug 25 00:56:43 raspberrypi systemd[529]: gpg-agent-ssh.socket: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[529]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Aug 25 00:56:43 raspberrypi systemd[529]: dirmngr.socket: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[529]: Closed GnuPG network certificate management daemon.
Aug 25 00:56:43 raspberrypi systemd[529]: gpg-agent.socket: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[529]: Closed GnuPG cryptographic agent and passphrase cache.
Aug 25 00:56:43 raspberrypi systemd[529]: Reached target Shutdown.
Aug 25 00:56:43 raspberrypi systemd[529]: systemd-exit.service: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[529]: Started Exit the Session.
Aug 25 00:56:43 raspberrypi systemd[529]: Reached target Exit the Session.
Aug 25 00:56:43 raspberrypi systemd[1]: user@999.service: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[1]: Stopped User Manager for UID 999.
Aug 25 00:56:43 raspberrypi systemd[1]: Stopping User Runtime Directory /run/user/999...
Aug 25 00:56:43 raspberrypi systemd[1]: run-user-999.mount: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[528]: run-user-999.mount: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[1]: user-runtime-dir@999.service: Succeeded.
Aug 25 00:56:43 raspberrypi systemd[1]: Stopped User Runtime Directory /run/user/999.
Aug 25 00:56:43 raspberrypi systemd[1]: Removed slice User Slice of UID 999.
there is no competing process on port 53.
pi@raspberrypi:/var/log $ sudo netstat -nltup | grep 'Proto\|:53 \|:5053 \|:5353 \|:8953 \|:67 \|:80 \|:471'
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 0.0.0.0:80 0.0.0.0:* LISTEN 502/lighttpd
tcp6 0 0 :::80 :::* LISTEN 502/lighttpd
udp 0 0 0.0.0.0:5353 0.0.0.0:* 315/avahi-daemon: r
udp6 0 0 :::5353 :::* 315/avahi-daemon: r
During one of the reboots however the system hang with
[ 1.040655] CPU1: failed to come online
I had to poweroff the pi2 to get it working again.
Possibly bad hardware? Could this cause the crashes of FTL when the pi gets busy?
It's a secondhand pi2 that I bought, so maybe it has some defects. How can I test the hardware?
I did the sysbench stresstests several times and had no problems at all.
I cannot fully reproduce the crashes, but when there is an openvpn connection active and I press "restart DNS resolver" in the web interface of pihole. The FTL service crashes approximately 4 out of 5 times. When there is no VPN connection active It works 4 out of 5 times but 1 in 5 times it still crashes.
Seems to me the crashes appear when the pi is busy, during the sysbench test I tried a restart DNS resolver. first time it worked, second time FTL crashed.
Aug 25 22:47:42 raspberrypi pihole-FTL[1037]: dnsmasq: failed to bind DHCP server socket: Address already in use
Aug 25 22:47:42 raspberrypi dnsmasq[1085]: failed to bind DHCP server socket: Address already in use
Aug 25 22:47:42 raspberrypi dnsmasq[1085]: FAILED to start up
Maybe someone can try to replicate the crash of the FTL service on a raspberry pi2, by running
sysbench --test=cpu --cpu-max-prime=20000 run
and simultaneously restarting the DNS resolver several times.
If nobody can reproduce this crash I probably have faulty hardware.
I think you are right. I read the topic, I do not understand everything as i have little programming experience but it seems to me my pi has the same problem. But sometimes either port 53 is not free yet or the socket for the dhcp service is not yet available. If the pi is busy with other stuff the bug is more likely to happen and this is consistent with the behaviour I saw. It also explains why it happens less often under raspbian lite than under a full install. Interesting.