Ftl: Pi-hole FTL crash (iface_check+0x48)

[shartenauer]

Pi-hole FTL service crashes every 1-2 days
High CPU-Load

In raising this issue, I confirm the following (please check boxes, eg [X]) Failure to fill the template will close your issue:

• [X] I have read and understood the contributors guide.
• [X] The issue I am reporting can be replicated
• [X] The issue I am reporting isn't a duplicate

How familiar are you with the codebase?:

_{replace this text with a number from 1 to 10, with 1 being not familiar, and 10 being very familiar}_

---

[BUG | ISSUE] Expected Behaviour:

[BUG | ISSUE] Actual Behaviour:

[BUG | ISSUE] Steps to reproduce:

-
-
-
-

Log file output [if available]

2020-06-06 16:31:59.557 338] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-06-06 16:31:59.557 338] ----------------------------> FTL crashed! <----------------------------
[2020-06-06 16:31:59.557 338] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-06-06 16:31:59.557 338] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-06-06 16:31:59.557 338] and include in your report already the following details:
[2020-06-06 16:31:59.557 338] FTL has been running for 99192 seconds
[2020-06-06 16:31:59.557 338] FTL branch: master
[2020-06-06 16:31:59.557 338] FTL version: v5.0
[2020-06-06 16:31:59.557 338] FTL commit: 3d7c095
[2020-06-06 16:31:59.557 338] FTL date: 2020-05-10 18:58:38 +0100
[2020-06-06 16:31:59.557 338] FTL user: started as pihole, ended as pihole
[2020-06-06 16:31:59.557 338] Compiled for x86_64 (compiled on CI) using gcc (Debian 6.3.0-18+deb9u1) 6.3.0 20170516
[2020-06-06 16:31:59.557 338] Received signal: Segmentation fault
[2020-06-06 16:31:59.557 338] at address: (nil)
[2020-06-06 16:31:59.557 338] with code: Unknown (128)
[2020-06-06 16:31:59.558 338] Backtrace:
[2020-06-06 16:31:59.558 338] ------ Listing content of directory /dev/shm ------
[2020-06-06 16:31:59.558 338] File Mode User:Group Filesize Filename
[2020-06-06 16:31:59.558 338] rwxrwxrwx root:root 260 .
[2020-06-06 16:31:59.558 338] rwxr-xr-x root:root 440 ..
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 37K FTL-dns-cache
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 12K FTL-overTime
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 2M FTL-queries
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 4K FTL-upstreams
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 20K FTL-clients
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 98K FTL-domains
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 49K FTL-strings
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 12 FTL-settings
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 124 FTL-counters
[2020-06-06 16:31:59.558 338] rw------- pihole:pihole 48 FTL-lock
[2020-06-06 16:31:59.558 338] ---------------------------------------------------
[2020-06-06 16:31:59.558 338] Thank you for helping us to improve our FTL engine!
[2020-06-06 16:31:59.558 338] FTL terminated!

Device specifics

Hardware Type: rPi, VPS, etc
OS: Debian 10.4, Proxmox LXC Container

_This template was created based on the work of udemy-dl._

[yubiuser]

Thanks for posting. Since v5.0 some users experiencing random crashes, usually using Cloudflare as upstream DNS provider. Your bug is the same as reported here

https://github.com/pi-hole/FTL/issues/757

It would be great if you could attach a debugger as described here:
https://docs.pi-hole.net/ftldns/debugging/

Also useful would be a snipped of your /var/log/pihole.log around the time pihole crashed to see if it correlates with a specific DNS request.

[MichaelVoelkel]

Hi, I also have the same issue. I run this on BananaPI M1+ (but this should probably not play a role here). Upload of the debug log failed but I made a local copy and uploaded it manually: http://mihahome.de/pihole_debug.log
I noticed that /var/log/lighthttp was owned to root. I chmodedded it to 777 which works for starting but after some time (at restart or something) it gets back to fewer rights. I chowned it to www-data now again... but all of this has probably nothing to do with FTL.
Edit: attached debugger within screen session, will also put the output here once available (but now, Murphy's law applies and this will crash tomorrow during my work hours, but let's see :))

[shartenauer]

pihole.log:

Jun 6 16:31:58 dnsmasq[338]: query[A] 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com from 2a01:4f8:141:42cd:56a:f557:efc6:8181
Jun 6 16:31:58 dnsmasq[338]: forwarded 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com to 192.168.99.1
Jun 6 16:31:58 dnsmasq[338]: query[AAAA] 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com from 2a01:4f8:141:42cd:56a:f557:efc6:8181
Jun 6 16:31:58 dnsmasq[338]: forwarded 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com to 192.168.99.1
Jun 6 16:31:58 dnsmasq[338]: query[AAAA] 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com from 192.168.99.10
Jun 6 16:31:58 dnsmasq[338]: forwarded 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com to 192.168.99.1
Jun 6 16:31:58 dnsmasq[338]: query[A] 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com from 192.168.99.10
Jun 6 16:31:58 dnsmasq[338]: forwarded 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com to 192.168.99.1
Jun 6 16:31:58 dnsmasq[338]: reply 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com is
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.158.162
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.151.18
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.148.50
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.136.194
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.137.146
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.148.210
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.156.114
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.51.66
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.49.18
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.156.82
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.48.34
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.136.226
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.96.40.178
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.159.66
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.157.50
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.149.130
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.150.98
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.49.178
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.137.114
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.157.66
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.150.242
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.158.130
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.148.226
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.136.210
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.149.146
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.150.82
Jun 6 16:31:58 dnsmasq[338]: reply 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com is
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.157.66
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.49.194
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.158.162
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.49.18
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.137.114
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.157.50
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.159.66
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.148.210
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.150.242
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.156.98
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.136.226
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.96.40.178
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.151.18
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.158.130
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.48.98
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.148.226
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.158.178
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.148.50
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.136.194
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.137.146
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.156.82
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.149.146
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.150.98
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.137.130
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.136.210
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 40.97.51.66
Jun 6 16:31:58 dnsmasq[29692]: query[A] 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com from 2a01:4f8:141:42cd:56a:f557:efc6:8181
Jun 6 16:31:58 dnsmasq[29692]: forwarded 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com to 192.168.99.1
Jun 6 16:31:58 dnsmasq[29692]: reply 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com is
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.157.50
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.150.242
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.148.226
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.151.18
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.150.98
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.136.194
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.159.66
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.150.82
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.51.66
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.156.114
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.158.130
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.136.226
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.158.114
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.158.178
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.158.162
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.137.146
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.49.18
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.48.34
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.148.210
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.48.98
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.49.194
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.157.66
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.49.178
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.149.130
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.96.40.178
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.136.210
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.137.130
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.137.114
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.149.146
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.156.98
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.156.82
Jun 6 16:31:58 dnsmasq[29692]: reply cys-efz.office.com is 40.97.148.50
Jun 6 16:31:58 dnsmasq[338]: reply 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com is
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:11a::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2a01:111:f400:31ab::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:18::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:16::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:12f::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:e0::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:906:15::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:106::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:df::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:2b::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:906:14::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:906:60::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:90::2
Jun 6 16:31:58 dnsmasq[338]: reply 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com is
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:7c::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:2b::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:906:60::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:16::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:906:14::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:66::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:906:15::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:7b::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:7a::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:8f::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:12f::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:ca::2
Jun 6 16:31:58 dnsmasq[338]: reply cys-efz.office.com is 2603:1036:902:108::2
Jun 6 16:31:58 dnsmasq[29693]: query[AAAA] 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com from 2a01:4f8:141:42cd:56a:f557:efc6:8181
Jun 6 16:31:58 dnsmasq[29693]: forwarded 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com to 192.168.99.1
Jun 6 16:31:58 dnsmasq[29693]: reply 877a0bd7139c07533fcb42cb9520ee15.fp.measure.office.com is
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:90::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:66::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:106::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:906:15::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:7c::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:8f::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:906:14::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:906:60::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:a3::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:108::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:16::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:18::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:b3::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:df::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:ca::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:11a::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:de::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:2c::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:7a::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:906:5f::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:12e::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:12f::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2a01:111:f400:31ab::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:906:5e::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:e0::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:7b::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:c5::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:f4::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:2b::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:902:11c::2
Jun 6 16:31:58 dnsmasq[29693]: reply cys-efz.office.com is 2603:1036:906:16::2

[yubiuser]

Prefect, thanks. It must be something with pihole v5.0, cloudflare and office.com domains...

[shartenauer]

We don't use Cloudflare

[yubiuser]

Oh, interesting. Most users report crashes with Cloudflare, so I assumed you do too.

[DL6ER]

@shartenauer Then the obvious question is: Which upstream server are you using? :slightly_smiling_face:

[shartenauer]

We use Hetzner DNS Server:
213.133.98.98
213.133.99.99
213.133.100.100

[DL6ER]

Checking your posted log above everything is Jun 6 16:31:58. This likely means that there is a lot more. Can you share your entire log somehow? I will not make anything public, but it may help me reproducing the crash locally when I can fire off the same chain of domains as happened in your network.

You can get a slimmed down (and gzip compressed!) list of domains using

grep "query\[" /var/log/pihole.log | gzip -c > shortlog.gz

You can send it to <my username here>@pi-hole.net

[DL6ER]

@MichaelVoelkel Thanks for attaching the debugger. As you might have seen, there is little to no debugger output available right now to tackle this issue. There was once a ticket with debugger output and this immediately lead to a fix. However, it was something else.

I've seen this line in your debug output:

Jun  6 08:52:05 dnsmasq[1072]: warning: interface eth0 does not currently exist

Can you tell us if you're using some custom network stuff on your BananaPi? (Thinking of virtual network adapters, VPNs like OpenVPN, Wireguard, etc.). Also, do you connect over ethernet or WiFi? Or many alternating between them?

Also, do you also see the crashes being related to office.com queries?

[MichaelVoelkel]

This BananaPI is very fresh and Pihole was the first "real" software to install. Other apt-get tools were merely some helpers, stuff like sudo, vim, etc. In the very beginning I used wlan0 to setup and test everything because eth0 is only available if I hide the device. Later on, I turned wlan0 off, though, and reconfigured Pihole (with your reconfigure CLI tool) to only listen on eth0. I always have SSH access and it is always via eth0 because I turned the wlan0 device off entirely. Can there be other reasons for eth0 not being available? Maybe, Fritzbox does some funny stuff?

During installation of Pi I got some errors regarding user groups etc. and I needed to manually put a new group file there.

I did not notice some office.com messages, they do not appear on the "leaderboard" in the admin web UI. In fact, on the main computer that deals with the internet, there is no office installed. But I had another running for an hour or so with office and that was fine.

Murphy's law applies, by the way, uptime for over a day now. I got some (as you said useless) debugger output, though:

Thread 1 "pihole-FTL" received signal SIGTERM, Terminated.
Thread 3 "telnet-IPv6" received signal SIG32, Real-time event 32.
Thread 2 "telnet-IPv4" received signal SIG32, Real-time event 32.
Thread 4 "socket listener" received signal SIG32, Real-time event 32. 

And the program is down. Nevertheless, pihole-FTL is displayed as running in the admin website and everything works fine. Is there some restarter cronjob or anything active?

[DL6ER]

Is there some restarter cronjob or anything active?

No, there isn't anything that c/would restart the process at any time. I have a small Pi-hole running for non-development purposes and pihole-FTL has not been restarted since the last (regular) update of Pi-hole, it is running for over 74 days now:

# ps -eo pid,comm,lstart,etime | grep pihole-FTL
29735 pihole-FTL      Wed Mar 25 13:08:09 2020        74-17:57:50

My best guess is that you (or something on your behalf) called

sudo service pihole-FTL restart

or our wrapper for this call

pihole restartdns

The only things which cause a restart from within Pi-hole are:

• Checkout of custom branch (like development)
• Update to new version
• Flush logs (as only a full restart can ensure a properly forgotten memory)
• Gravity can restart pihole-FTL when it thinks that it is offline - only when gravity is run, but this could in fact be the reason from Sunday to Monday.

Can there be other reasons for eth0 not being available?

This I cannot answer and is something I do not recall having seen on Raspberry Pi or other devices so far, so it may be a BananaPi issue (Pi-hole already starting before the network is ready). I'd go ahead and say: It will not matter, but as we're seeing a crash in a function iface_check everything interface related should be looked at.

[DL6ER]

To all: Even when the debugger should not influence anything, it may still either do this or the bugs immediately disappeared as soon as you touched the debugger (out of 17 bug reports, I have seen only 2 coming back with a crash report from within the debugger, silence otherwise). I guess we all agree that the magic "fixed itself" is unlikely, so I went ahead and implemented more debugging output in a spacial variant of FTL.

Please run

pihole checkout ftl fix/master-in_zone-and-iface_check_debugging

and then continue running Pi-hole as if nothing would have happened (don't attach the debugger as we want to reproduce the crash!). Even when this branch does not fix anything (only logging output is added), it should give us more details in the log file just before a crash happens.

The DEBUG: lines will be interesting, also those during startup like

[2020-06-08 09:16:02.153 8515] DEBUG option::interface arg 1 = 0x55555594970a 'enp2s0'
[2020-06-08 09:16:02.153 8515] DEBUG option::interface comma = (nil) '(null)'       
[2020-06-08 09:16:02.153 8515] DEBUG option::interface arg 2 = 0x55555594970a 'enp2s0'
[2020-06-08 09:16:02.153 8515] DEBUG option::interface new->name = 0x555555960c40 'enp2s0'
[2020-06-08 09:16:02.154 8515] DEBUG iface_allowed: daemon->if_names->name = 0x55555594f030 'lo'

Thanks for your continues support in trying to resolve this. We're pretty advanced with our Pi-hole v5.1 preparations and it would be absolutely awesome if we could get the fix for this still in there!

[MichaelVoelkel]

You should've got mail @DL6ER

[DL6ER]

@MichaelVoelkel Thanks, this bug is really hard to catch, I'm concerned that it is not a real single bug, but more a more severe subtle memory issue somewhere in the dnsmasq code. Whenever I add debugging output to somewhere, the crash seems to be happening in another place. Your log via mail (thanks for that!) shows that the crash is happening in cache_recv_insert what is exactly the same as has only been reported yesterday in https://github.com/pi-hole/FTL/issues/806

Could you maybe run the following lines?

sudo sudo setcap -r /usr/bin/pihole-FTL
sudo valgrind --leak-check=full -v pihole-FTL -f > >(tee -a stdout.log) 2> >(tee -a stderr.log >&2)

This will launch pihole-FTL under memory supervision. You may need to install valgrind, first. It will generate a lot of output and put this into stdout.log and stderr.log in the folder where you ran the command. This should hopefully finally contain the memory issue details I need for this... Thanks for your continued assistance!

[MichaelVoelkel]

@DL6ER I have this running for 24 hours now again, no crash so far. But I am not sure whether I started this correctly. UI shows "Active green" but "FTL offline red" since from the very beginning. But DNS on Pihole still works (checked with nslookup). stderr is 1.5M big already, though, I could send you an interim state if it helps

[DL6ER]

@MichaelVoelkel Thanks, if you send me the intermediate state, I can take a look at what is in there, maybe there are already pointers to memory violations in there.

[MichaelVoelkel]

@DL6ER you should've got mail again

[fhriley]

Thanks, this bug is really hard to catch, I'm concerned that it is not a real single bug, but more a more severe subtle memory issue somewhere in the dnsmasq code. Whenever I add debugging output to somewhere, the crash seems to be happening in another place.

I highly doubt it is an issue in the dnsmasq code that wasn't introduced by pihole. I've been writing low level/HPC code for a long time, and I can tell you the design of pihole is such that it is very easy to accidentally create dangling pointer bugs. When a function call can move memory from underneath you, it's going to be a fragile design. Dangling pointer bugs are exactly as you're describing: very difficult to find and they manifest in random ways. I've found (and you've fixed) a couple, and I think I saw at least one other that you fixed. I would have these users run the development branch and see if it is already fixed. I suspect it may be.

[DL6ER]

I highly doubt it is an issue in the dnsmasq code that wasn't introduced by pihole.

I can tell you the design of pihole is such that it is very easy to accidentally create dangling pointer bugs

I'd like to see more evidence for these two points. Especially about the first one. Mind that dnsmasq only recently introduced a new feature that matches what we found, so far, quoting from the dnsmasq change log:

Improve cache behavior for TCP connections.
For ease of implementation, we always forked a new process to handle each incoming TCP connection. A side-effect of this is that any DNS queries answered from TCP connections are not cached: when TCP connections were rare, this was not a problem. With the coming of DNSSEC, it's now the case that some DNSSEC queries have answers which spill to TCP, and if, for instance, this applies to the keys for the root then those never get cached, and performance is very bad. This fix passes cache entries back from the TCP child process to the main server process, and fixes the problem.

Here, the same (so far unknown) domain is queried simultaneously over UDP and TCP. As dnsmasq is not using any locks anywhere, what leads you to the conclusion that this is a Pi-hole caused bug? Mind that the dangling pointer is in all bug reports known so far in the daemon pointer. An object we never touch. Further, mind that the daemon struct is allocated pretty far away from any other Pi-hole related memory so accidentally writing into this object is unlikely (even if not impossible, I totally agree on that).

The dangling pointers we've seen in Pi-hole's memory always caused a crash exactly here, in Pi-hole's code. Never in dnsmasq's code. Again, this is not saying that it is impossible that it was been caused by us, it just says I find it unlikely.

The sole reason for why this hasn't been found and reported for dnsmasq may be that Pi-hole adopted dnsmasq v2.81 early on and we have a very large user base, so a wide testing area. For instance, Ubuntu 20.04 (focal) hasn't even picked up dnsmasq v2.81 and many replaced the internal resolver by systemd-resolved so we may just be the first ones to see it.

What do you think given these points?

[fhriley]

Here, the same (so far unknown) domain is queried _simultaneously_ over UDP and TCP. As dnsmasq is not using any locks anywhere

The design of dnsmasq is such that it doesn't need any locks. I'm not saying it is impossible for there to be a bug in dnsmasq, but given the design of the pihole code, I find it much more likely that it is in pihole. My opinion remains the same on that. I also still think you should have these people run the development branch, or even release a point release with the fixes you've already made. I have a special build that easily reproduces problems in v5.0, but not on the development branch.

[DL6ER]

Thanks, but you missed my point slightly. I'm not criticizing dnsmasq's design, not a single bit, it is just not something we could have picked up as FTL's tasks are complex and threads surrounding the main engine are there to both keep things simple, separated and maintainable. Locks are the price to pay here, but, as the nature of the underlying dnsmasq is (mostly) sequential, they are usually never needed in FTL. The most important exception are periodic jobs like storing queries in the database, which is done once a minute.

The difference between the issues we have seen and the one discussed here is that the dnsmasq_daemon variable and "our" FTL variables are megabytes away from each other (there is the entire DNS cache in between). At least on x86_64 where I checked the memory mapping manually. The issues we have seen with incorrect pointers in FTL always lead to a crash in FTL's code. However, all the open discussions we have right now show crashed all related to reading content of daemon. Sure, users switching to development will not hurt, and I can recommend this. It would still surprise me if it changes anything. Mind that there is at least one report that stated that since switching to my debugging branch (which does nothing else than adding prints in the code), the issue went away. So we have to be careful with success messages, even.

I have been very busy with traveling and they severely affected my debugging abilities over the past two weeks, however, I reserved some time next week where I will try again to reproduce the bug locally with all the tools attached. And if this takes that I go and buy a (hopefully not too expensive) laptop with Office on it, then I'll likely even do that. I feel responsible for the code I wrote and promise do my best to finally resolve this issue for everyone!

[DL6ER]

@MichaelVoelkel @shartenauer Could you give

pihole checkout ftl development

a try? We changed quite a bit since v5.0. I'm not convinced that it will resolve the issue for you, however, we will only know for sure when you tried it.

[MichaelVoelkel]

Alright, will do. Let’s see if that helps

Am 12.06.2020 um 21:45 schrieb DL6ER [e-mail]:

@MichaelVoelkel https://github.com/MichaelVoelkel @shartenauer https://github.com/shartenauer Could you give

pihole checkout ftl development
a try? We changed quite a bit since v5.0. I'm not convinced that it will resolve the issue for you, however, we will only know for sure when you tried it.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub https://github.com/pi-hole/FTL/issues/805#issuecomment-643453676, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACJPCHQOHR7HRYK4E6MJCQTRWKATZANCNFSM4NWHZCMQ.

[fhriley]

I confirm this is a bug in dnsmasq! I have a way to reproduce it reliably. Anyone know where to file bugs against dnsmasq? All I can find is the debian bug tracker.

[DL6ER]

I confirm this is a bug in dnsmasq!

Thanks. A reliable way of reproducing this bug is great news!

Anyone know where to file bugs against dnsmasq?

There is only one way of doing this, via the official mailing list. Nothing else will be read by the maintainer, Simon Kelley.

[email protected]

IIRC you may need to subscribe to be able to post to the list. You can do this here: http://lists.thekelleys.org.uk/mailman/listinfo/dnsmasq-discuss

---

Do you already have a patch that fixes it? If not, would you mind sharing your findings so we can work on fixing this as soon as possible (I assume you will put the details in your mail anyways)? My experience over years is that the availability of Simon varies quite a lot. From replies within hours to replies taking weeks to months in extreme cases.

The easier the fix is for him (an attached bugfix patch is very easy), the sooner it will land. I will make sure to cherry-pick the fix into Pi-hole v5.1 when we have it. No need to wait for the next dnsmasq release with bug fixes.

[fhriley]

I have this fixed. I will be submitting a patch to dnsmasq. Do you want me to submit a pull request here so you can fix it until a new dnsmasq is released?

[DL6ER]

@MichaelVoelkel @shartenauer Please run

pihole checkout ftl fix/fhriley-fix_buf_overflow

if you are still experiencing issues (no harm in trying even when development is crash-free for you).
As always, I very much appreciate testing as it is the only way to be sure we really got it fixed!

[shartenauer]

After 4 weeks without any probles with pihole, I had 3 crashes in the last 2 days.
Today I installed the Fix fhriley-fix_buf_overflow.
Best regards Stephan