search

pi-hole / FTL

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

FTL Crash #2079

Open josh-h opened 2 days ago

josh-h commented 2 days ago

Versions

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

Platform

Running Debian Bookworm 12.6. Specifically, dietpi on a raspberry pi v4

Crash log

[2024-10-10 01:09:03.533 2635349/T2635430] Notice: Database size is 286.34 MB, deleted 1326 rows [2024-10-10 01:10:55.886 2635349M] Resizing "FTL-dns-cache" from 14221312 to (889088 16) == 14225408 (/dev/shm: 47.8MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:14:34.159 2635349M] Resizing "FTL-dns-cache" from 14225408 to (889344 16) == 14229504 (/dev/shm: 47.8MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:16:40.976 2635349M] Resizing "FTL-dns-cache" from 14229504 to (889600 16) == 14233600 (/dev/shm: 47.9MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:20:02.055 2635349/T2635430] Notice: Database size is 286.34 MB, deleted 1513 rows [2024-10-10 01:21:34.130 2635349M] Resizing "FTL-dns-cache" from 14233600 to (889856 16) == 14237696 (/dev/shm: 47.9MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:21:58.889 2635349M] Resizing "FTL-strings" from 3235840 to (3276800 1) == 3276800 (/dev/shm: 47.9MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:24:16.035 2635349M] Resizing "FTL-dns-cache" from 14237696 to (890112 16) == 14241792 (/dev/shm: 47.9MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:25:05.660 2635349/T2635430] Resizing "FTL-dns-cache" from 14241792 to (890368 * 16) == 14245888 (/dev/shm: 47.9MB used, 2.0GB total, FTL uses 47.5MB) [2024-10-10 01:30:01.568 2635349/T2635430] Notice: Database size is 286.34 MB, deleted 2433 rows [2024-10-10 01:33:03.177 3893957/F2635349] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! [2024-10-10 01:33:03.178 3893957/F2635349] ----------------------------> FTL crashed! <---------------------------- [2024-10-10 01:33:03.178 3893957/F2635349] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! [2024-10-10 01:33:03.178 3893957/F2635349] Please report a bug at https://github.com/pi-hole/FTL/issues [2024-10-10 01:33:03.178 3893957/F2635349] and include in your report already the following details: [2024-10-10 01:33:03.178 3893957/F2635349] FTL has been running for 769269 seconds [2024-10-10 01:33:03.178 3893957/F2635349] FTL branch: master [2024-10-10 01:33:03.178 3893957/F2635349] FTL version: v5.25.2 [2024-10-10 01:33:03.179 3893957/F2635349] FTL commit: 8943e260 [2024-10-10 01:33:03.179 3893957/F2635349] FTL date: 2024-05-08 20:59:50 +0100 [2024-10-10 01:33:03.179 3893957/F2635349] FTL user: started as pihole, ended as pihole [2024-10-10 01:33:03.179 3893957/F2635349] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 8.3.0-2) 8.3.0 [2024-10-10 01:33:03.179 3893957/F2635349] Process details: MID: 2635349 [2024-10-10 01:33:03.179 3893957/F2635349] PID: 3893957 [2024-10-10 01:33:03.179 3893957/F2635349] TID: 3893957 [2024-10-10 01:33:03.179 3893957/F2635349] Name: pihole-FTL [2024-10-10 01:33:03.179 3893957/F2635349] Received signal: Segmentation fault [2024-10-10 01:33:03.179 3893957/F2635349] at address: (nil) [2024-10-10 01:33:03.179 3893957/F2635349] with code: SEGV_MAPERR (Address not mapped to object) [2024-10-10 01:33:03.201 3893957/F2635349] Backtrace: [2024-10-10 01:33:03.201 3893957/F2635349] B[0000]: /usr/bin/pihole-FTL(generate_backtrace+0x38) [0x556880bec0]

[2024-10-10 01:33:03.516 3893957/F2635349] B[0001]: /usr/bin/pihole-FTL(+0x5c394) [0x556880c394]

[2024-10-10 01:33:03.563 3893957/F2635349] B[0002]: linux-vdso.so.1(__kernel_rt_sigreturn+0) [0x7f8346a7a8] [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.613 3893957/F2635349] B[0004]: /usr/bin/pihole-FTL(+0x64cc0) [0x5568814cc0]

[2024-10-10 01:33:03.660 3893957/F2635349] B[0005]: /usr/bin/pihole-FTL(FTL_TCP_worker_terminating+0x84) [0x55688000c4]

[2024-10-10 01:33:03.710 3893957/F2635349] B[0006]: /usr/bin/pihole-FTL(+0x81238) [0x5568831238]

[2024-10-10 01:33:03.766 3893957/F2635349] B[0007]: /usr/bin/pihole-FTL(main_dnsmasq+0x16a8) [0x5568833470]

[2024-10-10 01:33:03.821 3893957/F2635349] B[0008]: /usr/bin/pihole-FTL(main+0x100) [0x55687f2560]

[2024-10-10 01:33:03.872 3893957/F2635349] B[0009]: /lib/aarch64-linux-gnu/libc.so.6(+0x27780) [0x7f831a7780] [2024-10-10 01:33:03.872 3893957/F2635349] B[0010]: /lib/aarch64-linux-gnu/libc.so.6(__libc_start_main+0x98) [0x7f831a7858] [2024-10-10 01:33:03.872 3893957/F2635349] B[0011]: /usr/bin/pihole-FTL(+0x42a28) [0x55687f2a28]

[2024-10-10 01:33:03.953 3893957/F2635349] ------ Listing content of directory /dev/shm ------ [2024-10-10 01:33:03.953 3893957/F2635349] File Mode User:Group Size Filename [2024-10-10 01:33:03.954 3893957/F2635349] rwxrwxrwx root:root 680 . [2024-10-10 01:33:03.954 3893957/F2635349] rwxr-xr-x root:root 4K .. [2024-10-10 01:33:03.954 3893957/F2635349] rw------- root:root 5K mongoc-3893431 [2024-10-10 01:33:03.954 3893957/F2635349] rw------- root:root 5K mongoc-3318693 [2024-10-10 01:33:03.954 3893957/F2635349] rw------- root:root 5K mongoc-2760553 [2024-10-10 01:33:03.954 3893957/F2635349] rw------- pihole:pihole 25K FTL-per-client-regex [2024-10-10 01:33:03.955 3893957/F2635349] rw------- pihole:pihole 14M FTL-dns-cache [2024-10-10 01:33:03.955 3893957/F2635349] rw------- pihole:pihole 8K FTL-overTime [2024-10-10 01:33:03.955 3893957/F2635349] rw------- pihole:pihole 13M FTL-queries [2024-10-10 01:33:03.955 3893957/F2635349] rw------- pihole:pihole 315K FTL-upstreams [2024-10-10 01:33:03.955 3893957/F2635349] rw------- pihole:pihole 16M FTL-clients [2024-10-10 01:33:03.955 3893957/F2635349] rw------- pihole:pihole 860K FTL-domains [2024-10-10 01:33:03.956 3893957/F2635349] rw------- pihole:pihole 3M FTL-strings [2024-10-10 01:33:03.956 3893957/F2635349] rw------- pihole:pihole 16 FTL-settings [2024-10-10 01:33:03.956 3893957/F2635349] rw------- pihole:pihole 248 FTL-counters [2024-10-10 01:33:03.956 3893957/F2635349] rw------- pihole:pihole 104 FTL-lock [2024-10-10 01:33:03.956 3893957/F2635349] rw------- root:root 5K mongoc-2624492 [2024-10-10 01:33:03.957 3893957/F2635349] rw------- root:root 5K mongoc-2483025 [2024-10-10 01:33:03.957 3893957/F2635349] rw------- root:root 5K mongoc-2340503 [2024-10-10 01:33:03.957 3893957/F2635349] rw------- root:root 5K mongoc-1914129 [2024-10-10 01:33:03.957 3893957/F2635349] rw------- root:root 5K mongoc-1627137 [2024-10-10 01:33:03.957 3893957/F2635349] rw------- root:root 5K mongoc-1484623 [2024-10-10 01:33:03.957 3893957/F2635349] rw------- root:root 5K mongoc-1040710 [2024-10-10 01:33:03.958 3893957/F2635349] rw------- root:root 5K mongoc-481483 [2024-10-10 01:33:03.958 3893957/F2635349] rw------- root:root 5K mongoc-201954 [2024-10-10 01:33:03.958 3893957/F2635349] rw------- root:root 5K mongoc-3945760 [2024-10-10 01:33:03.958 3893957/F2635349] rw------- root:root 5K mongoc-3329702 [2024-10-10 01:33:03.958 3893957/F2635349] rw------- root:root 5K mongoc-3183795 [2024-10-10 01:33:03.958 3893957/F2635349] rw------- root:root 5K mongoc-2463026 [2024-10-10 01:33:03.958 3893957/F2635349] rw-r----- sonarr:dietpi 4K mono.456533 [2024-10-10 01:33:03.959 3893957/F2635349] rw------- root:root 5K mongoc-316990 [2024-10-10 01:33:03.959 3893957/F2635349] rw-rw---- netdata:netdata 32 sem.netdata_sem_cgroup_ebpf [2024-10-10 01:33:03.959 3893957/F2635349] rw-rw---- netdata:netdata 4M netdata_shm_cgroup_ebpf [2024-10-10 01:33:03.959 3893957/F2635349] rw------- root:root 5K mongoc-708 [2024-10-10 01:33:03.960 3893957/F2635349] --------------------------------------------------- [2024-10-10 01:33:03.960 3893957/F2635349] Please also include some lines from above the !!!!!!!!! header. [2024-10-10 01:33:03.960 3893957/F2635349] Thank you for helping us to improve our FTL engine! [2024-10-10 01:33:03.960 3893957/F2635349] Asking parent pihole-FTL (PID 2635349) to shut down [2024-10-10 01:33:03.960 2635349M] Received: Real-time signal 2 (36 -> 2)

In syslog I have the following as well:

2024-10-10T01:32:58.252599+01:00 pi kernel: [4957445.547581] vm_enough_memory: 2 callbacks suppressed 2024-10-10T01:32:58.252641+01:00 pi kernel: [4957445.547598] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252645+01:00 pi kernel: [4957445.547618] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252648+01:00 pi kernel: [4957445.547632] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252651+01:00 pi kernel: [4957445.548833] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252653+01:00 pi kernel: [4957445.548859] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252655+01:00 pi kernel: [4957445.548872] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252657+01:00 pi kernel: [4957445.548885] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252659+01:00 pi kernel: [4957445.548897] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252662+01:00 pi kernel: [4957445.548909] vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:32:58.252664+01:00 pi kernel: [4957445.548921] __vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation 2024-10-10T01:33:04.181382+01:00 pi systemd[1]: pihole-FTL.service: Deactivated successfully. 2024-10-10T01:33:04.182039+01:00 pi systemd[1]: pihole-FTL.service: Consumed 20h 51min 30.677s CPU time.

Curiously, my system was reporting 1.2gb of free memory at the time in the logs.

I became aware of this issue because DNS queries failed to respond, and the service appeared to have stopped listening to requests.

This happens to me every couple of weeks, I only noticed the crash log tonight as I was investigating. Normally I simply restart the service to restore service.

DL6ER commented 1 day ago

Those __vm_enough_memory: pid: 3893957, comm: pihole-FTL, no enough memory for the allocation do look suspicious to me, interestingly, the seems to be the very same crash as reported at almost exactly the same time by a different user in #2078.

Can you somehow reproduce it? If so, it may be interesting to set DEBUG_VECTORS=true in you /etc/pihole/pihole-FTL.conf to get some more debug output before the crash happens.