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 #987

Closed
jens1205 opened this issue Dec 18, 2020 · 27 comments
Closed

FTL crashed #987

jens1205 opened this issue Dec 18, 2020 · 27 comments

Comments

@jens1205
Copy link

jens1205 commented Dec 18, 2020

Versions

  • Pi-hole: v5.2.1
  • AdminLTE: v5.2.1
  • FTL: v5.3.2

Platform

  • OS and version: ubuntu server Ubuntu 20.04.1 LTS
  • Platform: Raspberry Pi 4 Model B

Expected behavior

FTL should not crash

Actual behavior / bug

FTL crashed

Steps to reproduce

Steps to reproduce the behavior:

Don't know, it just happened

Debug Token

none

Screenshots

none

Additional context

[2020-12-18 13:43:22.637 8176M] Resizing "FTL-dns-cache" from 8192 to (768 * 16) == 12288 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 13:47:33.987 8176M] Resizing "FTL-dns-cache" from 12288 to (1024 * 16) == 16384 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 14:02:23.797 8176M] Resizing "FTL-dns-cache" from 16384 to (1280 * 16) == 20480 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 14:02:36.339 8176M] Resizing "FTL-strings" from 49152 to (53248 * 1) == 53248 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 14:14:49.518 8176M] Resizing "FTL-dns-cache" from 20480 to (1536 * 16) == 24576 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 14:51:40.031 8176M] Resizing "FTL-dns-cache" from 24576 to (1792 * 16) == 28672 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 15:28:51.744 8176M] Resizing "FTL-strings" from 53248 to (57344 * 1) == 57344 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-18 15:54:05.965 8176M] Resizing "FTL-queries" from 1310720 to (24576 * 64) == 1572864 (/dev/shm: 1.8MB used, 2.0GB total)
[2020-12-18 15:56:13.104 8176M] Resizing "FTL-dns-cache" from 28672 to (2048 * 16) == 32768 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 16:15:16.812 8176M] Resizing "FTL-dns-cache" from 32768 to (2304 * 16) == 36864 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 16:50:37.075 8176M] Resizing "FTL-strings" from 57344 to (61440 * 1) == 61440 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 16:57:31.745 8176M] Resizing "FTL-dns-cache" from 36864 to (2560 * 16) == 40960 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 17:19:25.576 8176M] Resizing "FTL-dns-cache" from 40960 to (2816 * 16) == 45056 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 18:07:10.629 8176M] Resizing "FTL-dns-cache" from 45056 to (3072 * 16) == 49152 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 18:07:49.104 8176M] Resizing "FTL-strings" from 61440 to (65536 * 1) == 65536 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 18:10:14.762 8176M] Resizing "FTL-queries" from 1572864 to (28672 * 64) == 1835008 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-18 18:33:44.563 8176M] Resizing "FTL-dns-cache" from 49152 to (3328 * 16) == 53248 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:45:14.451 8176M] Resizing "FTL-dns-cache" from 53248 to (3584 * 16) == 57344 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:50:41.622 8176M] Resizing "FTL-strings" from 65536 to (69632 * 1) == 69632 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:50:47.569 8176M] Resizing "FTL-dns-cache" from 57344 to (3840 * 16) == 61440 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:51:17.066 8176M] Resizing "FTL-dns-cache" from 61440 to (4096 * 16) == 65536 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:52:05.326 8176M] Resizing "FTL-strings" from 69632 to (73728 * 1) == 73728 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:52:15.994 8176M] Resizing "FTL-queries" from 1835008 to (32768 * 64) == 2097152 (/dev/shm: 2.3MB used, 2.0GB total)
[2020-12-18 19:52:29.785 8176M] Resizing "FTL-dns-cache" from 65536 to (4352 * 16) == 69632 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 19:53:37.687 8176M] Resizing "FTL-dns-cache" from 69632 to (4608 * 16) == 73728 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 19:54:57.638 8176M] Resizing "FTL-dns-cache" from 73728 to (4864 * 16) == 77824 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 19:55:29.563 8176M] Resizing "FTL-strings" from 73728 to (77824 * 1) == 77824 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 19:59:35.480 8176M] Resizing "FTL-dns-cache" from 77824 to (5120 * 16) == 81920 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 20:07:51.431 8176M] Resizing "FTL-dns-cache" from 81920 to (5376 * 16) == 86016 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 20:16:14.121 8176M] Resizing "FTL-strings" from 77824 to (81920 * 1) == 81920 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 20:31:31.079 8176M] Resizing "FTL-dns-cache" from 86016 to (5632 * 16) == 90112 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 20:56:16.188 8176M] Received: Real-time signal 0 (34 -> 0)
[2020-12-18 20:56:16.248 8176/T8180] Compiled 0 whitelist and 12 blacklist regex filters for 24 clients in 22.9 msec
[2020-12-18 20:56:39.663 8176M] Received: Real-time signal 0 (34 -> 0)
[2020-12-18 20:56:39.733 8176/T8180] Compiled 0 whitelist and 13 blacklist regex filters for 24 clients in 25.8 msec
[2020-12-18 20:57:05.072 8176M] Received: Real-time signal 0 (34 -> 0)
[2020-12-18 20:57:05.218 8176/T8180] Compiled 0 whitelist and 13 blacklist regex filters for 24 clients in 26.1 msec
[2020-12-18 21:03:20.675 8176M] Resizing "FTL-queries" from 2097152 to (36864 * 64) == 2359296 (/dev/shm: 2.6MB used, 2.0GB total)
[2020-12-18 21:21:07.601 8176M] Received: Real-time signal 0 (34 -> 0)
[2020-12-18 21:21:07.710 8176/T8180] Compiled 0 whitelist and 13 blacklist regex filters for 24 clients in 24.5 msec
[2020-12-18 21:22:31.555 8176M] Received: Real-time signal 0 (34 -> 0)
[2020-12-18 21:22:31.702 8176/T8180] Compiled 0 whitelist and 13 blacklist regex filters for 24 clients in 24.7 msec
[2020-12-18 21:22:31.876 8176M] Received: Real-time signal 0 (34 -> 0)
[2020-12-18 21:22:31.954 8176/T8180] Compiled 0 whitelist and 13 blacklist regex filters for 24 clients in 26.3 msec
[2020-12-18 21:23:00.218 8176/T8180] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-18 21:23:00.218 8176/T8180] ----------------------------> FTL crashed! <----------------------------
[2020-12-18 21:23:00.218 8176/T8180] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-18 21:23:00.218 8176/T8180] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-12-18 21:23:00.218 8176/T8180] and include in your report already the following details:
[2020-12-18 21:23:00.218 8176/T8180] FTL has been running for 28064 seconds
[2020-12-18 21:23:00.219 8176/T8180] FTL branch: master
[2020-12-18 21:23:00.219 8176/T8180] FTL version: v5.3.2
[2020-12-18 21:23:00.219 8176/T8180] FTL commit: 0790cf7
[2020-12-18 21:23:00.219 8176/T8180] FTL date: 2020-12-02 21:28:39 +0000
[2020-12-18 21:23:00.219 8176/T8180] FTL user: started as pihole, ended as pihole
[2020-12-18 21:23:00.219 8176/T8180] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-12-18 21:23:00.219 8176/T8180] Process details: MID: 8176
[2020-12-18 21:23:00.219 8176/T8180] PID: 8176
[2020-12-18 21:23:00.219 8176/T8180] TID: 8180
[2020-12-18 21:23:00.219 8176/T8180] Name: database
[2020-12-18 21:23:00.219 8176/T8180] Received signal: Segmentation fault
[2020-12-18 21:23:00.219 8176/T8180] at address: 0xa206574756f
[2020-12-18 21:23:00.219 8176/T8180] with code: SEGV_MAPERR (Address not mapped to object)
2020-12-18 21:29:46.192 18626M] Using log file /var/log/pihole-FTL.log
[2020-12-18 21:29:46.192 18626M] ########## FTL started! ##########
[2020-12-18 21:29:46.192 18626M] FTL branch: master
[2020-12-18 21:29:46.192 18626M] FTL version: v5.3.2
[2020-12-18 21:29:46.192 18626M] FTL commit: 0790cf7
[2020-12-18 21:29:46.192 18626M] FTL date: 2020-12-02 21:28:39 +0000
[2020-12-18 21:29:46.192 18626M] FTL user: pihole

@DL6ER
Copy link
Member

DL6ER commented Dec 19, 2020

@jensgersdorf Is this everything from the log file? I'd expect a lot more output, containing further crash details such as a (hopefulyl complete) backtrace of the crash location. I'd be great if could check /var/log/pihole-FTL.log for further information. A few more lines above and below what you already posted could be helpful in narrowing down what happened to cause the crash.

Could you also try whether running

pihole checkout ftl fix/all_the_things

fixes the crash for you?

@jens1205
Copy link
Author

I just added some more logging what happened before. After the crash of course nothing happened - besides my manual restart some minutes later.

The pihole installation is rather fresh - the server has been running since [2020-12-18 13:35:16.045 8174M] before the crash occured - so approx. 8 hours. It's the first and so far only time a crash occured (which does not say anything, as the whole installation is only a 9 hours older).

I'd first stick to the current version of pihole and wait and see if it will crash again in the next days. If so, I will tell in this ticket and install the fix/all_the_things branch.

@jens1205
Copy link
Author

I can reproduce the problem. It occurs when I use the "Audit log". When I click on two audit buttons in a row, FTL crashes.

[2020-12-19 19:32:48.337 37366M] ########## FTL started! ##########
[2020-12-19 19:32:48.337 37366M] FTL branch: master
[2020-12-19 19:32:48.337 37366M] FTL version: v5.3.2
[2020-12-19 19:32:48.337 37366M] FTL commit: 0790cf7
[2020-12-19 19:32:48.337 37366M] FTL date: 2020-12-02 21:28:39 +0000
[2020-12-19 19:32:48.337 37366M] FTL user: pihole
[2020-12-19 19:32:48.337 37366M] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-12-19 19:32:48.337 37366M] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-12-19 19:32:48.337 37366M] SOCKET_LISTENING: only local
[2020-12-19 19:32:48.337 37366M] AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-12-19 19:32:48.338 37366M] MAXDBDAYS: max age for stored queries is 365 days
[2020-12-19 19:32:48.338 37366M] RESOLVE_IPV6: Resolve IPv6 addresses
[2020-12-19 19:32:48.338 37366M] RESOLVE_IPV4: Resolve IPv4 addresses
[2020-12-19 19:32:48.338 37366M] DBINTERVAL: saving to DB file every minute
[2020-12-19 19:32:48.338 37366M] DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-12-19 19:32:48.338 37366M] MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-12-19 19:32:48.338 37366M] PRIVACYLEVEL: Set to 0
[2020-12-19 19:32:48.338 37366M] IGNORE_LOCALHOST: Show queries from localhost
[2020-12-19 19:32:48.338 37366M] BLOCKINGMODE: Null IPs for blocked domains
[2020-12-19 19:32:48.338 37366M] ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-12-19 19:32:48.338 37366M] DBIMPORT: Importing history from database
[2020-12-19 19:32:48.338 37366M] PIDFILE: Using /run/pihole-FTL.pid
[2020-12-19 19:32:48.338 37366M] PORTFILE: Using /run/pihole-FTL.port
[2020-12-19 19:32:48.338 37366M] SOCKETFILE: Using /run/pihole/FTL.sock
[2020-12-19 19:32:48.339 37366M] SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-12-19 19:32:48.339 37366M] MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-12-19 19:32:48.339 37366M] GRAVITYDB: Using /etc/pihole/gravity.db
[2020-12-19 19:32:48.339 37366M] PARSE_ARP_CACHE: Active
[2020-12-19 19:32:48.339 37366M] CNAME_DEEP_INSPECT: Active
[2020-12-19 19:32:48.339 37366M] DELAY_STARTUP: No delay requested.
[2020-12-19 19:32:48.339 37366M] BLOCK_ESNI: Enabled, blocking _esni.{blocked domain}
[2020-12-19 19:32:48.339 37366M] NICE: Set process niceness to -10 (default)
[2020-12-19 19:32:48.339 37366M] MAXNETAGE: Removing IP addresses and host names from network table after 365 days
[2020-12-19 19:32:48.339 37366M] NAMES_FROM_NETDB: Enabled, trying to get names from network database
[2020-12-19 19:32:48.339 37366M] EDNS0_ECS: Overwrite client from ECS information
[2020-12-19 19:32:48.339 37366M] REFRESH_HOSTNAMES: Periodically refreshing IPv4 names
[2020-12-19 19:32:48.339 37366M] Finished config file parsing
[2020-12-19 19:32:48.340 37366M] Creating mutex
[2020-12-19 19:32:48.342 37366M] Database version is 9
[2020-12-19 19:32:48.343 37366M] Imported 0 alias-clients
[2020-12-19 19:32:48.343 37366M] Database successfully initialized
[2020-12-19 19:32:48.344 37366M] New upstream server: 1.0.0.1:53 (0/512)
[2020-12-19 19:32:48.346 37366M] New upstream server: 1.1.1.1:53 (1/512)
[2020-12-19 19:32:48.347 37366M] New upstream server: 192.168.178.1:53 (2/512)
[2020-12-19 19:32:48.351 37366M] Resizing "FTL-strings" from 4096 to (8192 * 1) == 8192 (/dev/shm: 626.7KB used, 2.0GB total)
[2020-12-19 19:32:48.360 37366M] Resizing "FTL-strings" from 8192 to (12288 * 1) == 12288 (/dev/shm: 630.8KB used, 2.0GB total)
[2020-12-19 19:32:48.371 37366M] Resizing "FTL-strings" from 12288 to (16384 * 1) == 16384 (/dev/shm: 634.9KB used, 2.0GB total)
[2020-12-19 19:32:48.375 37366M] Resizing "FTL-queries" from 262144 to (8192 * 64) == 524288 (/dev/shm: 639.0KB used, 2.0GB total)
[2020-12-19 19:32:48.389 37366M] Resizing "FTL-strings" from 16384 to (20480 * 1) == 20480 (/dev/shm: 901.1KB used, 2.0GB total)
[2020-12-19 19:32:48.410 37366M] Resizing "FTL-strings" from 20480 to (24576 * 1) == 24576 (/dev/shm: 905.2KB used, 2.0GB total)
[2020-12-19 19:32:48.418 37366M] Resizing "FTL-queries" from 524288 to (12288 * 64) == 786432 (/dev/shm: 909.3KB used, 2.0GB total)
[2020-12-19 19:32:48.436 37366M] Resizing "FTL-queries" from 786432 to (16384 * 64) == 1048576 (/dev/shm: 1.2MB used, 2.0GB total)
[2020-12-19 19:32:48.455 37366M] Resizing "FTL-strings" from 24576 to (28672 * 1) == 28672 (/dev/shm: 1.4MB used, 2.0GB total)
[2020-12-19 19:32:48.478 37366M] Resizing "FTL-queries" from 1048576 to (20480 * 64) == 1310720 (/dev/shm: 1.4MB used, 2.0GB total)
[2020-12-19 19:32:48.494 37366M] Resizing "FTL-strings" from 28672 to (32768 * 1) == 32768 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-19 19:32:48.526 37366M] Resizing "FTL-queries" from 1310720 to (24576 * 64) == 1572864 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-19 19:32:48.537 37366M] Resizing "FTL-strings" from 32768 to (36864 * 1) == 36864 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-19 19:32:48.559 37366M] Resizing "FTL-strings" from 36864 to (40960 * 1) == 40960 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-19 19:32:48.568 37366M] Resizing "FTL-queries" from 1572864 to (28672 * 64) == 1835008 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-19 19:32:48.605 37366M] Resizing "FTL-strings" from 40960 to (45056 * 1) == 45056 (/dev/shm: 2.2MB used, 2.0GB total)
[2020-12-19 19:32:48.608 37366M] Resizing "FTL-queries" from 1835008 to (32768 * 64) == 2097152 (/dev/shm: 2.2MB used, 2.0GB total)
[2020-12-19 19:32:48.632 37366M] Resizing "FTL-strings" from 45056 to (49152 * 1) == 49152 (/dev/shm: 2.5MB used, 2.0GB total)
[2020-12-19 19:32:48.650 37366M] Resizing "FTL-strings" from 49152 to (53248 * 1) == 53248 (/dev/shm: 2.5MB used, 2.0GB total)
[2020-12-19 19:32:48.692 37366M] Resizing "FTL-queries" from 2097152 to (36864 * 64) == 2359296 (/dev/shm: 2.5MB used, 2.0GB total)
[2020-12-19 19:32:48.737 37366M] Resizing "FTL-strings" from 53248 to (57344 * 1) == 57344 (/dev/shm: 2.8MB used, 2.0GB total)
[2020-12-19 19:32:48.755 37366M] Resizing "FTL-queries" from 2359296 to (40960 * 64) == 2621440 (/dev/shm: 2.8MB used, 2.0GB total)
[2020-12-19 19:32:48.791 37366M] Resizing "FTL-strings" from 57344 to (61440 * 1) == 61440 (/dev/shm: 3.0MB used, 2.0GB total)
[2020-12-19 19:32:48.826 37366M] Resizing "FTL-queries" from 2621440 to (45056 * 64) == 2883584 (/dev/shm: 3.0MB used, 2.0GB total)
[2020-12-19 19:32:48.856 37366M] Resizing "FTL-strings" from 61440 to (65536 * 1) == 65536 (/dev/shm: 3.3MB used, 2.0GB total)
[2020-12-19 19:32:48.897 37366M] Resizing "FTL-queries" from 2883584 to (49152 * 64) == 3145728 (/dev/shm: 3.3MB used, 2.0GB total)
[2020-12-19 19:32:48.954 37366M] Resizing "FTL-queries" from 3145728 to (53248 * 64) == 3407872 (/dev/shm: 3.6MB used, 2.0GB total)
[2020-12-19 19:32:48.964 37366M] Imported 49738 queries from the long-term database
[2020-12-19 19:32:48.965 37366M] -> Total DNS queries: 49738
[2020-12-19 19:32:48.965 37366M] -> Cached DNS queries: 8888
[2020-12-19 19:32:48.965 37366M] -> Forwarded DNS queries: 23030
[2020-12-19 19:32:48.965 37366M] -> Blocked DNS queries: 17254
[2020-12-19 19:32:48.965 37366M] -> Unknown DNS queries: 335
[2020-12-19 19:32:48.965 37366M] -> Unique domains: 2528
[2020-12-19 19:32:48.966 37366M] -> Unique clients: 27
[2020-12-19 19:32:48.966 37366M] -> Known forward destinations: 3
[2020-12-19 19:32:48.966 37366M] Successfully accessed setupVars.conf
[2020-12-19 19:32:48.977 37368M] PID of FTL process: 37368
[2020-12-19 19:32:48.978 37368/T37369] Listening on port 4711 for incoming IPv4 telnet connections
[2020-12-19 19:32:48.978 37368/T37371] Listening on Unix socket
[2020-12-19 19:32:48.978 37368M] INFO: FTL is running as user pihole (UID 997)
[2020-12-19 19:32:48.978 37368/T37370] Listening on port 4711 for incoming IPv6 telnet connections
[2020-12-19 19:32:48.979 37368M] Reloading DNS cache
[2020-12-19 19:32:48.979 37368M] Blocking status is enabled
[2020-12-19 19:32:49.129 37368/T37372] Compiled 0 whitelist and 13 blacklist regex filters for 27 clients in 27.7 msec
[2020-12-19 19:33:00.254 37368/T37374] Resizing "FTL-strings" from 65536 to (69632 * 1) == 69632 (/dev/shm: 3.8MB used, 2.0GB total)
[2020-12-19 19:43:10.059 37368M] Resizing "FTL-dns-cache" from 4096 to (512 * 16) == 8192 (/dev/shm: 3.8MB used, 2.0GB total)
[2020-12-19 19:51:59.550 37368M] Resizing "FTL-dns-cache" from 8192 to (768 * 16) == 12288 (/dev/shm: 3.8MB used, 2.0GB total)
[2020-12-19 19:52:49.802 37368M] Received: Real-time signal 0 (34 -> 0)
[2020-12-19 19:52:49.913 37368/T37372] Compiled 0 whitelist and 13 blacklist regex filters for 27 clients in 28.3 msec
[2020-12-19 19:54:25.586 37368M] Received: Real-time signal 0 (34 -> 0)
[2020-12-19 19:54:25.730 37368/T37372] Compiled 0 whitelist and 13 blacklist regex filters for 27 clients in 27.7 msec
[2020-12-19 19:54:26.343 37368M] Received: Real-time signal 0 (34 -> 0)
[2020-12-19 19:54:26.481 37368/T37372] Compiled 0 whitelist and 13 blacklist regex filters for 27 clients in 26.7 msec
[2020-12-19 19:54:27.775 37368M] Received: Real-time signal 0 (34 -> 0)
[2020-12-19 19:54:27.832 37368/T37372] Compiled 0 whitelist and 13 blacklist regex filters for 27 clients in 25.5 msec
[2020-12-19 19:54:27.833 37368/T37879] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-19 19:54:27.833 37368/T37879] ----------------------------> FTL crashed! <----------------------------
[2020-12-19 19:54:27.833 37368/T37879] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-19 19:54:27.833 37368/T37879] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-12-19 19:54:27.833 37368/T37879] and include in your report already the following details:
[2020-12-19 19:54:27.833 37368/T37879] FTL has been running for 1299 seconds
[2020-12-19 19:54:27.833 37368/T37879] FTL branch: master
[2020-12-19 19:54:27.833 37368/T37879] FTL version: v5.3.2
[2020-12-19 19:54:27.833 37368/T37879] FTL commit: 0790cf7
[2020-12-19 19:54:27.833 37368/T37879] FTL date: 2020-12-02 21:28:39 +0000
[2020-12-19 19:54:27.833 37368/T37879] FTL user: started as pihole, ended as pihole
[2020-12-19 19:54:27.833 37368/T37879] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-12-19 19:54:27.833 37368/T37879] Process details: MID: 37368
[2020-12-19 19:54:27.834 37368/T37879] PID: 37368
[2020-12-19 19:54:27.834 37368/T37879] TID: 37879
[2020-12-19 19:54:27.834 37368/T37879] Name: telnet-17
[2020-12-19 19:54:27.834 37368/T37879] Received signal: Segmentation fault
[2020-12-19 19:54:27.834 37368/T37879] at address: (nil)
[2020-12-19 19:54:27.834 37368/T37879] with code: SEGV_MAPERR (Address not mapped to object)
[2020-12-19 19:54:27.834 37368/T37879] Backtrace:
[2020-12-19 19:54:27.835 37368/T37879] B[0000]: /usr/bin/pihole-FTL(+0x555f8) [0xaaaaba8ad5f8]
[2020-12-19 19:54:27.855 37368/T37879] L[0000]: /root/project/src/signals.c:193
[2020-12-19 19:54:27.858 37368/T37879] B[0001]: linux-vdso.so.1(__kernel_rt_sigreturn+0) [0xffff9ed485b8]
[2020-12-19 19:54:27.858 37368/T37879] B[0002]: /lib/aarch64-linux-gnu/libc.so.6(+0x87f0c) [0xffff9eb3bf0c]
[2020-12-19 19:54:27.858 37368/T37879] B[0003]: /lib/aarch64-linux-gnu/libc.so.6(getdelim+0xd0) [0xffff9eb1bc38]
[2020-12-19 19:54:27.858 37368/T37879] B[0004]: /usr/bin/pihole-FTL(+0x4384c) [0xaaaaba89b84c]
[2020-12-19 19:54:27.881 37368/T37879] L[0004]: /root/project/src/config.c:511
[2020-12-19 19:54:27.884 37368/T37879] B[0005]: /usr/bin/pihole-FTL(get_privacy_level+0x4c) [0xaaaaba89bbdc]
[2020-12-19 19:54:27.905 37368/T37879] L[0005]: /root/project/src/config.c:569
[2020-12-19 19:54:27.907 37368/T37879] B[0006]: /usr/bin/pihole-FTL(getTopDomains+0x80) [0xaaaaba8aebb8]
[2020-12-19 19:54:27.928 37368/T37879] L[0006]: /root/project/src/api/api.c:215
[2020-12-19 19:54:27.930 37368/T37879] B[0007]: /usr/bin/pihole-FTL(process_request+0x1d4) [0xaaaaba8b20fc]
[2020-12-19 19:54:27.951 37368/T37879] L[0007]: /root/project/src/api/request.c:54
[2020-12-19 19:54:27.954 37368/T37879] B[0008]: /usr/bin/pihole-FTL(+0x5a794) [0xaaaaba8b2794]
[2020-12-19 19:54:27.975 37368/T37879] L[0008]: /root/project/src/api/socket.c:338
[2020-12-19 19:54:27.977 37368/T37879] B[0009]: /lib/aarch64-linux-gnu/libpthread.so.0(+0x84fc) [0xffff9ec2d4fc]
[2020-12-19 19:54:27.977 37368/T37879] B[0010]: /lib/aarch64-linux-gnu/libc.so.6(+0xd40cc) [0xffff9eb880cc]
[2020-12-19 19:54:27.977 37368/T37879] ------ Listing content of directory /dev/shm ------
[2020-12-19 19:54:27.978 37368/T37879] File Mode User:Group Filesize Filename
[2020-12-19 19:54:27.978 37368/T37879] rwxrwxrwx root:root 260 .
[2020-12-19 19:54:27.978 37368/T37879] rwxr-xr-x root:root 19K ..
[2020-12-19 19:54:27.978 37368/T37879] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-12-19 19:54:27.978 37368/T37879] rw------- pihole:pihole 12K FTL-dns-cache
[2020-12-19 19:54:27.978 37368/T37879] rw------- pihole:pihole 45K FTL-overTime
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 3M FTL-queries
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 20K FTL-upstreams
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 176K FTL-clients
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 98K FTL-domains
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 70K FTL-strings
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 12 FTL-settings
[2020-12-19 19:54:27.979 37368/T37879] rw------- pihole:pihole 152 FTL-counters
[2020-12-19 19:54:27.980 37368/T37879] rw------- pihole:pihole 56 FTL-lock
[2020-12-19 19:54:27.980 37368/T37879] ---------------------------------------------------
[2020-12-19 19:54:27.980 37368/T37879] Please also include some lines from above the !!!!!!!!! header.
[2020-12-19 19:54:27.980 37368/T37879] Thank you for helping us to improve our FTL engine!
[2020-12-19 19:54:27.980 37368/T37879] FTL terminated!
[2020-12-19 19:54:50.810 37928M] Using log file /var/log/pihole-FTL.log
[2020-12-19 19:54:50.810 37928M] ########## FTL started! ##########
[2020-12-19 19:54:50.810 37928M] FTL branch: master
[2020-12-19 19:54:50.810 37928M] FTL version: v5.3.2
[2020-12-19 19:54:50.810 37928M] FTL commit: 0790cf7
[2020-12-19 19:54:50.810 37928M] FTL date: 2020-12-02 21:28:39 +0000
[2020-12-19 19:54:50.810 37928M] FTL user: pihole

@DL6ER
Copy link
Member

DL6ER commented Dec 19, 2020

Looking at

[2020-12-19 19:54:27.832 37368/T37372] Compiled 0 whitelist and 13 blacklist regex filters for 27 clients in 25.5 msec
[2020-12-19 19:54:27.833 37368/T37879] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-19 19:54:27.833 37368/T37879] ----------------------------> FTL crashed! <----------------------------
[2020-12-19 19:54:27.833 37368/T37879] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

it is really very likely that the fix we have prepared in the custom branch will resolve this for you. You can go back to master at any time without loosing any data. Just use pihole checkout ftl master to return to the released version (if you feel you have to).

@jens1205
Copy link
Author

I installed fix/all_the_things - and I still can reproduce the error.

[2020-12-21 05:17:25.574 69050M] ########## FTL started! ##########
[2020-12-21 05:17:25.575 69050M] FTL branch: fix/all_the_things
[2020-12-21 05:17:25.575 69050M] FTL version: vDev-2e0d740
[2020-12-21 05:17:25.575 69050M] FTL commit: 2e0d740
[2020-12-21 05:17:25.575 69050M] FTL date: 2020-12-20 11:07:28 +0100
[2020-12-21 05:17:25.575 69050M] FTL user: pihole
[2020-12-21 05:17:25.575 69050M] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-12-21 05:17:25.575 69050M] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-12-21 05:17:25.575 69050M] SOCKET_LISTENING: only local
[2020-12-21 05:17:25.575 69050M] AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-12-21 05:17:25.575 69050M] MAXDBDAYS: max age for stored queries is 365 days
[2020-12-21 05:17:25.575 69050M] RESOLVE_IPV6: Resolve IPv6 addresses
[2020-12-21 05:17:25.576 69050M] RESOLVE_IPV4: Resolve IPv4 addresses
[2020-12-21 05:17:25.576 69050M] DBINTERVAL: saving to DB file every minute
[2020-12-21 05:17:25.576 69050M] DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-12-21 05:17:25.576 69050M] MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-12-21 05:17:25.576 69050M] PRIVACYLEVEL: Set to 0
[2020-12-21 05:17:25.576 69050M] IGNORE_LOCALHOST: Show queries from localhost
[2020-12-21 05:17:25.576 69050M] BLOCKINGMODE: Null IPs for blocked domains
[2020-12-21 05:17:25.576 69050M] ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-12-21 05:17:25.576 69050M] DBIMPORT: Importing history from database
[2020-12-21 05:17:25.576 69050M] PIDFILE: Using /run/pihole-FTL.pid
[2020-12-21 05:17:25.577 69050M] PORTFILE: Using /run/pihole-FTL.port
[2020-12-21 05:17:25.577 69050M] SOCKETFILE: Using /run/pihole/FTL.sock
[2020-12-21 05:17:25.577 69050M] SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-12-21 05:17:25.577 69050M] MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-12-21 05:17:25.577 69050M] GRAVITYDB: Using /etc/pihole/gravity.db
[2020-12-21 05:17:25.577 69050M] PARSE_ARP_CACHE: Active
[2020-12-21 05:17:25.577 69050M] CNAME_DEEP_INSPECT: Active
[2020-12-21 05:17:25.577 69050M] DELAY_STARTUP: No delay requested.
[2020-12-21 05:17:25.577 69050M] BLOCK_ESNI: Enabled, blocking _esni.{blocked domain}
[2020-12-21 05:17:25.578 69050M] NICE: Set process niceness to -10 (default)
[2020-12-21 05:17:25.578 69050M] MAXNETAGE: Removing IP addresses and host names from network table after 365 days
[2020-12-21 05:17:25.578 69050M] NAMES_FROM_NETDB: Enabled, trying to get names from network database
[2020-12-21 05:17:25.578 69050M] EDNS0_ECS: Overwrite client from ECS information
[2020-12-21 05:17:25.578 69050M] REFRESH_HOSTNAMES: Periodically refreshing IPv4 names
[2020-12-21 05:17:25.578 69050M] Finished config file parsing
[2020-12-21 05:17:25.579 69050M] Creating mutex
[2020-12-21 05:17:25.582 69050M] Database version is 9
[2020-12-21 05:17:25.582 69050M] Imported 0 alias-clients
[2020-12-21 05:17:25.582 69050M] Database successfully initialized
[2020-12-21 05:17:25.583 69050M] New upstream server: 1.0.0.1:53 (0/512)
[2020-12-21 05:17:25.589 69050M] Resizing "FTL-strings" from 4096 to (8192 * 1) == 8192 (/dev/shm: 626.7KB used, 2.0GB total)
[2020-12-21 05:17:25.594 69050M] New upstream server: 192.168.178.1:53 (1/512)
[2020-12-21 05:17:25.597 69050M] New upstream server: 1.1.1.1:53 (2/512)
[2020-12-21 05:17:25.599 69050M] Resizing "FTL-strings" from 8192 to (12288 * 1) == 12288 (/dev/shm: 630.8KB used, 2.0GB total)
[2020-12-21 05:17:25.606 69050M] Resizing "FTL-queries" from 262144 to (8192 * 64) == 524288 (/dev/shm: 634.9KB used, 2.0GB total)
[2020-12-21 05:17:25.608 69050M] Resizing "FTL-strings" from 12288 to (16384 * 1) == 16384 (/dev/shm: 897.0KB used, 2.0GB total)
[2020-12-21 05:17:25.632 69050M] Resizing "FTL-strings" from 16384 to (20480 * 1) == 20480 (/dev/shm: 901.1KB used, 2.0GB total)
[2020-12-21 05:17:25.633 69050M] Resizing "FTL-queries" from 524288 to (12288 * 64) == 786432 (/dev/shm: 905.2KB used, 2.0GB total)
[2020-12-21 05:17:25.662 69050M] Resizing "FTL-strings" from 20480 to (24576 * 1) == 24576 (/dev/shm: 1.2MB used, 2.0GB total)
[2020-12-21 05:17:25.665 69050M] Resizing "FTL-queries" from 786432 to (16384 * 64) == 1048576 (/dev/shm: 1.2MB used, 2.0GB total)
[2020-12-21 05:17:25.689 69050M] Resizing "FTL-queries" from 1048576 to (20480 * 64) == 1310720 (/dev/shm: 1.4MB used, 2.0GB total)
[2020-12-21 05:17:25.703 69050M] Resizing "FTL-strings" from 24576 to (28672 * 1) == 28672 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-21 05:17:25.725 69050M] Resizing "FTL-queries" from 1310720 to (24576 * 64) == 1572864 (/dev/shm: 1.7MB used, 2.0GB total)
[2020-12-21 05:17:25.761 69050M] Resizing "FTL-strings" from 28672 to (32768 * 1) == 32768 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-21 05:17:25.763 69050M] Resizing "FTL-queries" from 1572864 to (28672 * 64) == 1835008 (/dev/shm: 2.0MB used, 2.0GB total)
[2020-12-21 05:17:25.790 69050M] Resizing "FTL-queries" from 1835008 to (32768 * 64) == 2097152 (/dev/shm: 2.2MB used, 2.0GB total)
[2020-12-21 05:17:25.802 69050M] Resizing "FTL-strings" from 32768 to (36864 * 1) == 36864 (/dev/shm: 2.5MB used, 2.0GB total)
[2020-12-21 05:17:25.838 69050M] Resizing "FTL-strings" from 36864 to (40960 * 1) == 40960 (/dev/shm: 2.5MB used, 2.0GB total)
[2020-12-21 05:17:25.839 69050M] Resizing "FTL-queries" from 2097152 to (36864 * 64) == 2359296 (/dev/shm: 2.5MB used, 2.0GB total)
[2020-12-21 05:17:25.860 69050M] Resizing "FTL-queries" from 2359296 to (40960 * 64) == 2621440 (/dev/shm: 2.8MB used, 2.0GB total)
[2020-12-21 05:17:25.898 69050M] Resizing "FTL-queries" from 2621440 to (45056 * 64) == 2883584 (/dev/shm: 3.0MB used, 2.0GB total)
[2020-12-21 05:17:25.921 69050M] Resizing "FTL-strings" from 40960 to (45056 * 1) == 45056 (/dev/shm: 3.3MB used, 2.0GB total)
[2020-12-21 05:17:25.934 69050M] Resizing "FTL-queries" from 2883584 to (49152 * 64) == 3145728 (/dev/shm: 3.3MB used, 2.0GB total)
[2020-12-21 05:17:25.965 69050M] Resizing "FTL-queries" from 3145728 to (53248 * 64) == 3407872 (/dev/shm: 3.6MB used, 2.0GB total)
[2020-12-21 05:17:25.980 69050M] Resizing "FTL-strings" from 45056 to (49152 * 1) == 49152 (/dev/shm: 3.8MB used, 2.0GB total)
[2020-12-21 05:17:26.005 69050M] Resizing "FTL-queries" from 3407872 to (57344 * 64) == 3670016 (/dev/shm: 3.8MB used, 2.0GB total)
[2020-12-21 05:17:26.037 69050M] Resizing "FTL-queries" from 3670016 to (61440 * 64) == 3932160 (/dev/shm: 4.1MB used, 2.0GB total)
[2020-12-21 05:17:26.061 69050M] Resizing "FTL-queries" from 3932160 to (65536 * 64) == 4194304 (/dev/shm: 4.3MB used, 2.0GB total)
[2020-12-21 05:17:26.073 69050M] Resizing "FTL-strings" from 49152 to (53248 * 1) == 53248 (/dev/shm: 4.6MB used, 2.0GB total)
[2020-12-21 05:17:26.083 69050M] Resizing "FTL-queries" from 4194304 to (69632 * 64) == 4456448 (/dev/shm: 4.6MB used, 2.0GB total)
[2020-12-21 05:17:26.101 69050M] Resizing "FTL-queries" from 4456448 to (73728 * 64) == 4718592 (/dev/shm: 4.9MB used, 2.0GB total)
[2020-12-21 05:17:26.123 69050M] Resizing "FTL-queries" from 4718592 to (77824 * 64) == 4980736 (/dev/shm: 5.1MB used, 2.0GB total)
[2020-12-21 05:17:26.142 69050M] Resizing "FTL-queries" from 4980736 to (81920 * 64) == 5242880 (/dev/shm: 5.4MB used, 2.0GB total)
[2020-12-21 05:17:26.171 69050M] Resizing "FTL-queries" from 5242880 to (86016 * 64) == 5505024 (/dev/shm: 5.7MB used, 2.0GB total)
[2020-12-21 05:17:26.203 69050M] Resizing "FTL-strings" from 53248 to (57344 * 1) == 57344 (/dev/shm: 5.9MB used, 2.0GB total)
[2020-12-21 05:17:26.217 69050M] Resizing "FTL-queries" from 5505024 to (90112 * 64) == 5767168 (/dev/shm: 5.9MB used, 2.0GB total)
[2020-12-21 05:17:26.218 69050M] Imported 86022 queries from the long-term database
[2020-12-21 05:17:26.218 69050M] -> Total DNS queries: 86022
[2020-12-21 05:17:26.218 69050M] -> Cached DNS queries: 7257
[2020-12-21 05:17:26.218 69050M] -> Forwarded DNS queries: 17187
[2020-12-21 05:17:26.218 69050M] -> Blocked DNS queries: 60791
[2020-12-21 05:17:26.218 69050M] -> Unknown DNS queries: 508
[2020-12-21 05:17:26.218 69050M] -> Unique domains: 2271
[2020-12-21 05:17:26.218 69050M] -> Unique clients: 23
[2020-12-21 05:17:26.219 69050M] -> Known forward destinations: 3
[2020-12-21 05:17:26.219 69050M] Successfully accessed setupVars.conf
[2020-12-21 05:17:26.231 69052M] PID of FTL process: 69052
[2020-12-21 05:17:26.232 69052M] INFO: FTL is running as user pihole (UID 997)
[2020-12-21 05:17:26.232 69052/T69053] Listening on port 4711 for incoming IPv4 telnet connections
[2020-12-21 05:17:26.232 69052/T69054] Listening on port 4711 for incoming IPv6 telnet connections
[2020-12-21 05:17:26.232 69052M] Reloading DNS cache
[2020-12-21 05:17:26.232 69052/T69055] Listening on Unix socket
[2020-12-21 05:17:26.232 69052M] Blocking status is enabled
[2020-12-21 05:17:26.379 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 20.2 msec
[2020-12-21 05:18:17.291 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:17.351 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 28.0 msec
[2020-12-21 05:18:18.920 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:18.002 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 25.1 msec
[2020-12-21 05:18:20.088 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:20.155 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 24.5 msec
[2020-12-21 05:18:25.004 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:26.116 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 27.8 msec
[2020-12-21 05:18:27.533 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:27.667 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 22.2 msec
[2020-12-21 05:18:30.865 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:30.922 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 27.4 msec
[2020-12-21 05:18:33.508 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:18:33.574 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 24.8 msec
[2020-12-21 05:19:32.115 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:19:32.184 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 27.0 msec
[2020-12-21 05:19:37.370 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:19:37.430 69052/T69056] Resizing "FTL-strings" from 57344 to (61440 * 1) == 61440 (/dev/shm: 6.2MB used, 2.0GB total)
[2020-12-21 05:19:37.440 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 24.3 msec
[2020-12-21 05:19:43.209 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:19:43.304 69052/T69056] Compiled 0 whitelist and 13 blacklist regex filters for 23 clients in 29.1 msec
[2020-12-21 05:19:44.262 69052M] Received: Real-time signal 0 (34 -> 0)
[2020-12-21 05:19:44.327 69052/T69056] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-21 05:19:44.328 69052/T69056] ----------------------------> FTL crashed! <----------------------------
[2020-12-21 05:19:44.328 69052/T69056] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-12-21 05:19:44.328 69052/T69056] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-12-21 05:19:44.328 69052/T69056] and include in your report already the following details:
[2020-12-21 05:19:44.328 69052/T69056] FTL has been running for 139 seconds
[2020-12-21 05:19:44.328 69052/T69056] FTL branch: fix/all_the_things
[2020-12-21 05:19:44.328 69052/T69056] FTL version: vDev-2e0d740
[2020-12-21 05:19:44.328 69052/T69056] FTL commit: 2e0d740
[2020-12-21 05:19:44.328 69052/T69056] FTL date: 2020-12-20 11:07:28 +0100
[2020-12-21 05:19:44.329 69052/T69056] FTL user: started as pihole, ended as pihole
[2020-12-21 05:19:44.329 69052/T69056] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-12-21 05:19:44.329 69052/T69056] Process details: MID: 69052
[2020-12-21 05:19:44.329 69052/T69056] PID: 69052
[2020-12-21 05:19:44.329 69052/T69056] TID: 69056
[2020-12-21 05:19:44.329 69052/T69056] Name: database
[2020-12-21 05:19:44.329 69052/T69056] Received signal: Segmentation fault
[2020-12-21 05:19:44.330 69052/T69056] at address: 0x2
[2020-12-21 05:19:44.330 69052/T69056] with code: SEGV_MAPERR (Address not mapped to object)
[2020-12-21 05:19:44.330 69052/T69056] Backtrace:
[2020-12-21 05:19:44.334 69052/T69056] B[0000]: /usr/bin/pihole-FTL(+0x569f4) [0xaaaadef0f9f4]
[2020-12-21 05:19:44.360 69052/T69056] L[0000]: /root/project/src/signals.c:191
[2020-12-21 05:19:44.362 69052/T69056] B[0001]: linux-vdso.so.1(__kernel_rt_sigreturn+0) [0xffffb55915b8]
[2020-12-21 05:19:44.363 69052/T69056] B[0002]: /lib/aarch64-linux-gnu/libc.so.6(__libc_malloc+0x110) [0xffffb5379650]
[2020-12-21 05:19:44.363 69052/T69056] B[0003]: /usr/bin/pihole-FTL(+0xe01cc) [0xaaaadef991cc]
[2020-12-21 05:19:44.457 69052/T69056] L[0003]: /root/project/src/database/sqlite3.c:23508
[2020-12-21 05:19:44.470 69052/T69056] B[0004]: /usr/bin/pihole-FTL(+0xc0f10) [0xaaaadef79f10]
[2020-12-21 05:19:44.564 69052/T69056] L[0004]: /root/project/src/database/sqlite3.c:27680
[2020-12-21 05:19:44.576 69052/T69056] B[0005]: /usr/bin/pihole-FTL(+0xc6b18) [0xaaaadef7fb18]
[2020-12-21 05:19:44.670 69052/T69056] L[0005]: /root/project/src/database/sqlite3.c:27854
[2020-12-21 05:19:44.683 69052/T69056] B[0006]: /usr/bin/pihole-FTL(+0x13618c) [0xaaaadefef18c]
[2020-12-21 05:19:44.777 69052/T69056] L[0006]: /root/project/src/database/sqlite3.c:135384
[2020-12-21 05:19:44.789 69052/T69056] B[0007]: /usr/bin/pihole-FTL(+0x13ae98) [0xaaaadeff3e98]
[2020-12-21 05:19:44.884 69052/T69056] L[0007]: /root/project/src/database/sqlite3.c:127579
[2020-12-21 05:19:44.896 69052/T69056] B[0008]: /usr/bin/pihole-FTL(+0x13b9f0) [0xaaaadeff49f0]
[2020-12-21 05:19:44.990 69052/T69056] L[0008]: /root/project/src/database/sqlite3.c:127058
[2020-12-21 05:19:44.003 69052/T69056] B[0009]: /usr/bin/pihole-FTL(sqlite3_exec+0x5bc) [0xaaaadf002c74]
[2020-12-21 05:19:45.097 69052/T69056] L[0009]: /root/project/src/database/sqlite3.c:122099
[2020-12-21 05:19:45.109 69052/T69056] B[0010]: /usr/bin/pihole-FTL(+0x13bdbc) [0xaaaadeff4dbc]
[2020-12-21 05:19:45.202 69052/T69056] L[0010]: /root/project/src/database/sqlite3.c:127278
[2020-12-21 05:19:45.214 69052/T69056] B[0011]: /usr/bin/pihole-FTL(+0x14a7e8) [0xaaaadf0037e8]
[2020-12-21 05:19:45.311 69052/T69056] L[0011]: /root/project/src/database/sqlite3.c:127349
[2020-12-21 05:19:45.324 69052/T69056] B[0012]: /usr/bin/pihole-FTL(+0x14a838) [0xaaaadf003838]
[2020-12-21 05:19:45.419 69052/T69056] L[0012]: /root/project/src/database/sqlite3.c:127375
[2020-12-21 05:19:45.432 69052/T69056] B[0013]: /usr/bin/pihole-FTL(+0x14ae98) [0xaaaadf003e98]
[2020-12-21 05:19:45.525 69052/T69056] L[0013]: /root/project/src/database/sqlite3.c:109478
[2020-12-21 05:19:45.537 69052/T69056] B[0014]: /usr/bin/pihole-FTL(+0x14bc88) [0xaaaadf004c88]
[2020-12-21 05:19:45.631 69052/T69056] L[0014]: /root/project/src/database/sqlite3.c:132826
[2020-12-21 05:19:45.643 69052/T69056] B[0015]: /usr/bin/pihole-FTL(+0xbef7c) [0xaaaadef77f7c]
[2020-12-21 05:19:45.736 69052/T69056] L[0015]: /root/project/src/database/sqlite3.c:96750
[2020-12-21 05:19:45.748 69052/T69056] B[0016]: /usr/bin/pihole-FTL(+0xbf208) [0xaaaadef78208]
[2020-12-21 05:19:45.842 69052/T69056] L[0016]: /root/project/src/database/sqlite3.c:96638
[2020-12-21 05:19:45.854 69052/T69056] B[0017]: /usr/bin/pihole-FTL(+0xbf288) [0xaaaadef78288]
[2020-12-21 05:19:45.948 69052/T69056] L[0017]: /root/project/src/database/sqlite3.c:96667
[2020-12-21 05:19:45.960 69052/T69056] B[0018]: /usr/bin/pihole-FTL(+0xbef8c) [0xaaaadef77f8c]
[2020-12-21 05:19:46.055 69052/T69056] L[0018]: /root/project/src/database/sqlite3.c:96680
[2020-12-21 05:19:46.068 69052/T69056] B[0019]: /usr/bin/pihole-FTL(+0xbf9d4) [0xaaaadef789d4]
[2020-12-21 05:19:46.162 69052/T69056] L[0019]: /root/project/src/database/sqlite3.c:133200
[2020-12-21 05:19:46.174 69052/T69056] B[0020]: /usr/bin/pihole-FTL(+0x124cc8) [0xaaaadefddcc8]
[2020-12-21 05:19:46.270 69052/T69056] L[0020]: /root/project/src/database/sqlite3.c:133638
[2020-12-21 05:19:46.282 69052/T69056] B[0021]: /usr/bin/pihole-FTL(+0x134de4) [0xaaaadefedde4]
[2020-12-21 05:19:46.379 69052/T69056] L[0021]: /root/project/src/database/sqlite3.c:155888
[2020-12-21 05:19:46.391 69052/T69056] B[0022]: /usr/bin/pihole-FTL(+0x13ae98) [0xaaaadeff3e98]
[2020-12-21 05:19:46.484 69052/T69056] L[0022]: /root/project/src/database/sqlite3.c:127579
[2020-12-21 05:19:46.496 69052/T69056] B[0023]: /usr/bin/pihole-FTL(+0x13b384) [0xaaaadeff4384]
[2020-12-21 05:19:46.590 69052/T69056] L[0023]: /root/project/src/database/sqlite3.c:127650
[2020-12-21 05:19:46.602 69052/T69056] B[0024]: /usr/bin/pihole-FTL(+0x5eddc) [0xaaaadef17ddc]
[2020-12-21 05:19:46.624 69052/T69056] L[0024]: /root/project/src/database/gravity-db.c:146
[2020-12-21 05:19:46.626 69052/T69056] B[0025]: /usr/bin/pihole-FTL(gravityDB_reopen+0x64) [0xaaaadef19294]
[2020-12-21 05:19:46.648 69052/T69056] L[0025]: /root/project/src/database/gravity-db.c:75
[2020-12-21 05:19:46.650 69052/T69056] B[0026]: /usr/bin/pihole-FTL(FTL_reload_all_domainlists+0x40) [0xaaaadef00698]
[2020-12-21 05:19:46.671 69052/T69056] L[0026]: /root/project/src/datastructure.c:485
[2020-12-21 05:19:46.673 69052/T69056] B[0027]: /usr/bin/pihole-FTL(DB_thread+0x184) [0xaaaadef179bc]
[2020-12-21 05:19:46.694 69052/T69056] L[0027]: /root/project/src/database/database-thread.c:84
[2020-12-21 05:19:46.696 69052/T69056] B[0028]: /lib/aarch64-linux-gnu/libpthread.so.0(+0x84fc) [0xffffb54764fc]
[2020-12-21 05:19:46.696 69052/T69056] B[0029]: /lib/aarch64-linux-gnu/libc.so.6(+0xd40cc) [0xffffb53d10cc]
[2020-12-21 05:19:46.696 69052/T69056] ------ Listing content of directory /dev/shm ------
[2020-12-21 05:19:46.696 69052/T69056] File Mode User:Group Filesize Filename
[2020-12-21 05:19:46.697 69052/T69056] rwxrwxrwx root:root 260 .
[2020-12-21 05:19:46.697 69052/T69056] rwxr-xr-x root:root 19K ..
[2020-12-21 05:19:46.697 69052/T69056] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-12-21 05:19:46.697 69052/T69056] rw------- pihole:pihole 4K FTL-dns-cache
[2020-12-21 05:19:46.697 69052/T69056] rw------- pihole:pihole 45K FTL-overTime
[2020-12-21 05:19:46.697 69052/T69056] rw------- pihole:pihole 6M FTL-queries
[2020-12-21 05:19:46.698 69052/T69056] rw------- pihole:pihole 20K FTL-upstreams
[2020-12-21 05:19:46.698 69052/T69056] rw------- pihole:pihole 176K FTL-clients
[2020-12-21 05:19:46.698 69052/T69056] rw------- pihole:pihole 98K FTL-domains
[2020-12-21 05:19:46.698 69052/T69056] rw------- pihole:pihole 61K FTL-strings
[2020-12-21 05:19:46.698 69052/T69056] rw------- pihole:pihole 12 FTL-settings
[2020-12-21 05:19:46.698 69052/T69056] rw------- pihole:pihole 144 FTL-counters
[2020-12-21 05:19:46.699 69052/T69056] rw------- pihole:pihole 56 FTL-lock
[2020-12-21 05:19:46.699 69052/T69056] ---------------------------------------------------
[2020-12-21 05:19:46.699 69052/T69056] Please also include some lines from above the !!!!!!!!! header.
[2020-12-21 05:19:46.699 69052/T69056] Thank you for helping us to improve our FTL engine!
[2020-12-21 05:19:46.699 69052/T69056] FTL terminated!

@jens1205
Copy link
Author

I have attached gdb to the process (as described in https://docs.pi-hole.net/ftldns/debugging/). Here is the output when it crashes

[New Thread 0xffffa1bec1e0 (LWP 72454)]
[Thread 0xffffa1bec1e0 (LWP 72454) exited]
[New Thread 0xffffa1bec1e0 (LWP 72455)]
[Thread 0xffffa1bec1e0 (LWP 72455) exited]
[New Thread 0xffffa1bec1e0 (LWP 72467)]
[Thread 0xffffa1bec1e0 (LWP 72467) exited]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72473)]
[Thread 0xffffa1bec1e0 (LWP 72473) exited]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72479)]
[Thread 0xffffa1bec1e0 (LWP 72479) exited]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72485)]
[Thread 0xffffa1bec1e0 (LWP 72485) exited]
[New Thread 0xffffa1bec1e0 (LWP 72486)]
[Detaching after fork from child process 72487]
[Thread 0xffffa1bec1e0 (LWP 72486) exited]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72493)]
[Thread 0xffffa1bec1e0 (LWP 72493) exited]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72499)]
[Thread 0xffffa1bec1e0 (LWP 72499) exited]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72505)]
[Thread 0xffffa1bec1e0 (LWP 72505) exited]
[Detaching after vfork from child process 72509]
[Detaching after vfork from child process 72513]

Thread 1 "pihole-FTL" received signal SIG34, Real-time event 34.
[New Thread 0xffffa1bec1e0 (LWP 72515)]

Thread 18 "telnet-19" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xffffa1bec1e0 (LWP 72515)]

@DL6ER
Copy link
Member

DL6ER commented Dec 21, 2020

Thanks! When you see

 received signal SIGSEGV, Segmentation fault.

could you then run backtrace inside gdb and copy the entire result as well?

@jens1205
Copy link
Author

jens1205 commented Dec 21, 2020

#0  unlink_chunk (p=p@entry=0xffff7c0629d0, av=0xffff7c000020) at malloc.c:1459
#1  0x0000ffff957fe5d8 in _int_malloc (av=av@entry=0xffff7c000020, bytes=bytes@entry=264) at malloc.c:4041
#2  0x0000ffff957ff69c in __GI___libc_malloc (bytes=bytes@entry=264) at malloc.c:3066
#3  0x0000aaaab8f1e1cc in sqlite3MemMalloc (nByte=256) at /root/project/src/database/sqlite3.c:23508
#4  0x0000aaaab8efef10 in dbMallocRawFinish (db=0xffff7c025d48, n=<optimized out>) at /root/project/src/database/sqlite3.c:27680
#5  0x0000aaaab8f0663c in exprDup (db=0xffff7c025d48, p=0xffff7c058608, dupFlags=1, pzBuffer=0x0)
    at /root/project/src/database/sqlite3.c:99950
#6  0x0000aaaab8f05b58 in sqlite3ExprDup (flags=1, p=<optimized out>, db=0xffff7c025d48)
    at /root/project/src/database/sqlite3.c:100113
#7  sqlite3SrcListDup (db=db@entry=0xffff7c025d48, p=0xffff937f2128, flags=-1192298888, flags@entry=1)
    at /root/project/src/database/sqlite3.c:34665
#8  0x0000aaaab8f05eec in sqlite3SelectDup (db=db@entry=0xffff7c025d48, pDup=pDup@entry=0xffff7c04b458, flags=flags@entry=1)
    at /root/project/src/database/sqlite3.c:100242
#9  0x0000aaaab8f77f40 in sqlite3CreateView (pBegin=0xffff937f1750, noErr=<optimized out>, isTemp=<optimized out>,
    pSelect=0xffff7c04b458, pCNames=0x0, pName2=0xffff937f17c8, pName1=0xffff937f17b0, pParse=0xffff937f2128)
    at /root/project/src/database/sqlite3.c:111633
#10 yy_reduce (yyLookahead=<optimized out>, pParse=0xffff937f2128, yyLookaheadToken=..., yyruleno=80, yypParser=0xffff937f1820)
    at /root/project/src/database/sqlite3.c:24804
#11 sqlite3Parser (yyminor=..., yymajor=<optimized out>, yyp=0xffff937f1820) at /root/project/src/database/sqlite3.c:26109
#12 sqlite3RunParser (pParse=pParse@entry=0xffff937f2128, zSql=<optimized out>, zSql@entry=0x0,
    pzErrMsg=pzErrMsg@entry=0xffff937f2190) at /root/project/src/database/sqlite3.c:27383
#13 0x0000aaaab8f78e98 in sqlite3Prepare (db=db@entry=0xffff7c025d48, zSql=0x0, nBytes=nBytes@entry=-1,
    prepFlags=prepFlags@entry=0, pReprepare=pReprepare@entry=0x0, ppStmt=0x0, ppStmt@entry=0xffff937f2340,
    pzTail=pzTail@entry=0x0) at /root/project/src/database/sqlite3.c:127575
#14 0x0000aaaab8f799f0 in sqlite3InitCallback (pInit=0xffff937f2440, argc=<optimized out>, argv=0xffff7c0842b0,
    NotUsed=<optimized out>) at /root/project/src/database/sqlite3.c:127055
#15 0x0000aaaab8f87c74 in sqlite3_exec (db=0x0, zSql=<optimized out>, xCallback=0xaaaab90ed000 <[email protected]>,
    pArg=0x0, pzErrMsg=0x0) at /root/project/src/database/sqlite3.c:122099
#16 0x0000aaaab8f79dbc in sqlite3InitOne (db=0xffff7c025d48, iDb=iDb@entry=0, pzErrMsg=pzErrMsg@entry=0xffff937f3620,
    mFlags=mFlags@entry=0) at /root/project/src/database/sqlite3.c:127276
#17 0x0000aaaab8f887e8 in sqlite3Init (db=db@entry=0xffff7c025d48, pzErrMsg=pzErrMsg@entry=0xffff937f3620)
    at /root/project/src/database/sqlite3.c:127348
#18 0x0000aaaab8f88838 in sqlite3ReadSchema (pParse=pParse@entry=0xffff937f3618) at /root/project/src/database/sqlite3.c:127374
#19 0x0000aaaab8f88e98 in sqlite3LocateTable (pParse=0xffff937f3618, flags=0, zName=0xffff7c084a08 "domain_audit", zDbase=0x0)
    at /root/project/src/database/sqlite3.c:109478
#20 0x0000aaaab8f89c88 in selectExpander (pWalker=0xffff937f27d8, p=0x0) at /root/project/src/database/sqlite3.c:132826
#21 0x0000aaaab8efcf7c in sqlite3WalkSelect (pWalker=pWalker@entry=0xffff937f27d8, p=0xffff7c084808)
    at /root/project/src/database/sqlite3.c:96749
#22 0x0000aaaab8efd208 in walkExpr (pWalker=pWalker@entry=0xffff937f27d8, pExpr=0xffff7c084788)
    at /root/project/src/database/sqlite3.c:96638
#23 0x0000aaaab8efd288 in sqlite3WalkExpr (pExpr=<optimized out>, pWalker=0xffff937f27d8)
    at /root/project/src/database/sqlite3.c:96655
#24 sqlite3WalkExprList (pWalker=0xffff937f27d8, p=<optimized out>) at /root/project/src/database/sqlite3.c:31131
#25 0x0000aaaab8efcf8c in sqlite3WalkSelectExpr (p=0xffff7c084608, pWalker=0xffff937f27d8)
    at /root/project/src/database/sqlite3.c:96680
#26 sqlite3WalkSelect (pWalker=pWalker@entry=0xffff937f27d8, p=p@entry=0xffff7c084608)
    at /root/project/src/database/sqlite3.c:31215
#27 0x0000aaaab8efd9d4 in sqlite3SelectExpand (pSelect=0xffff7c084608, pParse=0xffff937f3618)
    at /root/project/src/database/sqlite3.c:133114
#28 sqlite3SelectPrep (pParse=0xffff937f3618, p=0xffff7c084608, pOuterNC=0x0) at /root/project/src/database/sqlite3.c:2127
#29 0x0000aaaab8f62cc8 in sqlite3Select (pParse=pParse@entry=0xffff937f3618, p=0xffff7c084608, pDest=0xffff937f2be0,
    pDest@entry=0xffff937f2ce0) at /root/project/src/database/sqlite3.c:133637
#30 0x0000aaaab8f72de4 in yy_reduce (yyLookahead=<optimized out>, pParse=0xffff937f3618, yyLookaheadToken=..., yyruleno=82,
    yypParser=0xffff937f2d10) at /root/project/src/database/sqlite3.c:155887
#31 sqlite3Parser (yyminor=..., yymajor=<optimized out>, yyp=0xffff937f2d10) at /root/project/src/database/sqlite3.c:26109
#32 sqlite3RunParser (pParse=pParse@entry=0xffff937f3618, zSql=<optimized out>, zSql@entry=0x0,
    pzErrMsg=pzErrMsg@entry=0xffff937f3680) at /root/project/src/database/sqlite3.c:27383
#33 0x0000aaaab8f78e98 in sqlite3Prepare (db=db@entry=0xffff7c025d48, zSql=0x0,
    zSql@entry=0xaaaab90575f8 "SELECT EXISTS(SELECT domain, CASE WHEN substr(domain, 1, 1) = '*' THEN '*' || substr(:input, - length(domain) + 1) ELSE :input END matcher FROM domain_audit WHERE matcher = domain);", nBytes=nBytes@entry=-1,
    prepFlags=prepFlags@entry=128, pReprepare=pReprepare@entry=0x0, ppStmt=0x0, ppStmt@entry=0xaaaab90f75d8 <auditlist_stmt>,
    pzTail=pzTail@entry=0x0) at /root/project/src/database/sqlite3.c:127575
#34 0x0000aaaab8f79384 in sqlite3LockAndPrepare (db=0xffff7c025d48,
    zSql=0xaaaab90575f8 "SELECT EXISTS(SELECT domain, CASE WHEN substr(domain, 1, 1) = '*' THEN '*' || substr(:input, - length(domain) + 1) ELSE :input END matcher FROM domain_audit WHERE matcher = domain);", nBytes=-1, prepFlags=128, pOld=0x0,
    ppStmt=0xaaaab90f75d8 <auditlist_stmt>, pzTail=0x0) at /root/project/src/database/sqlite3.c:127647
#35 0x0000aaaab8e9cddc in gravityDB_open () at /root/project/src/database/gravity-db.c:136
#36 0x0000aaaab8e9e294 in gravityDB_open () at /root/project/src/database/gravity-db.c:88
#37 gravityDB_reopen () at /root/project/src/database/gravity-db.c:74
#38 0x0000aaaab8e85698 in FTL_reload_all_domainlists () at /root/project/src/datastructure.c:482
#39 0x0000aaaab8e9c9bc in DB_thread (val=<optimized out>) at /root/project/src/database/database-thread.c:81
#40 0x0000ffff958fc4fc in start_thread (arg=0xffffcbb95bff) at pthread_create.c:477
#41 0x0000ffff958570cc in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

edit Code formatting added.

@DL6ER
Copy link
Member

DL6ER commented Dec 21, 2020

This looks very much similar to what @yubiuser is seeing (#960 (comment)). It is a crash deep down when preparing the audit database statement. With all the information, I'm not pretty confident that this is an original SQLite3 bug. Could one of you report it to the SQLite3 maintainers?

https://www.sqlite.org/src/wiki?name=Bug+Reports

The crashing statement is

SELECT EXISTS(SELECT domain, CASE WHEN substr(domain, 1, 1) = '*' THEN '*' || substr(:input, - length(domain) + 1) ELSE :input END matcher FROM domain_audit WHERE matcher = domain);

Others than that I can work out an alternative query doing the same (wildcard matching) and substitute this. This may circumvent the problem in SQLite3. It would obviously be nicer if we could get it fixed upstream without any needs for working around it (we can never be sure it doesn't happen again).

The SQL statement above together with the backtrace should give the SQLite3 maintainers enough to work on this. You can also give them the schema of the corresponding table as they may need it:

CREATE TABLE domain_audit
(
	id INTEGER PRIMARY KEY AUTOINCREMENT,
	domain TEXT UNIQUE NOT NULL,
	date_added INTEGER NOT NULL DEFAULT (cast(strftime('%s', 'now') as int))
);

@jens1205
Copy link
Author

jens1205 commented Dec 21, 2020

I reported it in sqlite3 (https://www.sqlite.org/forum/forumpost/bd706d2342)

@jens1205
Copy link
Author

First reaction is that they think it's a heap corruption caused by the calling programm - and until someone proves it's not, they will not have a closer look.

But I saw that you just changed the code of the prepared statemen in #992. If its integrated in some branch I can retest.

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

Saying it's the other application's fault is the easy solution, however, as they can always be right, there isn't much we can do about it unless we could truly identify the bug ourselves in the 228.449 lines of sqlite3.c (yes, that number is not a typo).

What I'm just seeing is that both reports we have for the crashing (@jens1205 @yubiuser) are on the aarch64 architecture. Since aarch64 is really rarely used (just an assumption, though) plus few people uses auditing, it makes me believe that these two reports may even be representative for the entire architecture. It doesn't happen and cannot be reproduced on any other CPU architecture.

Unfortunately, their suggestion of using the AddressSanitizer is not going to help here as aarch64 is not supported on Linux (see here, look for ARM64). Neither is running in valgrind (see here).

From your reports, I see

  • OS and version: ubuntu server Ubuntu 20.04.1 LTS
  • Platform: Raspberry Pi (@jens1205 which revision are you using?)
    and
  • OS and version: Debian 10
  • Platform: NanoPi Neo 2 Plus

so I'll likely try to former to reproduce this myself. Unfortunately, I do not have a 64bit NanoPi around (only the NanoPi NEO which is Cortex-A7 = 32bit), however, the bug should be similarly reproducible on the Raspberry Pi.

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

@jens1205

But I saw that you just changed the code of the prepared statement in #992. If its integrated in some branch I can retest.

It has already been tested here #960 (comment) and found to make no difference.

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

You could also try to crash FTL using

while true; do sudo pkill -HUP pihole-FTL; sleep 0.2; done

so without any need to click on really any auditing button fast. It should have a very similar effect.

@jens1205
Copy link
Author

Platform: Raspberry Pi (@jens1205 which revision are you using?)

It's a Raspberry Pi 4 Model B

@jens1205
Copy link
Author

I tried

while true; do sudo pkill -HUP pihole-FTL; sleep 0.2; done

But no crash. Only a lot of "Reloading DNS Cache" entries in the logfile.

I'm still on

[2020-12-22 05:51:01.310 97695M] FTL branch: fix/all_the_things
[2020-12-22 05:51:01.310 97695M] FTL version: vDev-2e0d740
[2020-12-22 05:51:01.310 97695M] FTL commit: 2e0d740
[2020-12-22 05:51:01.310 97695M] FTL date: 2020-12-20 11:07:28 +0100
[2020-12-22 05:51:01.310 97695M] FTL user: pihole

@DL6ER DL6ER added the Unclear label Dec 22, 2020
@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

I only have a Raspberry Pi 3 available so I'll first try with this one. If it doesn't work, I'll order a Raspberry Pi 4 ...

edit Looking good so far, I'll be able to do more tests later:

  [i] FTL Checks...

  [✓] Detected AArch64 (64 Bit ARM) processor
  [i] Checking for existing FTL binary...
  [✓] Downloading and Installing FTL

@yubiuser
Copy link
Member

Neither is running in valgrind

Valgrind is supported on ARM64/Linux (for ARMv8) . I installed the latest version 3.16.1, but I failed to run pihole inside valgrind

nanopi@nanopi:~$ sudo valgrind /usr/bin/pihole-FTL
==21260== 
==21260== Warning: Can't execute setuid/setgid/setcap executable: /usr/bin/pihole-FTL
==21260== Possible workaround: remove --trace-children=yes, if in effect
==21260== 
valgrind: /usr/bin/pihole-FTL: Permission denied

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

@yubiuser To remove capabilities from FTL use the -r flag

sudo setcap -r /usr/bin/pihole-FTL

They'll be reinstalled by sudo service pihole-FTL restart

@yubiuser
Copy link
Member

yubiuser commented Dec 22, 2020

Even without the while loop valgrind doesn't run long (less than 20 sec). Pihole continues to work.

valgrind.log

Add

And with the loop:

==2152== 1,120,000 bytes in 1 blocks are still reachable in loss record 68 of 68
==2152==    at 0x484A164: calloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==2152==    by 0x1B6BEB: safe_malloc (util.c:282)
==2152==    by 0x1749A3: cache_init (cache.c:111)
==2152==    by 0x181023: main_dnsmasq (dnsmasq.c:394)
==2152==    by 0x14A783: main (main.c:95)
==2152== 
==2152== LEAK SUMMARY:
==2152==    definitely lost: 0 bytes in 0 blocks
==2152==    indirectly lost: 0 bytes in 0 blocks
==2152==      possibly lost: 0 bytes in 0 blocks
==2152==    still reachable: 1,139,510 bytes in 76 blocks
==2152==                       of which reachable via heuristic:
==2152==                         length64           : 16 bytes in 1 blocks
==2152==         suppressed: 0 bytes in 0 blocks
==2152== 
==2152== For lists of detected and suppressed errors, rerun with: -s
==2152== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
nanopi@nanopi:~$ ==2153== Syscall param sendmsg(msg.msg_control) points to uninitialised byte(s)
==2153==    at 0x494B284: __libc_sendmsg (sendmsg.c:28)
==2153==    by 0x494B284: sendmsg (sendmsg.c:25)
==2153==    by 0x18765B: send_from (forward.c:95)
==2153==    by 0x18A7C7: reply_query (forward.c:1282)
==2153==    by 0x17F087: check_dns_listeners (dnsmasq.c:1764)
==2153==    by 0x1808F7: main_dnsmasq (dnsmasq.c:1203)
==2153==    by 0x14A783: main (main.c:95)
==2153==  Address 0x1ffefffffc is on thread 1's stack
==2153==  in frame #1, created by send_from (forward.c:32)
==2153== 
==2153== Syscall param sendmsg(msg.msg_control) points to uninitialised byte(s)
==2153==    at 0x494B284: __libc_sendmsg (sendmsg.c:28)
==2153==    by 0x494B284: sendmsg (sendmsg.c:25)
==2153==    by 0x18765B: send_from (forward.c:95)
==2153==    by 0x189CF3: receive_query (forward.c:1639)
==2153==    by 0x17F0EB: check_dns_listeners (dnsmasq.c:1791)
==2153==    by 0x1808F7: main_dnsmasq (dnsmasq.c:1203)
==2153==    by 0x14A783: main (main.c:95)
==2153==  Address 0x1ffeffff0c is on thread 1's stack
==2153==  in frame #1, created by send_from (forward.c:32)
==2153== 
==2153== Syscall param sendmsg(msg.msg_control) points to uninitialised byte(s)
==2153==    at 0x494B284: __libc_sendmsg (sendmsg.c:28)
==2153==    by 0x494B284: sendmsg (sendmsg.c:25)
==2153==    by 0x18765B: send_from (forward.c:95)
==2153==    by 0x18A04B: receive_query (forward.c:1649)
==2153==    by 0x17F0EB: check_dns_listeners (dnsmasq.c:1791)
==2153==    by 0x1808F7: main_dnsmasq (dnsmasq.c:1203)
==2153==    by 0x14A783: main (main.c:95)
==2153==  Address 0x1ffeffff0c is on thread 1's stack
==2153==  in frame #1, created by send_from (forward.c:32)
==2153== 
==2153== Syscall param sendmsg(msg.msg_control) points to uninitialised byte(s)
==2153==    at 0x494B284: __libc_sendmsg (sendmsg.c:28)
==2153==    by 0x494B284: sendmsg (sendmsg.c:25)
==2153==    by 0x18765B: send_from (forward.c:95)
==2153==    by 0x189233: forward_query (forward.c:589)
==2153==    by 0x18A117: receive_query (forward.c:1653)
==2153==    by 0x17F0EB: check_dns_listeners (dnsmasq.c:1791)
==2153==    by 0x1808F7: main_dnsmasq (dnsmasq.c:1203)
==2153==    by 0x14A783: main (main.c:95)
==2153==  Address 0x1ffefffe1c is on thread 1's stack
==2153==  in frame #1, created by send_from (forward.c:32)
==2153== 

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

looks perfectly fine. Do you see any hint why it stopped? Is there anything in the Pi-hole log files in /var/log ?


Edit @yubiuser from your valgrind.log:

dnsmasq: failed to create listening socket for port 53: Address already in use
You need to stop the running FTL instance first before you can start a new one (inside valgrind`)

@yubiuser
Copy link
Member

yubiuser commented Dec 22, 2020

I tried with the loop again and got the same result:
FTL.log
valgrind.log

The dashboard shows FTL offline but DNS resolution still running (My fault....of course... it's running as root... )

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

You may need to try pihole-FTL -f to prevent FTL from forking inside valgrind.

@DL6ER
Copy link
Member

DL6ER commented Dec 22, 2020

I tried really hard to get it to crash, however, it did it only once (and this was when my SD card got full). Nonetheless, I added some smaller improvements to the code so please update your FTLs before trying to continue to crash it.

@yubiuser
Copy link
Member

update your FTLs before

Which is the branch to go? Last update to fix/all_the_things was two days ago, so I guess it''s tweak/audit_statement_and_all_the_things or only tweak/audit_statement?

@DL6ER
Copy link
Member

DL6ER commented Dec 23, 2020

tweak/audit_statement_and_all_the_things is the best fit right now. Thanks!

@DL6ER
Copy link
Member

DL6ER commented Dec 24, 2020

The next version of FTL has been released. Please update and run

pihole checkout master

to get back on-track. Thanks for helping us to make Pi-hole better for us all!

If you still experience any issues, please either reopen this ticket or (preferably) create a new ticket describing the issues in further detail and only reference this ticket. This will help us to help you best.

@DL6ER DL6ER closed this as completed Dec 24, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants