FTL crashed during normal operations

[jgantenberg]

Versions

Core version is v6.0.4 (Latest: v6.0.4)
Web version is v6.0.1 (Latest: v6.0.1)
FTL version is v6.0.2 (Latest: v6.0.2)

Platform

• OS and version:

• Platform: Armbian v24.11.1 / Debian 12.9

Expected behavior

After several days of normal operation FTL process died all of a sudden. Til now this happend only once. Simple restart after crash "fixed" it for the moment.

Logs:
`
2025-02-24 16:49:01.651 CET [5506/T5704] INFO: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
2025-02-24 16:49:01.655 CET [5506/T5704] INFO: ----------------------------> FTL crashed! <----------------------------
2025-02-24 16:49:01.655 CET [5506/T5704] INFO: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: Please report a bug at https://github.com/pi-hole/FTL/issues
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: and include in your report already the following details:
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: FTL has been running for 32894 seconds
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: FTL branch: master
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: FTL version: v6.0.2
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: FTL commit: ac500d5
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: FTL date: 2025-02-21 21:48:20 +0000
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: FTL user: started as pihole, ended as pihole
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: Compiled for linux/arm/v7 (compiled on CI) using cc (Alpine 14.2.0) 14.2.0
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: Process details: MID: 5506
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: PID: 5506
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: TID: 5704
2025-02-24 16:49:01.656 CET [5506/T5704] INFO: Name: database
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: Received signal: Segmentation fault
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: at address: 0x28
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: with code: SEGV_MAPERR (Address not mapped to object)
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: !!! INFO: pihole-FTL has not been compiled with glibc/backtrace support, not generating one !!!
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: ------ Listing content of directory /dev/shm ------
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: File Mode User:Group Size Filename
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: rwxrwxrwx root:root 360 .
2025-02-24 16:49:01.657 CET [5506/T5704] INFO: rwxr-xr-x root:root 520 ..
2025-02-24 16:49:01.658 CET [5506/T5704] INFO: rw------- pihole:pihole 56 FTL-5506-lock
2025-02-24 16:49:01.658 CET [5506/T5704] INFO: rw------- pihole:pihole 328 FTL-5506-counters
2025-02-24 16:49:01.658 CET [5506/T5704] INFO: rw------- pihole:pihole 136 FTL-5506-settings
2025-02-24 16:49:01.658 CET [5506/T5704] INFO: rw------- pihole:pihole 205K FTL-5506-strings
2025-02-24 16:49:01.659 CET [5506/T5704] INFO: rw------- pihole:pihole 147K FTL-5506-domains
2025-02-24 16:49:01.659 CET [5506/T5704] INFO: rw------- pihole:pihole 340K FTL-5506-clients
2025-02-24 16:49:01.659 CET [5506/T5704] INFO: rw------- pihole:pihole 12K FTL-5506-upstreams
2025-02-24 16:49:01.659 CET [5506/T5704] INFO: rw------- pihole:pihole 6M FTL-5506-queries
2025-02-24 16:49:01.659 CET [5506/T5704] INFO: rw------- pihole:pihole 8K FTL-5506-overTime
2025-02-24 16:49:01.660 CET [5506/T5704] INFO: rw------- pihole:pihole 184K FTL-5506-dns-cache
2025-02-24 16:49:01.660 CET [5506/T5704] INFO: rw------- pihole:pihole 4K FTL-5506-per-client-regex
2025-02-24 16:49:01.660 CET [5506/T5704] INFO: rw------- pihole:pihole 560K FTL-5506-fifo-log
2025-02-24 16:49:01.660 CET [5506/T5704] INFO: rw------- pihole:pihole 4K FTL-5506-clients-lookup
2025-02-24 16:49:01.660 CET [5506/T5704] INFO: rw------- pihole:pihole 33K FTL-5506-domains-lookup
2025-02-24 16:49:01.661 CET [5506/T5704] INFO: rw------- pihole:pihole 37K FTL-5506-dns-cache-lookup
2025-02-24 16:49:01.661 CET [5506/T5704] INFO: rw------- pihole:pihole 786K FTL-5506-recycler
2025-02-24 16:49:01.661 CET [5506/T5704] INFO: ---------------------------------------------------
2025-02-24 16:49:01.661 CET [5506/T5704] INFO: Please also include some lines from above the !!!!!!!!! header.
2025-02-24 16:49:01.661 CET [5506/T5704] INFO: Thank you for helping us to improve our FTL engine!
2025-02-24 16:49:01.661 CET [5506/T5704] INFO: Waiting for threads to join
2025-02-24 16:49:01.761 CET [5506/T5707] INFO: Terminating timer thread
2025-02-24 16:49:02.623 CET [5506/T5706] INFO: Terminating resolver thread
2025-02-24 16:49:03.661 CET [5506/T5704] INFO: Thread database (0) is still busy, cancelling it.
2025-02-24 16:49:03.662 CET [5506/T5705] ERROR: Error when obtaining outer SHM lock: Previous owner died
2025-02-24 16:49:03.662 CET [5506/T5705] ERROR: Error when obtaining inner SHM lock: Previous owner died
2025-02-24 16:49:03.662 CET [5506/T5705] INFO: Terminating GC thread
2025-02-24 16:49:08.308 CET [5506M] ERROR: export_queries_to_disk(): Failed to export queries: database is locked
2025-02-24 16:49:08.308 CET [5506M] INFO: SQL query was: "INSERT INTO disk.query_storage SELECT * FROM query_storage WHERE id > ? AND timestamp < ?"
2025-02-24 16:49:08.308 CET [5506M] INFO: with parameters: id = 29158009, timestamp = 1740412147.304474
2025-02-24 16:49:08.310 CET [5506M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.domain_by_id SELECT * FROM domain_by_id): Cannot export subtable: da>
2025-02-24 16:49:08.310 CET [5506M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.client_by_id SELECT * FROM client_by_id): Cannot export subtable: da>
2025-02-24 16:49:08.310 CET [5506M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.forward_by_id SELECT * FROM forward_by_id): Cannot export subtable: >
2025-02-24 16:49:08.311 CET [5506M] ERROR: export_queries_to_disk(disk.INSERT OR IGNORE INTO disk.addinfo_by_id SELECT * FROM addinfo_by_id): Cannot export subtable: >
2025-02-24 16:49:08.311 CET [5506M] ERROR: export_queries_to_disk(disk.UPDATE disk.sqlite_sequence SET seq = (SELECT seq FROM sqlite_sequence WHERE disk.sqlite_sequen>
2025-02-24 16:49:08.312 CET [5506M] ERROR: ERROR: SQL query "INSERT OR REPLACE INTO disk.ftl (id, value) VALUES ( 1, 1740412137.054578 );" failed: database is locked >
2025-02-24 16:49:08.312 CET [5506M] ERROR: export_queries_to_disk(): Cannot update timestamp: database is locked
2025-02-24 16:49:08.312 CET [5506M] ERROR: ERROR: SQL query "UPDATE disk.counters SET value = value + 0 WHERE id = 0;" failed: database is locked (SQLITE_BUSY)
2025-02-24 16:49:08.312 CET [5506M] ERROR: export_queries_to_disk(): Cannot update total queries counter: database is locked
2025-02-24 16:49:08.313 CET [5506M] ERROR: ERROR: SQL query "UPDATE disk.counters SET value = value + 0 WHERE id = 1;" failed: database is locked (SQLITE_BUSY)
2025-02-24 16:49:08.313 CET [5506M] ERROR: export_queries_to_disk(): Cannot update blocked queries counter: database is locked
2025-02-24 16:49:09.547 CET [5506M] INFO: Finished final database update
2025-02-24 16:49:09.547 CET [5506M] INFO: Waiting for threads to join
2025-02-24 16:49:09.547 CET [5506M] INFO: All threads joined
2025-02-24 16:49:09.551 CET [5506M] INFO: PID file emptied
2025-02-24 16:49:10.556 CET [5506M] ERROR: SQL error in backup_db_sessions(): database is locked (5)
2025-02-24 16:49:11.263 CET [5506M] INFO: ########## FTL terminated after 9h 8m 23s (code 0)! ##########

`

[yubiuser]

Please also include some lines from above the !!!!!!!!! header.

[yubiuser]

It would be extremely helpful if you could follow the steps on https://docs.pi-hole.net/ftldns/gdb/ and provide the backtrace on this crash.

[jgantenberg]

I'll do my best. I started gdb session as documented but til now the crash occured only once. So no idea whether it will occure again.

[jgantenberg]

by the way: here is the full FTL log above the header:

2025-02-24 07:40:47.386 CET [5506M] INFO: ########## FTL started on pihole! ##########
2025-02-24 07:40:47.386 CET [5506M] INFO: FTL branch: master
2025-02-24 07:40:47.387 CET [5506M] INFO: FTL version: v6.0.2
2025-02-24 07:40:47.387 CET [5506M] INFO: FTL commit: ac500d5f
2025-02-24 07:40:47.387 CET [5506M] INFO: FTL date: 2025-02-21 21:48:20 +0000
2025-02-24 07:40:47.387 CET [5506M] INFO: FTL user: pihole
2025-02-24 07:40:47.387 CET [5506M] INFO: Compiled for linux/arm/v7 (compiled on CI) using cc (Alpine 14.2.0) 14.2.0
2025-02-24 07:40:47.404 CET [5506M] INFO: Wrote config file:
2025-02-24 07:40:47.404 CET [5506M] INFO:  - 152 total entries
2025-02-24 07:40:47.404 CET [5506M] INFO:  - 143 entries are default
2025-02-24 07:40:47.404 CET [5506M] INFO:  - 9 entries are modified
2025-02-24 07:40:47.404 CET [5506M] INFO:  - 0 entries are forced through environment
2025-02-24 07:40:47.411 CET [5506M] INFO: Parsed config file /etc/pihole/pihole.toml successfully
2025-02-24 07:40:47.411 CET [5506M] INFO: PID file does not exist or not readable
2025-02-24 07:40:47.412 CET [5506M] INFO: No other running FTL process found.
2025-02-24 07:40:47.423 CET [5506M] INFO: PID of FTL process: 5506
2025-02-24 07:40:47.425 CET [5506M] INFO: listening on 0.0.0.0 port 53
2025-02-24 07:40:47.425 CET [5506M] INFO: listening on :: port 53
2025-02-24 07:40:47.431 CET [5506M] INFO: PID of FTL process: 5506
2025-02-24 07:40:47.437 CET [5506M] INFO: Database version is 21
2025-02-24 07:40:47.439 CET [5506M] INFO: Database successfully initialized
2025-02-24 07:40:58.737 CET [5506M] INFO: Imported 83088 queries from the on-disk database (it has 24711381 rows)
2025-02-24 07:40:58.737 CET [5506M] INFO: Parsing queries in database
2025-02-24 07:40:59.099 CET [5506M] INFO:   10000 queries parsed...
2025-02-24 07:40:59.388 CET [5506M] INFO:   20000 queries parsed...
2025-02-24 07:40:59.722 CET [5506M] INFO:   30000 queries parsed...
2025-02-24 07:40:59.984 CET [5506M] INFO:   40000 queries parsed...
2025-02-24 07:41:00.267 CET [5506M] INFO:   50000 queries parsed...
2025-02-24 07:41:00.537 CET [5506M] INFO:   60000 queries parsed...
2025-02-24 07:41:00.819 CET [5506M] INFO:   70000 queries parsed...
2025-02-24 07:41:01.069 CET [5506M] INFO:   80000 queries parsed...
2025-02-24 07:41:01.171 CET [5506M] INFO: Imported 83076 queries from the long-term database
2025-02-24 07:41:01.171 CET [5506M] INFO:  -> Total DNS queries: 83076
2025-02-24 07:41:01.171 CET [5506M] INFO:  -> Cached DNS queries: 64622
2025-02-24 07:41:01.171 CET [5506M] INFO:  -> Forwarded DNS queries: 9731
2025-02-24 07:41:01.172 CET [5506M] INFO:  -> Blocked DNS queries: 7460
2025-02-24 07:41:01.172 CET [5506M] INFO:  -> Unknown DNS queries: 35
2025-02-24 07:41:01.172 CET [5506M] INFO:  -> Unique domains: 2396
2025-02-24 07:41:01.172 CET [5506M] INFO:  -> Unique clients: 50
2025-02-24 07:41:01.172 CET [5506M] INFO:  -> DNS cache records: 725
2025-02-24 07:41:01.172 CET [5506M] INFO:  -> Known forward destinations: 8
2025-02-24 07:41:01.958 CET [5506M] WARNING: Insufficient permissions to set system time (CAP_SYS_TIME required), NTP client not available
2025-02-24 07:41:01.958 CET [5506/T5702] INFO: NTP server listening on 0.0.0.0:123 (IPv4)
2025-02-24 07:41:01.959 CET [5506/T5703] INFO: NTP server listening on :::123 (IPv6)
2025-02-24 07:41:01.959 CET [5506M] INFO: FTL is running as user pihole (UID 997)
2025-02-24 07:41:01.960 CET [5506M] INFO: Reading certificate from /etc/pihole/tls.pem ...
2025-02-24 07:41:01.964 CET [5506M] INFO: Using SSL/TLS certificate file /etc/pihole/tls.pem
2025-02-24 07:41:01.966 CET [5506M] INFO: Web server ports:
2025-02-24 07:41:01.966 CET [5506M] INFO:   - 80 (HTTP, IPv4, optional)
2025-02-24 07:41:01.966 CET [5506M] INFO:   - 443 (HTTPS, IPv4, optional)
2025-02-24 07:41:01.966 CET [5506M] INFO:   - 80 (HTTP, IPv6, optional)
2025-02-24 07:41:01.966 CET [5506M] INFO:   - 443 (HTTPS, IPv6, optional)
2025-02-24 07:41:01.967 CET [5506M] INFO: Restored 1 API session from the database
2025-02-24 07:41:01.979 CET [5506M] INFO: Blocking status is enabled
2025-02-24 07:41:02.625 CET [5506/T5704] INFO: Compiled 1 allow and 0 deny regex for 51 clients in 522.3 msec
2025-02-24 07:41:13.677 CET [5506/T5720] INFO: Local URI: "/admin/"
2025-02-24 07:41:13.772 CET [5506/T5718] INFO: Local URI: "/admin/style/themes/high-contrast.css"
2025-02-24 07:41:15.698 CET [5506/T5720] INFO: Local URI: "/admin/img/favicons/favicon.ico"
2025-02-24 07:45:55.867 CET [5506/T5718] INFO: Local URI: "/admin/settings/api"
2025-02-24 07:45:56.076 CET [5506/T5728] INFO: Local URI: "/admin/vendor/qrious/qrious.min.js"
2025-02-24 07:45:56.176 CET [5506/T5720] INFO: Local URI: "/admin/scripts/js/settings-api.js"
2025-02-24 07:46:04.181 CET [5506/T5728] INFO: Wrote config file:
2025-02-24 07:46:04.182 CET [5506/T5728] INFO:  - 152 total entries
2025-02-24 07:46:04.182 CET [5506/T5728] INFO:  - 144 entries are default
2025-02-24 07:46:04.182 CET [5506/T5728] INFO:  - 8 entries are modified
2025-02-24 07:46:04.182 CET [5506/T5728] INFO:  - 0 entries are forced through environment
2025-02-24 07:46:04.200 CET [5506/T5728] INFO: Config file written to /etc/pihole/pihole.toml
2025-02-24 07:46:06.289 CET [5506/T5718] INFO: Local URI: "/admin/settings/api"
2025-02-24 07:46:12.933 CET [5506/T5720] INFO: Local URI: "/admin/settings/dnsrecords"
2025-02-24 07:46:30.228 CET [5506/T5728] INFO: Local URI: "/admin/settings/api"
2025-02-24 07:46:31.728 CET [5506/T5720] INFO: Local URI: "/admin/"
2025-02-24 07:47:19.451 CET [5506/T5718] INFO: Local URI: "/admin/settings/dnsrecords"
2025-02-24 07:48:28.200 CET [5506/T5728] INFO: Local URI: "/admin/"
2025-02-24 07:49:15.757 CET [5506/T5728] INFO: Local URI: "/admin/settings/dnsrecords"
2025-02-24 07:49:20.251 CET [5506/T5718] INFO: Local URI: "/admin/"
2025-02-24 07:49:21.347 CET [5506/T5718] INFO: Local URI: "/admin/settings/dnsrecords"
2025-02-24 07:49:22.513 CET [5506/T5728] INFO: Local URI: "/admin/"

Perhaps the debugger session is more informative ...