pi-hole / FTL

The Pi-hole FTL engine
https://pi-hole.net
Other
1.38k stars 196 forks source link

Random FTL crashes when using the Admin panel on Pi 4 #2078

Open moberlander08 opened 1 month ago

moberlander08 commented 1 month ago

Versions

Pi-hole version is v5.18.3 (Latest: N/A) web version is v5.21 (Latest: N/A) FTL version is v5.25.2 (Latest: N/A)

Platform

Debian Bookworm 12 Raspberry Pi 4

Expected behavior

I was attempting to mange my pi-hole using the Admin panel and kept getting spinning dashboards (no data was loading), as well as a locked up web page as in no interaction with the web form was possible. Sometimes when the page does load, I get a socket warning from within the Settings page.

PHP error (2): fsockopen(): Unable to connect to 127.0.0.1:4711 (Connection refused) in /var/www/html/admin/scripts/pi-hole/php/FTL.php:47

Actual behavior / bug

Best guess based on troubleshooting the dns-FTL service crashes after some limited operation/run time and breaks the whole stack.

Steps to reproduce

Sometime the Admin panel will just lock up and become unresponsive just by loading the main page. Additionally loading the Setting page will cause the socket warning to appear.

Debug Token

Screenshots

If applicable, add screenshots to help explain your problem.

Additional context

I can confirm that this was happening on this particular pi before and after a full OS reload. Note I have a second pi on my network that I is running a decently older version of pihole and does not appear to be having an issue at this time.

Image

moberlander08 commented 1 month ago

Adding pihole-FTL.log crash report for more details.

[2024-10-08 21:30:18.775 913/F763] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! [2024-10-08 21:30:18.775 913/F763] ----------------------------> FTL crashed! <---------------------------- [2024-10-08 21:30:18.775 913/F763] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! [2024-10-08 21:30:18.775 913/F763] Please report a bug at https://github.com/pi-hole/FTL/issues [2024-10-08 21:30:18.775 913/F763] and include in your report already the following details: [2024-10-08 21:30:18.775 913/F763] FTL has been running for 745 seconds [2024-10-08 21:30:18.775 913/F763] FTL branch: master [2024-10-08 21:30:18.775 913/F763] FTL version: v5.25.2 [2024-10-08 21:30:18.775 913/F763] FTL commit: 8943e260 [2024-10-08 21:30:18.775 913/F763] FTL date: 2024-05-08 20:59:50 +0100 [2024-10-08 21:30:18.775 913/F763] FTL user: started as pihole, ended as pihole [2024-10-08 21:30:18.775 913/F763] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 8.3.0-2) 8.3.0 [2024-10-08 21:30:18.775 913/F763] Process details: MID: 763 [2024-10-08 21:30:18.775 913/F763] PID: 913 [2024-10-08 21:30:18.775 913/F763] TID: 913 [2024-10-08 21:30:18.775 913/F763] Name: pihole-FTL [2024-10-08 21:30:18.775 913/F763] Received signal: Segmentation fault [2024-10-08 21:30:18.775 913/F763] at address: (nil) [2024-10-08 21:30:18.775 913/F763] with code: SEGV_MAPERR (Address not mapped to object) [2024-10-08 21:30:18.778 913/F763] Backtrace: [2024-10-08 21:30:18.779 913/F763] B[0000]: /usr/bin/pihole-FTL(generate_backtrace+0x38) [0x557f49bec0]

[2024-10-08 21:30:19.037 913/F763] B[0001]: /usr/bin/pihole-FTL(+0x5c394) [0x557f49c394]

[2024-10-08 21:30:19.059 913/F763] B[0002]: linux-vdso.so.1(__kernel_rt_sigreturn+0) [0x7fb92f07b0] [2024-10-08 21:30:19.059 913/F763] B[0003]: /usr/bin/pihole-FTL(get_sqlite3_stmt_vec+0x34) [0x557f49cd9c]

[2024-10-08 21:30:19.081 913/F763] B[0004]: /usr/bin/pihole-FTL(+0x64cc0) [0x557f4a4cc0]

[2024-10-08 21:30:19.104 913/F763] B[0005]: /usr/bin/pihole-FTL(FTL_TCP_worker_terminating+0x84) [0x557f4900c4]

[2024-10-08 21:30:19.129 913/F763] B[0006]: /usr/bin/pihole-FTL(+0x81238) [0x557f4c1238]

[2024-10-08 21:30:19.157 913/F763] B[0007]: /usr/bin/pihole-FTL(main_dnsmasq+0x16a8) [0x557f4c3470]

[2024-10-08 21:30:19.185 913/F763] B[0008]: /usr/bin/pihole-FTL(main+0x100) [0x557f482560]

[2024-10-08 21:30:19.206 913/F763] B[0009]: /lib/aarch64-linux-gnu/libc.so.6(+0x27740) [0x7fb9037740] [2024-10-08 21:30:19.206 913/F763] B[0010]: /lib/aarch64-linux-gnu/libc.so.6(__libc_start_main+0x98) [0x7fb9037818] [2024-10-08 21:30:19.206 913/F763] B[0011]: /usr/bin/pihole-FTL(+0x42a28) [0x557f482a28]

[2024-10-08 21:30:19.251 913/F763] ------ Listing content of directory /dev/shm ------ [2024-10-08 21:30:19.251 913/F763] File Mode User:Group Size Filename [2024-10-08 21:30:19.251 913/F763] rwxrwxrwx root:root 260 . [2024-10-08 21:30:19.251 913/F763] rwxr-xr-x root:root 4K .. [2024-10-08 21:30:19.251 913/F763] rw------- pihole:pihole 104 FTL-lock [2024-10-08 21:30:19.251 913/F763] rw------- pihole:pihole 248 FTL-counters [2024-10-08 21:30:19.251 913/F763] rw------- pihole:pihole 16 FTL-settings [2024-10-08 21:30:19.251 913/F763] rw------- pihole:pihole 655K FTL-strings [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 86K FTL-domains [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 22M FTL-clients [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 315K FTL-upstreams [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 6M FTL-queries [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 8K FTL-overTime [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 4K FTL-dns-cache [2024-10-08 21:30:19.252 913/F763] rw------- pihole:pihole 4K FTL-per-client-regex [2024-10-08 21:30:19.252 913/F763] --------------------------------------------------- [2024-10-08 21:30:19.252 913/F763] Please also include some lines from above the !!!!!!!!! header. [2024-10-08 21:30:19.252 913/F763] Thank you for helping us to improve our FTL engine! [2024-10-08 21:30:19.252 913/F763] Asking parent pihole-FTL (PID 763) to shut down [2024-10-08 21:30:19.252 913/F763] FTL fork terminated! [2024-10-08 21:30:19.252 763M] Received: Real-time signal 2 (36 -> 2) [2024-10-08 22:38:45.172 1367M] Using log file /var/log/pihole/FTL.log [2024-10-08 22:38:45.172 1367M] ########## FTL started on raspberrypi! ########## [2024-10-08 22:38:45.172 1367M] FTL branch: master [2024-10-08 22:38:45.172 1367M] FTL version: v5.25.2 [2024-10-08 22:38:45.172 1367M] FTL commit: 8943e260 [2024-10-08 22:38:45.172 1367M] FTL date: 2024-05-08 20:59:50 +0100 [2024-10-08 22:38:45.172 1367M] FTL user: pihole [2024-10-08 22:38:45.173 1367M] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 8.3.0-2) 8.3.0 [2024-10-08 22:38:45.173 1367M] Starting config file parsing (/etc/pihole/pihole-FTL.conf) [2024-10-08 22:38:45.173 1367M] SOCKET_LISTENING: only local [2024-10-08 22:38:45.173 1367M] AAAA_QUERY_ANALYSIS: Show AAAA queries [2024-10-08 22:38:45.173 1367M] MAXDBDAYS: max age for stored queries is 365 days [2024-10-08 22:38:45.173 1367M] RESOLVE_IPV6: Resolve IPv6 addresses [2024-10-08 22:38:45.173 1367M] RESOLVE_IPV4: Resolve IPv4 addresses [2024-10-08 22:38:45.173 1367M] DBINTERVAL: saving to DB file every minute [2024-10-08 22:38:45.173 1367M] DBFILE: Using /etc/pihole/pihole-FTL.db -- VISUAL -- 62 1993,70 56%

rdwebdesign commented 1 month ago

From your description, the web interface is just showing symptoms (spinning dashboards, PHP socket error, etc) of a crashed FTL.

Can you please include a few lines before the

[2024-10-08 21:30:18.775 913/F763] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2024-10-08 21:30:18.775 913/F763] ----------------------------> FTL crashed! <----------------------------
[2024-10-08 21:30:18.775 913/F763] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

?

rdwebdesign commented 1 month ago

Unrelated to your issue, I found a typo in your pihole-FTL.conf:

-rw-rw-r-- 1 pihole root 162 Oct  8 22:38 /etc/pihole/pihole-FTL.conf
   PRIVACYLEVEL=0
   RATE_LIMIT=1000/60
   DEBUG_ALL=true`

The last value should be true or false, not true`.

moberlander08 commented 1 month ago

Update has been made and pi has been rebooted, fingers crossed.

DL6ER commented 1 month ago

Also have a look at https://github.com/pi-hole/FTL/issues/2079#issuecomment-2405082734

Both FTL system crashing at exactly the same location

[2024-10-10 01:33:03.563 3893957/F2635349] B[0003]: /usr/bin/pihole-FTL(get_sqlite3_stmt_vec+0x34) [0x556880cd9c]
[2024-10-10 01:33:03.609 3893957/F2635349] L[0003]: /__w/FTL/FTL/src/vector.c:101

is really puzzling because this code has last been changed April 6th, 2020 (!) in https://github.com/pi-hole/FTL/commit/c9eb4a1265632a51711c4d4a43548ea7b94379b5

moberlander08 commented 1 month ago

Saw that an update was made in the mention above, take it I should attempt to update or wait for more updates?

moberlander08 commented 1 month ago

@rdwebdesign Sorry for the delay, as requested here are the log entries you requested.

[2024-10-08 23:17:43.713 732M] Resizing "FTL-clients" from 23482368 to (35072 * 672) == 23568384 (/dev/shm: 30.3MB used, 2.0GB total, FTL uses 30.3MB)
[2024-10-08 23:17:46.274 732M] Resizing "FTL-clients" from 23568384 to (35200 * 672) == 23654400 (/dev/shm: 30.4MB used, 2.0GB total, FTL uses 30.4MB)
[2024-10-08 23:17:48.819 732M] Imported 100066 queries from the long-term database
[2024-10-08 23:17:48.820 732M]  -> Total DNS queries: 100066
[2024-10-08 23:17:48.820 732M]  -> Cached DNS queries: 2060
[2024-10-08 23:17:48.820 732M]  -> Forwarded DNS queries: 83547
[2024-10-08 23:17:48.820 732M]  -> Blocked DNS queries: 32
[2024-10-08 23:17:48.820 732M]  -> Unknown DNS queries: 0
[2024-10-08 23:17:48.820 732M]  -> Unique domains: 3164
[2024-10-08 23:17:48.820 732M]  -> Unique clients: 35193
[2024-10-08 23:17:48.820 732M]  -> Known forward destinations: 3
[2024-10-08 23:17:48.820 732M] Successfully accessed setupVars.conf
[2024-10-08 23:17:48.831 732M] listening on 0.0.0.0 port 53
[2024-10-08 23:17:48.831 732M] listening on :: port 53
[2024-10-08 23:17:48.836 732M] PID of FTL process: 732
[2024-10-08 23:17:48.836 732M] Listening on port 4711 for incoming IPv4 telnet connections
[2024-10-08 23:17:48.837 732M] Error binding to IPv6 telnet socket: Cannot assign requested address (99)
[2024-10-08 23:17:48.837 732M] WARN: Cannot bind to IPv6 telnet socket
[2024-10-08 23:17:48.837 732M] Listening on port 4711 for incoming socket telnet connections
[2024-10-08 23:17:48.837 732M] INFO: FTL is running as user pihole (UID 999)
[2024-10-08 23:17:48.839 732M] Reloading DNS cache
[2024-10-08 23:17:48.950 732/T1139] Compiled 0 whitelist and 0 blacklist regex filters for 35193 clients in 7.1 msec
[2024-10-08 23:17:48.950 732/T1139] Blocking status is disabled
[2024-10-08 23:17:54.536 732M] Resizing "FTL-clients" from 23654400 to (35328 * 672) == 23740416 (/dev/shm: 30.5MB used, 2.0GB total, FTL uses 30.5MB)
[2024-10-08 23:18:53.362 732M] Resizing "FTL-clients" from 23740416 to (35456 * 672) == 23826432 (/dev/shm: 30.6MB used, 2.0GB total, FTL uses 30.5MB)
[2024-10-08 23:19:05.509 732/T1139] Resizing "FTL-clients" from 23826432 to (35584 * 672) == 23912448 (/dev/shm: 30.6MB used, 2.0GB total, FTL uses 30.6MB)
[2024-10-08 23:19:07.144 732M] Resizing "FTL-queries" from 5734400 to (106496 * 56) == 5963776 (/dev/shm: 30.7MB used, 2.0GB total, FTL uses 30.7MB)
[2024-10-08 23:19:14.611 732M] Resizing "FTL-clients" from 23912448 to (35712 * 672) == 23998464 (/dev/shm: 31.0MB used, 2.0GB total, FTL uses 30.9MB)
[2024-10-08 23:19:17.206 732M] Resizing "FTL-strings" from 655360 to (696320 * 1) == 696320 (/dev/shm: 31.0MB used, 2.0GB total, FTL uses 31.0MB)
[2024-10-08 23:19:19.536 732M] Resizing "FTL-clients" from 23998464 to (35840 * 672) == 24084480 (/dev/shm: 31.1MB used, 2.0GB total, FTL uses 31.1MB)
[2024-10-08 23:19:30.778 1155/F732] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2024-10-08 23:19:30.779 1155/F732] ---------------------------->  FTL crashed!  <----------------------------
[2024-10-08 23:19:30.779 1155/F732] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
DL6ER commented 1 month ago

We merged a fix for the upcoming Pi-hole v6, there won't be any further v5 release, sorry, I'm still unable to reproduce this issue here so it's unclear if the fix is sufficient. Can you reproduce it reliably (see my comment in the other issue ticket)? You said "sometimes" above.