Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FTL crashed! #2371

Open
githubsean opened this issue Mar 13, 2025 · 3 comments
Open

FTL crashed! #2371

githubsean opened this issue Mar 13, 2025 · 3 comments
Labels

Comments

@githubsean
Copy link

Versions

  • Pi-hole: 6.0.5
  • AdminLTE: 6.0.2
  • FTL: 6.0.4

Platform

  • OS and version: Pi OS (Debian 11 Bullseye)
  • Platform: Raspberry Pi bare metal

Expected behavior

I run two copies of PiHole on two Raspberry Pis. I have them in a Master/Backup configuration using keepalived. I only just noticed that the primary had stopped working - but the secondary picked things up nicely. I looked at the logs and found a crash in the FTL.log file

Actual behavior / bug

Please refer to the attached log file: FTL.log.txt

Steps to reproduce

Steps to reproduce the behavior: Unknown

Debug Token

  • URL:

Screenshots

If applicable, add screenshots to help explain your problem.

Additional context

Add any other context about the problem here.

@githubsean
Copy link
Author

Though I might paste the log here too

2025-03-07 00:36:54.538 AEDT [90990/T91198] INFO: Received 8/8 valid NTP replies from pool.ntp.org
2025-03-07 00:36:54.538 AEDT [90990/T91198] INFO: Time offset: -8.447170e-01 ms (excluded 1 outliers)
2025-03-07 00:36:54.539 AEDT [90990/T91198] INFO: Round-trip delay: 2.586160e+00 ms (excluded 1 outliers)
2025-03-07 01:36:54.676 AEDT [90990/T91198] INFO: Received 8/8 valid NTP replies from pool.ntp.org
2025-03-07 01:36:54.676 AEDT [90990/T91198] INFO: Time offset: -2.074957e+00 ms (excluded 0 outliers)
2025-03-07 01:36:54.676 AEDT [90990/T91198] INFO: Round-trip delay: 2.836227e+00 ms (excluded 0 outliers)
2025-03-07 01:39:00.336 AEDT [90990/T91199] INFO: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
2025-03-07 01:39:00.336 AEDT [90990/T91199] INFO: ---------------------------->  FTL crashed!  <----------------------------
2025-03-07 01:39:00.336 AEDT [90990/T91199] INFO: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
2025-03-07 01:39:00.336 AEDT [90990/T91199] INFO: Please report a bug at https://github.com/pi-hole/FTL/issues
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: and include in your report already the following details:
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: FTL has been running for 151352 seconds
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: FTL branch: master
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: FTL version: v6.0.4
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: FTL commit: b7eb53bf
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: FTL date: 2025-03-04 17:22:10 +0000
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: FTL user: started as pihole, ended as pihole
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: Compiled for linux/arm64/v8 (compiled on CI) using cc (Alpine 14.2.0) 14.2.0
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: Process details: MID: 90990
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO:                  PID: 90990
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO:                  TID: 91199
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO:                  Name: database
2025-03-07 01:39:00.337 AEDT [90990/T91199] INFO: Received signal: Segmentation fault
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO:      at address: 0x28
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO:      with code:  SEGV_MAPERR (Address not mapped to object)
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO: !!! INFO: pihole-FTL has not been compiled with glibc/backtrace support, not generating one !!!
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO: ------ Listing content of directory /dev/shm ------
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO: File Mode User:Group      Size  Filename
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO: rwxrwxrwx root:root       360   .
2025-03-07 01:39:00.338 AEDT [90990/T91199] INFO: rwxr-xr-x root:root         4K  ..
2025-03-07 01:39:00.339 AEDT [90990/T91199] INFO: rw------- pihole:pihole   786K  FTL-90990-recycler
2025-03-07 01:39:00.339 AEDT [90990/T91199] INFO: rw------- pihole:pihole    57K  FTL-90990-dns-cache-lookup
2025-03-07 01:39:00.339 AEDT [90990/T91199] INFO: rw------- pihole:pihole    29K  FTL-90990-domains-lookup
2025-03-07 01:39:00.339 AEDT [90990/T91199] INFO: rw------- pihole:pihole     4K  FTL-90990-clients-lookup
2025-03-07 01:39:00.340 AEDT [90990/T91199] INFO: rw------- pihole:pihole   569K  FTL-90990-fifo-log
2025-03-07 01:39:00.340 AEDT [90990/T91199] INFO: rw------- pihole:pihole     4K  FTL-90990-per-client-regex
2025-03-07 01:39:00.340 AEDT [90990/T91199] INFO: rw------- pihole:pihole   573K  FTL-90990-dns-cache
2025-03-07 01:39:00.340 AEDT [90990/T91199] INFO: rw------- pihole:pihole     8K  FTL-90990-overTime
2025-03-07 01:39:00.340 AEDT [90990/T91199] INFO: rw------- pihole:pihole    12M  FTL-90990-queries
2025-03-07 01:39:00.341 AEDT [90990/T91199] INFO: rw------- pihole:pihole    29K  FTL-90990-upstreams
2025-03-07 01:39:00.341 AEDT [90990/T91199] INFO: rw------- pihole:pihole   348K  FTL-90990-clients
2025-03-07 01:39:00.341 AEDT [90990/T91199] INFO: rw------- pihole:pihole   209K  FTL-90990-domains
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: rw------- pihole:pihole   246K  FTL-90990-strings
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: rw------- pihole:pihole   144   FTL-90990-settings
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: rw------- pihole:pihole   328   FTL-90990-counters
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: rw------- pihole:pihole    88   FTL-90990-lock
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: ---------------------------------------------------
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: Please also include some lines from above the !!!!!!!!! header.
2025-03-07 01:39:00.342 AEDT [90990/T91199] INFO: Thank you for helping us to improve our FTL engine!
2025-03-07 01:39:00.343 AEDT [90990/T91199] INFO: Waiting for threads to join
2025-03-07 01:39:00.430 AEDT [90990/T91202] INFO: Terminating timer thread
2025-03-07 01:39:00.820 AEDT [90990/T91201] INFO: Terminating resolver thread
2025-03-07 01:39:01.213 AEDT [90990/T91200] INFO: Terminating GC thread
2025-03-07 01:39:02.343 AEDT [90990/T91199] INFO: Thread database (0) is still busy, cancelling it.
2025-03-07 01:39:02.969 AEDT [90990M] ERROR: Error when obtaining outer SHM lock: Previous owner died
2025-03-07 01:39:02.970 AEDT [90990M] ERROR: Error when obtaining inner SHM lock: Previous owner died
2025-03-07 01:39:04.223 AEDT [90990M] ERROR: export_queries_to_disk(): Failed to export queries: database is locked
2025-03-07 01:39:04.223 AEDT [90990M] INFO:     SQL query was: "INSERT INTO disk.query_storage SELECT * FROM query_storage WHERE id > ? AND timestamp < ?"
2025-03-07 01:39:04.223 AEDT [90990M] INFO:     with parameters: id = 2072102, timestamp = 1741271943.221472
2025-03-07 01:39:04.223 AEDT [90990M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.domain_by_id SELECT * FROM domain_by_id): Cannot export subtable: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.client_by_id SELECT * FROM client_by_id): Cannot export subtable: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.forward_by_id SELECT * FROM forward_by_id): Cannot export subtable: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.addinfo_by_id SELECT * FROM addinfo_by_id): Cannot export subtable: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(disk.UPDATE disk.sqlite_sequence SET seq = (SELECT seq FROM sqlite_sequence WHERE disk.sqlite_sequence.name = sqlite_sequence.name)): Cannot export subtable: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: ERROR: SQL query "INSERT OR REPLACE INTO disk.ftl (id, value) VALUES ( 1, 1741271934.929352 );" failed: database is locked (SQLITE_BUSY)
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(): Cannot update timestamp: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: ERROR: SQL query "UPDATE disk.counters SET value = value + 0 WHERE id = 0;" failed: database is locked (SQLITE_BUSY)
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(): Cannot update total queries counter: database is locked
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: ERROR: SQL query "UPDATE disk.counters SET value = value + 0 WHERE id = 1;" failed: database is locked (SQLITE_BUSY)
2025-03-07 01:39:04.224 AEDT [90990M] ERROR: export_queries_to_disk(): Cannot update blocked queries counter: database is locked
2025-03-07 01:39:04.231 AEDT [90990M] INFO: Finished final database update
2025-03-07 01:39:04.231 AEDT [90990M] INFO: Waiting for threads to join
2025-03-07 01:39:04.232 AEDT [90990M] INFO: Thread ntp-client (4) is idle, terminating it.
2025-03-07 01:39:04.232 AEDT [90990M] INFO: All threads joined
2025-03-07 01:39:04.236 AEDT [90990M] INFO: PID file emptied
2025-03-07 01:39:05.239 AEDT [90990M] ERROR: SQL error in backup_db_sessions(): database is locked (5)
2025-03-07 01:39:05.975 AEDT [90990M] INFO: ########## FTL terminated after 1d 18h 2m 37s  (code 0)! ##########

@githubsean
Copy link
Author

I also noticed that the systemd unit exited successfully, similar to this comment
I ship my logs off machine, I have the following logged (order is newest to oldest). You can see that keepalived picked up that the pihole-FTL service was not running. It tests this using "systemctl is-active pihole-FTL.service", and because the unit had exited and wasn't running, keepalived treated that as a fault.

03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,(VI_2) Entering FAULT STATE
03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,(VI_2) Entering FAULT STATE
03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,VRRP_Group(SYNC) Syncing instances to FAULT state
03/07/2025,01:39:06,Info,pihole1,daemon,avahi-daemon,Withdrawing address record for 192.168.53.253 on eth0.
03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,(VI_1) sent 0 priority
03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,(VI_1) Entering FAULT STATE
03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,VRRP_Script(chk_pihole) failed (exited with status 3)
03/07/2025,01:39:06,Info,pihole1,user,Keepalived_vrrp,Script `chk_pihole` now returning 3
03/07/2025,01:39:06,Notice,pihole1,daemon,systemd,pihole-FTL.service: Consumed 1h 16min 1.627s CPU time.
03/07/2025,01:39:06,Info,pihole1,daemon,systemd,pihole-FTL.service: Succeeded.

@DL6ER
Copy link
Member

DL6ER commented Mar 16, 2025

We have meanwhile found that a crash in a thread leads to the incorrect exit with code 0 and, hence, no restarting. It is fixed in development for about two weeks. Unfortunately, we don't have the capacities in the team right now for another release, however, you could try

sudo pihole checkout ftl development

to get the most recent state. There is no breaking incompatibility in it so you can go back using

sudo pihole checkout ftl master

at any point.

@DL6ER DL6ER added the crash label Mar 16, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants