FTL Crash

[josh-h]

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: 8943e26
[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.512 3893957/F2635349] L[0000]: /__w/FTL/FTL/src/signals.c:98
[2024-10-10 01:33:03.516 3893957/F2635349] B[0001]: /usr/bin/pihole-FTL(+0x5c394) [0x556880c394]
[2024-10-10 01:33:03.558 3893957/F2635349] L[0001]: /__w/FTL/FTL/src/signals.c:242
[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.609 3893957/F2635349] L[0003]: /__w/FTL/FTL/src/vector.c:101
[2024-10-10 01:33:03.613 3893957/F2635349] B[0004]: /usr/bin/pihole-FTL(+0x64cc0) [0x5568814cc0]
[2024-10-10 01:33:03.656 3893957/F2635349] L[0004]: /__w/FTL/FTL/src/database/gravity-db.c:949
[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.706 3893957/F2635349] L[0005]: /__w/FTL/FTL/src/dnsmasq_interface.c:3144
[2024-10-10 01:33:03.710 3893957/F2635349] B[0006]: /usr/bin/pihole-FTL(+0x81238) [0x5568831238]
[2024-10-10 01:33:03.760 3893957/F2635349] L[0006]: /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:2076
[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.816 3893957/F2635349] L[0007]: /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1281
[2024-10-10 01:33:03.821 3893957/F2635349] B[0008]: /usr/bin/pihole-FTL(main+0x100) [0x55687f2560]
[2024-10-10 01:33:03.867 3893957/F2635349] L[0008]: /__w/FTL/FTL/src/main.c:118
[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.943 3893957/F2635349] L[0011]: ??:?
[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]

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.