FTLv5.3.2 Engine Crash

Expected Behaviour:

FTL Engine running

Actual Behaviour:

FTL Engine v5.3.2 crashes and requires a manual restart. Has happened a few times now, other logs showed same system call failing. Device is RaspberryPi 3B+ and PiHole is the only application running.

Debug Token:

https://tricorder.pi-hole.net/neiimbvz70

Details?

I actually had the FTL engine crash again after I posted this. And another I found in an older log from yesterday. realloc_shm() has been consistently the process causing the engine to crash.

[2020-12-07 01:36:08.593 720M] Resizing "FTL-queries" from 10780672 to (196608 * 56) == 11010048 (/dev/shm: 11.3MB used, 485.5MB total)
[2020-12-07 01:36:08.597 720M] FATAL: realloc_shm(): Failed to resize "FTL-queries" (12) to 11010048: Interrupted system call (-1)

[2020-12-08 07:42:54.310 717M] Resizing "FTL-queries" from 7798784 to (143360 * 56) == 8028160 (/dev/shm: 8.4MB used, 485.5MB total)
[2020-12-08 07:42:54.315 717M] FATAL: realloc_shm(): Failed to resize "FTL-queries" (13) to 8028160: Interrupted system call (-1)
[2020-12-08 07:57:23.835 582M] Using log file /var/log/pihole-FTL.log
[2020-12-08 07:57:23.841 582M] ########## FTL started! ##########

How much memory is on the host platform for Pi-hole?

Results from running pihole -c
Task Load: 0.06 0.02 0.00 (Active: 0 of 52 tasks)
CPU usage: 1% (4x 600 MHz @ 125f)
RAM usage: 13% (Used: 121 MB of 926 MB)
HDD usage: 21% (Used: 6 GB of 29 GB)

Current FTL memory stats. Read the docs and cache evictions has never risen above 0 so left unchanged. PiHole is not configured as a DCHP server. My router is running DD-WRT, PiHole is device on LAN then I forward DNS requests to the Pi using dchp-option=6 method.

Does this gap in between mean it crashed? If so, why isn't there a gap here?

Have you been interacting with Pi-hole at this time or did the crash happen in your absence? I'm asking because of Interrupted system call which happens when a signal arrives during some system call. @DL6ER for input!

If a realloc() call is interrupted by an incoming signal (whatever origin it may have), this can lead to all sorts of bad things. I'm working on a patch making all system calls interrupt-safe for FTL while we speak.
Ideally, nobody should be sending random signals to FTL (Pi-hole specific signals would have been noted in the log file), however, I know we are not living in a perfect world.

Stay tuned for a PR and testing instructions to arrive here soon(ish).

This gap was the first time I noticed the crash when I realized I couldn't load external sites. With the setup I'm running, WiFi will still be connected so interacting with internal services is not interrupted. Being SSH'ed into other containers, I hadn't noticed external sites failing to load. At this point I simply restarted my Pi, problem resolved so I brushed it off and thought nothing of it until it happened again a few hours later. I've been working on micro services and containers but those are hosted on a server running Proxmox. Only thing I've done to the Pi is update PiHole and run system updates (OS is Rasbian). No other changes have been made.

Is this incoming system call something I should investigate further?

Please try whether this fixes your issue (it should at least avoid the Interrupted system call errors):

pihole checkout ftl tweak/interruptsafe_systemcalls

FTL is now running vDev-ab0daeb
Will monitor and report back if I notice any further crashes

I also checked out the branch. It is very clever to implement interrupt-safe system calls this way. I am very experienced with programming (also low-level) but can learn something new every day from you guys.

I experienced another crash running the dev version. Hasn't happened since but now happened twice, was able to catch it this time as I was in an SSH session trying to find the first crash.

Upload to tricoder failed when running, but here the main crash. I did save the full debug log as well if you would a copy. I didn't see any options the PiHole menu to re-upload.

*** [ DIAGNOSING ]: contents of /var/log

-rw-r--r-- 1 pihole pihole 2233 Dec 22 02:29 /var/log/pihole-FTL.log
   -----head of pihole-FTL.log------
   [2020-12-22 00:24:56.598 746M] Resizing "FTL-dns-cache" from 4096 to (512 * 16) == 8192 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:25:00.214 746/T750] Notice: Database size is 2089.15 MB, deleted 797 rows
   [2020-12-22 00:25:08.039 746M] Resizing "FTL-strings" from 65536 to (69632 * 1) == 69632 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:32:51.229 746M] Resizing "FTL-dns-cache" from 8192 to (768 * 16) == 12288 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:39:09.122 3637/F746] Resizing "FTL-queries" from 7340032 to (135168 * 56) == 7569408 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:39:09.135 746M] Remapping "FTL-queries" from 7340032 to (135168 * 56) == 7569408
   [2020-12-22 00:47:45.114 746M] Resizing "FTL-dns-cache" from 12288 to (1024 * 16) == 16384 (/dev/shm: 8.1MB used, 485.5MB total)
   [2020-12-22 00:55:22.824 4781/F746] Resizing "FTL-queries" from 7569408 to (139264 * 56) == 7798784 (/dev/shm: 8.1MB used, 485.5MB total)
   [2020-12-22 00:55:22.829 746M] Remapping "FTL-queries" from 7569408 to (139264 * 56) == 7798784
   [2020-12-22 01:00:00.259 746/T750] Notice: Database size is 2089.15 MB, deleted 1221 rows
   [2020-12-22 01:27:19.176 6435/F746] Resizing "FTL-queries" from 7798784 to (143360 * 56) == 8028160 (/dev/shm: 8.4MB used, 485.5MB total)
   [2020-12-22 01:27:21.049 746M] Remapping "FTL-queries" from 7798784 to (143360 * 56) == 8028160
   [2020-12-22 01:50:45.561 746M] Resizing "FTL-strings" from 69632 to (73728 * 1) == 73728 (/dev/shm: 8.6MB used, 485.5MB total)
   [2020-12-22 01:51:40.055 7635/F746] Resizing "FTL-queries" from 8028160 to (147456 * 56) == 8257536 (/dev/shm: 8.6MB used, 485.5MB total)
   [2020-12-22 01:51:40.059 746M] Remapping "FTL-queries" from 8028160 to (147456 * 56) == 8257536
   [2020-12-22 01:54:56.542 746M] Resizing "FTL-dns-cache" from 16384 to (1280 * 16) == 20480 (/dev/shm: 8.8MB used, 485.5MB total)
   [2020-12-22 01:59:00.425 746/T750] Notice: Database size is 2089.15 MB, deleted 1395 rows
   [2020-12-22 02:29:27.022 746M] Resizing "FTL-queries" from 8257536 to (151552 * 56) == 8486912 (/dev/shm: 8.8MB used, 485.5MB total)
   [2020-12-22 02:29:27.027 746M] FATAL: realloc_shm(): Failed to resize "FTL-queries" (18) to 8486912: Interrupted system call (-1)

   -----tail of pihole-FTL.log------
   [2020-12-22 00:24:56.598 746M] Resizing "FTL-dns-cache" from 4096 to (512 * 16) == 8192 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:25:00.214 746/T750] Notice: Database size is 2089.15 MB, deleted 797 rows
   [2020-12-22 00:25:08.039 746M] Resizing "FTL-strings" from 65536 to (69632 * 1) == 69632 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:32:51.229 746M] Resizing "FTL-dns-cache" from 8192 to (768 * 16) == 12288 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:39:09.122 3637/F746] Resizing "FTL-queries" from 7340032 to (135168 * 56) == 7569408 (/dev/shm: 7.9MB used, 485.5MB total)
   [2020-12-22 00:39:09.135 746M] Remapping "FTL-queries" from 7340032 to (135168 * 56) == 7569408
   [2020-12-22 00:47:45.114 746M] Resizing "FTL-dns-cache" from 12288 to (1024 * 16) == 16384 (/dev/shm: 8.1MB used, 485.5MB total)
   [2020-12-22 00:55:22.824 4781/F746] Resizing "FTL-queries" from 7569408 to (139264 * 56) == 7798784 (/dev/shm: 8.1MB used, 485.5MB total)
   [2020-12-22 00:55:22.829 746M] Remapping "FTL-queries" from 7569408 to (139264 * 56) == 7798784
   [2020-12-22 01:00:00.259 746/T750] Notice: Database size is 2089.15 MB, deleted 1221 rows
   [2020-12-22 01:27:19.176 6435/F746] Resizing "FTL-queries" from 7798784 to (143360 * 56) == 8028160 (/dev/shm: 8.4MB used, 485.5MB total)
   [2020-12-22 01:27:21.049 746M] Remapping "FTL-queries" from 7798784 to (143360 * 56) == 8028160
   [2020-12-22 01:50:45.561 746M] Resizing "FTL-strings" from 69632 to (73728 * 1) == 73728 (/dev/shm: 8.6MB used, 485.5MB total)
   [2020-12-22 01:51:40.055 7635/F746] Resizing "FTL-queries" from 8028160 to (147456 * 56) == 8257536 (/dev/shm: 8.6MB used, 485.5MB total)
   [2020-12-22 01:51:40.059 746M] Remapping "FTL-queries" from 8028160 to (147456 * 56) == 8257536
   [2020-12-22 01:54:56.542 746M] Resizing "FTL-dns-cache" from 16384 to (1280 * 16) == 20480 (/dev/shm: 8.8MB used, 485.5MB total)
   [2020-12-22 01:59:00.425 746/T750] Notice: Database size is 2089.15 MB, deleted 1395 rows
   [2020-12-22 02:29:27.022 746M] Resizing "FTL-queries" from 8257536 to (151552 * 56) == 8486912 (/dev/shm: 8.8MB used, 485.5MB total)
   [2020-12-22 02:29:27.027 746M] FATAL: realloc_shm(): Failed to resize "FTL-queries" (18) to 8486912: Interrupted system call (-1)

*** [ DIAGNOSING ]: contents of /dev/shm
-rw------- 1 pihole pihole 339968 Dec 21 23:44 /dev/shm/FTL-clients
-rw------- 1 pihole pihole 152 Dec 21 23:44 /dev/shm/FTL-counters
-rw------- 1 pihole pihole 20480 Dec 21 23:44 /dev/shm/FTL-dns-cache
-rw------- 1 pihole pihole 65536 Dec 21 23:44 /dev/shm/FTL-domains
-rw------- 1 pihole pihole 28 Dec 22 02:29 /dev/shm/FTL-lock
-rw------- 1 pihole pihole 20480 Dec 21 23:44 /dev/shm/FTL-overTime
-rw------- 1 pihole pihole 4096 Dec 21 23:44 /dev/shm/FTL-per-client-regex
-rw------- 1 pihole pihole 8257536 Dec 22 01:59 /dev/shm/FTL-queries
-rw------- 1 pihole pihole 12 Dec 21 23:44 /dev/shm/FTL-settings
-rw------- 1 pihole pihole 73728 Dec 22 01:50 /dev/shm/FTL-strings
-rw------- 1 pihole pihole 28672 Dec 21 23:44 /dev/shm/FTL-upstreams


was able to upload this one: https://tricorder.pi-hole.net/lqlny4uexc

Please report the bug here GitHub · Where software is built

and attach the corresponding log of /var/log/pihole-FTL.log

According to your debug token, you're still running FTL on commit ab0daeb. According to

this was somewhere in the middle of writing this PR, and, indeed, the issue you're reporting here (interrupted realloc_shm()) got fixed a few commits later. Please update your Pi-hole once again to get the latest code. Run

pihole checkout ftl development

to get the latest version as the branch I asked you to check out above has already moved along and was merged into development.