FTL crashing on processing on transparent Nginx DoT setup

[hiyan]

In raising this issue, I confirm the following (please check boxes, eg [X]) Failure to fill the template will close your issue:

• [X] I have read and understood the contributors guide.
• [X] The issue I am reporting can be replicated
• [X] The issue I am reporting isn't a duplicate

How familiar are you with the codebase?: 1

---

[BUG | ISSUE] Expected Behaviour: No error

[BUG | ISSUE] Actual Behaviour: FTL log show crashes, but FTL is still able to resolve dns requests.

[BUG | ISSUE] Steps to reproduce: Disclaimer: Long story so please bear with me... Also I'm not sure this is Pi-hole's issue to address. If not, no worries and close this.

My setup: First; I've setup a Private DoT using Nginx which is working fine. Port forward 853 from router to Nginx (I'm aware of the implication/exposure of this).

Second: However, I didn't like how the requesting IP always shows the Nginx IP, so I followed this (https://discourse.pi-hole.net/t/nginx-with-dns-over-tls-only-localhost/26064/21). Again, this went well.

Third: I've also made the following changes to dnsmaq configuration Added the following 2 lines and commented out localise-queries I did this so that my client (phone) uses the external ip with off network and internal ip when inside.

public IP

host-record=,xxx.xxx.xxx.xxx,2

local IP

host-record=,192.168.x.x,2

At this point, everything is working as I wanted it to...

So how to replicate this "crash"...

1. Phone connected to wifi (internal network) -- Eg: 10:50
2. Wait for the PTR hourly update -- Eg: 11:00
3. Disconnect wifi and uses mobile network -- Eg: 11:05
4. Below crash happens in FTL and phone is not able to resolve dns request. (Pihole log shows request was received but not resolving). Guess this is due to FTL's crash.
5. pihole restartdns will resolve this.

Note: After step 1, if I disconnect from wifi before 11:00, it would work fine without any crashes, and continue to do so after 11:00. It's only the above scenario that FTL crashes.

Log file output [if available] Token: 7ls3k7ik0k

pihole-FTL.log

[2020-02-21 09:14:02.671 29246] SQLite3 message: API called with finalized prepared statement (21)
[2020-02-21 09:14:02.672 29246] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-02-21 09:14:02.673 29246] domain_in_list("app-measurement.com"): Failed to bind domain (error 21) - not an error
[2020-02-21 09:14:02.673 29246] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-02-21 09:14:02.673 29246] ---------------------------->  FTL crashed!  <----------------------------
[2020-02-21 09:14:02.674 29246] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-02-21 09:14:02.674 29246] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-02-21 09:14:02.674 29246] and include in your report already the following details:
[2020-02-21 09:14:02.675 29246] FTL has been running for 45871 seconds
[2020-02-21 09:14:02.675 29246] FTL branch: release/v5.0
[2020-02-21 09:14:02.675 29246] FTL version: vDev-61d67ff
[2020-02-21 09:14:02.675 29246] FTL commit: 61d67ff
[2020-02-21 09:14:02.676 29246] FTL date: 2020-02-19 21:08:53 +0100
[2020-02-21 09:14:02.677 29246] FTL user: started as pihole, ended as pihole
[2020-02-21 09:14:02.677 29246] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-02-21 09:14:02.677 29246] Received signal: Segmentation fault
[2020-02-21 09:14:02.677 29246]      at address: 0xc
[2020-02-21 09:14:02.678 29246]      with code: SEGV_MAPERR (Address not mapped to object)
[2020-02-21 09:14:02.679 29246] Backtrace:
[2020-02-21 09:14:02.682 29246] B[0000]: 0x51ef74, /usr/bin/pihole-FTL(+0x2bf74) [0x51ef74]
[2020-02-21 09:14:02.682 29246] B[0001]: 0xb6df7130, /lib/arm-linux-gnueabihf/libc.so.6(__default_rt_sa_restorer+0) [0xb6df7130]
[2020-02-21 09:14:02.683 29246] B[0002]: 0x5f6e68, /usr/bin/pihole-FTL(sqlite3_reset+0x18) [0x5f6e68]
[2020-02-21 09:14:02.683 29246] B[0003]: 0x517524, /usr/bin/pihole-FTL(in_whitelist+0xf8) [0x517524]
[2020-02-21 09:14:02.683 29246] B[0004]: 0x522d84, /usr/bin/pihole-FTL(+0x2fd84) [0x522d84]
[2020-02-21 09:14:02.683 29246] B[0005]: 0x5243fc, /usr/bin/pihole-FTL(_FTL_new_query+0x684) [0x5243fc]
[2020-02-21 09:14:02.684 29246] B[0006]: 0x53bef4, /usr/bin/pihole-FTL(tcp_request+0x6a4) [0x53bef4]
[2020-02-21 09:14:02.684 29246] B[0007]: 0x552e84, /usr/bin/pihole-FTL(+0x5fe84) [0x552e84]
[2020-02-21 09:14:02.684 29246] B[0008]: 0x554b68, /usr/bin/pihole-FTL(main_dnsmasq+0xe90) [0x554b68]
[2020-02-21 09:14:02.684 29246] B[0009]: 0x511acc, /usr/bin/pihole-FTL(main+0xd8) [0x511acc]
[2020-02-21 09:14:02.685 29246] B[0010]: 0xb6de1718, /lib/arm-linux-gnueabihf/libc.so.6(__libc_start_main+0x10c) [0xb6de1718]
[2020-02-21 09:14:02.685 29246] ------ Listing content of directory /dev/shm ------
[2020-02-21 09:14:02.685 29246] File Mode User:Group  Filesize Filename
[2020-02-21 09:14:02.686 29246] rwxrwxrwx root:root 260 .
[2020-02-21 09:14:02.687 29246] rwxr-xr-x root:root 3K ..
[2020-02-21 09:14:02.688 29246] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-02-21 09:14:02.689 29246] rw------- pihole:pihole 33K FTL-dns-cache
[2020-02-21 09:14:02.690 29246] rw------- pihole:pihole 53K FTL-overTime
[2020-02-21 09:14:02.691 29246] rw------- pihole:pihole 1M FTL-queries
[2020-02-21 09:14:02.692 29246] rw------- pihole:pihole 20K FTL-upstreams
[2020-02-21 09:14:02.693 29246] rw------- pihole:pihole 20K FTL-clients
[2020-02-21 09:14:02.694 29246] rw------- pihole:pihole 66K FTL-domains
[2020-02-21 09:14:02.695 29246] rw------- pihole:pihole 66K FTL-strings
[2020-02-21 09:14:02.696 29246] rw------- pihole:pihole 12 FTL-settings
[2020-02-21 09:14:02.697 29246] rw------- pihole:pihole 120 FTL-counters
[2020-02-21 09:14:02.698 29246] rw------- pihole:pihole 28 FTL-lock
[2020-02-21 09:14:02.698 29246] ---------------------------------------------------
[2020-02-21 09:14:02.698 29246] Thank you for helping us to improve our FTL engine!
[2020-02-21 09:14:02.699 29246] FTL terminated!

_Note:

1. same crash log would happen for every request from the mobile.
2. FTL would continue working normally for other network clients during this time. _

pihole.log

Feb 21 09:14:02 dnsmasq[29246]: query[A] app-measurement.com from <mobile's external IP>
Feb 21 09:14:03 dnsmasq[29247]: query[A] app-measurement.com from <mobile's external IP>
Feb 21 09:14:03 dnsmasq[29248]: query[A] app-measurement.com from <mobile's external IP>
Feb 21 09:14:04 dnsmasq[29250]: query[A] app-measurement.com from <mobile's external IP>
Feb 21 09:14:04 dnsmasq[29257]: query[A] app-measurement.com from <mobile's external IP>
Feb 21 09:14:05 dnsmasq[29269]: query[A] app-measurement.com from <mobile's external IP>
Feb 21 09:14:16 dnsmasq[16033]: query[A] app-measurement.com from 192.168.x.x <other internal client>
Feb 21 09:14:16 dnsmasq[16033]: gravity blocked app-measurement.com is 0.0.0.0

Device specifics

Hardware Type: rPi, VPS, etc OS: Pi Zero, Raspbian Lite

This template was created based on the work of udemy-dl.

[DL6ER]

Can you still reproduce this?

If so, please try whether

pihole checkout ftl tweak/sqlite_debugging

fixes your problem.

[hiyan]

Yes, I can still reproduce the crash.

Will report back once I get to test it on the debugging branch.

[hiyan]

I was successful in pulling the branch, but FTL is now not able to start.

Error in pihole-FTL.log: [2020-03-09 14:59:00.235 5644] Reloading DNS cache [2020-03-09 14:59:00.241 5644] Blocking status is enabled [2020-03-09 14:59:10.290 5644] gravityDB_open() - SQL error (14): unable to open database file

Nothing is listening on port 53 in netstat.

FTL back to operation after switching back to release/v5.0

[hiyan]

Re-tried applying the patch, then rebooted the pi.

Got the following errors in pihole-FTL.log after

tail pihole-FTL.log
[2020-03-09 15:17:33.282 499] Reloading DNS cache
[2020-03-09 15:17:33.283 499] Blocking status is enabled
[2020-03-09 15:18:10.391 499] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
[2020-03-09 15:18:10.444 499] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
[2020-03-09 15:18:10.444 499] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/pihole-FTL.db) -  (14)
[2020-03-09 15:18:10.444 499] dbopen() - SQL error (14): unable to open database file
[2020-03-09 15:18:10.445 499] check_database(14): Disabling database connection due to error
[2020-03-09 15:18:10.445 499] getDatabaseHostname(192.168.1.176) - Failed to open DB
[2020-03-09 15:18:10.447 499] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/gravity.db) -  (14)
[2020-03-09 15:18:10.447 499] gravityDB_open() - SQL error (14): unable to open database file

[DL6ER]

And it's simply staying there doing nothing at all?

What's the output of

ls -lh /etc/pihole/

Do you use SELinux?

[hiyan]

And it's simply staying there doing nothing at all? Yes. FTL is not running.

pi@RaspPi:~$ ls -lh /etc/pihole/
total 254M
drwxr-xr-x 2 root   root   4.0K Jan 30 16:51 migration_backup
-rw-r--r-- 1 root   root    313 Feb  4 18:29 adlists.list
-rw-r--r-- 1 root   root    770 Jan 29 17:37 black.list
-rw-r--r-- 1 root   root    166 Feb 13 11:42 custom.list
-rw-r--r-- 1 pihole pihole    0 Mar 10 09:16 dhcp.leases
-rw-r--r-- 1 root   root    596 Mar  9 10:15 dns-servers.conf
-rw-r--r-- 1 root   root     13 Mar 10 01:08 ftlbranch
-rw-r--r-- 1 root   root      2 Mar  9 15:18 GitHubVersions
-rw-rw-r-- 1 pihole pihole 134M Mar 10 00:44 gravity.db
-rw-r--r-- 1 root   root    31M Jan 29 17:37 gravity.list
-rw-r--r-- 1 root   root   1.1K Mar  9 10:15 install.log
-rw-r--r-- 1 root   root   995K Mar  9 20:57 list.0.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    31K Mar  9 21:02 list.10.hosts-file.net.domains
-rw-r--r-- 1 root   root   9.8K Mar  9 21:02 list.11.hosts-file.net.domains
-rw-r--r-- 1 root   root    50K Mar  9 21:02 list.12.mirror.cedia.org.ec.domains
-rw-r--r-- 1 root   root   581K Mar  9 21:02 list.13.mirror1.malwaredomains.com.domains
-rw-r--r-- 1 root   root   260K Mar  9 21:02 list.14.phishing.army.domains
-rw-r--r-- 1 root   root   1.9K Mar  9 21:02 list.15.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root   956K Mar  9 21:02 list.16.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root   9.5K Mar  9 21:02 list.17.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    13K Mar  9 21:02 list.18.reddestdream.github.io.domains
-rw-r--r-- 1 root   root    43K Mar  9 21:02 list.19.s3.amazonaws.com.domains
-rw-r--r-- 1 root   root   403K Mar  9 20:57 list.1.sysctl.org.domains
-rw-r--r-- 1 root   root    44K Mar  9 21:02 list.20.s3.amazonaws.com.domains
-rw-r--r-- 1 root   root   443K Mar  9 21:02 list.21.v.firebog.net.domains
-rw-r--r-- 1 root   root    33K Mar  9 21:03 list.22.v.firebog.net.domains
-rw-r--r-- 1 root   root    52K Mar  9 21:03 list.23.v.firebog.net.domains
-rw-r--r-- 1 root   root    58K Mar  9 21:03 list.24.v.firebog.net.domains
-rw-r--r-- 1 root   root   590K Mar  9 21:03 list.25.v.firebog.net.domains
-rw-r--r-- 1 root   root   331K Mar  9 21:03 list.26.v.firebog.net.domains
-rw-r--r-- 1 root   root    13K Mar  9 21:03 list.27.v.firebog.net.domains
-rw-r--r-- 1 root   root   2.6M Mar  9 21:03 list.28.www.github.developerdan.com.domains
-rw-r--r-- 1 root   root    62K Mar  9 21:03 list.29.zerodot1.gitlab.io.domains
-rw-r--r-- 1 root   root    521 Mar  9 20:57 list.2.s3.amazonaws.com.domains
-rw-r--r-- 1 root   root    257 Mar  9 21:03 list.30.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    716 Mar  9 21:03 list.31.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root   2.0M Mar  9 21:06 list.32.hosts-file.net.domains
-rw-r--r-- 1 root   root   252K Mar  9 21:06 list.33.adaway.org.domains
-rw-r--r-- 1 root   root   3.5K Mar  9 21:06 list.34.osint.digitalside.it.domains
-rw-r--r-- 1 root   root    52K Mar  9 21:06 list.35.pgl.yoyo.org.domains
-rw-r--r-- 1 root   root    230 Mar  9 21:06 list.36.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    31K Mar  9 21:06 list.37.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    48K Mar  9 21:06 list.38.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root   1.5K Mar  9 21:06 list.39.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    43K Mar  9 20:57 list.3.bitbucket.org.domains
-rw-r--r-- 1 root   root   366K Mar  9 21:06 list.40.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root    22K Mar  9 21:06 list.41.www.malwaredomainlist.com.domains
-rw-r--r-- 1 root   root    31M Mar  9 21:07 list.42.raw.githubusercontent.com.domains
-rw-r--r-- 1 root   root   1.7M Mar  9 20:57 list.4.gitlab.com.domains
-rw-r--r-- 1 root   root    11K Mar  9 20:57 list.5.gitlab.com.domains
-rw-r--r-- 1 root   root      0 Mar  9 20:58 list.6.gitlab.com.domains
-rw-r--r-- 1 root   root   722K Mar  9 20:58 list.7.hostfiles.frogeye.fr.domains
-rw-r--r-- 1 root   root   1.3M Mar  9 20:59 list.8.hosts-file.net.domains
-rw-r--r-- 1 root   root   1.5M Mar  9 21:02 list.9.hosts-file.net.domains
-rw-r--r-- 1 root   root     38 Mar 10 09:30 localbranches
-rw-r--r-- 1 root   root     41 Mar  9 21:10 local.list
-rw-r--r-- 1 root   root     58 Mar 10 09:30 localversions
-rw-r--r-- 1 root   root    233 Mar  9 10:34 logrotate
-rw-r--r-- 1 pihole pihole 2.3M Mar 10 01:08 macvendor.db
-rw-rw-r-- 1 pihole root     75 Mar  9 10:15 pihole-FTL.conf
-rw-r--r-- 1 pihole pihole  41M Mar 10 09:39 pihole-FTL.db
-rw-r--r-- 1 root   root    783 Mar  9 10:15 setupVars.conf
-rw-r--r-- 1 root   root    783 Mar  9 10:15 setupVars.conf.update.bak

Do you use SELinux? Am testing this on Pi Zero running Raspbian Lite.

[DL6ER]

Okay, something is clearly strange here. You shouldn't have all these files int he folder. Did you try to downgrade back to v4.x at some point? Note that this is not supported as v5.0 is not backwards-compatible and things might be completely broken now.

What is the output of pihole -g ?

[hiyan]

No, I have not downgrade to 4.0.

I have had no problem with pihole -g.

What are the file "that shouldn't be there", I assume those will be safe to delete.

I'll be able to do a clean install later tonight if you aren't able to let me know which files to delete.

[DL6ER]

I have had no problem with pihole -g.

I'm still interested in the output, there might be something off you don't notice as it may not be clearly shown as an error. One never knows.

What are the file "that shouldn't be there", I assume those will be safe to delete.

They are adlist.list, black.list, white.list and gravity.list. Deleting them won't do anything, their presence suggests that something went wrong half-way as they are moved into the newly created directory /etc/pihole/migration_backup during the upgrade to v5.0. Are there files in this directory?

If so, are they identical to the ones in /etc/pihole ? If so, please run pihole -g -r to have the database entirely regenerated. The output of this would be interesting as well.

[hiyan]

Here you go.

pi@RaspPi:/etc/pihole$ ls -lh migration_backup/
total 16K
-rw-r--r-- 1 root   root     2.4K Jan 29 17:30 adlists.list
-rw-r--r-- 1 root   root      770 Jan 29 17:11 blacklist.txt
-rw-rw-r-- 1 pihole www-data  470 Jan 29 17:06 regex.list
-rw-r--r-- 1 root   root      141 Jan 29 17:10 whitelist.txt

pi@RaspPi:/etc/pihole$ pihole -g -r
  [✓] Restoring from migration backup
  [i] Creating new gravity database
  [i] Migrating content of /etc/pihole/adlists.list into new database
  [i] Migrating content of /etc/pihole/blacklist.txt into new database
  [i] Migrating content of /etc/pihole/whitelist.txt into new database
  [i] Migrating content of /etc/pihole/regex.list into new database
  [i] Neutrino emissions detected...
  [✓] Pulling blocklist source list into range

  [✓] Preparing new gravity database
  [i] Target: https://raw.githubusercontent.com/StevenBlack/hosts/master/hosts
  [✓] Status: Retrieval successful
  [i] Received 51313 domains

  [i] Target: http://sysctl.org/cameleon/hosts
  [✓] Status: No changes detected
  [i] Received 20567 domains

  [i] Target: https://s3.amazonaws.com/lists.disconnect.me/simple_tracking.txt
  [✓] Status: No changes detected
  [i] Received 34 domains

  [i] Target: https://bitbucket.org/ethanr/dns-blacklists/raw/8575c9f96e5b4a1308f2f12394abd86d0927a4a0/bad_lists/Mandiant_APT1_Report_Appendix_D.txt
  [✓] Status: No changes detected
  [i] Received 2046 domains

  [i] Target: https://gitlab.com/curben/urlhaus-filter/raw/master/urlhaus-filter-hosts.txt
  [✓] Status: Retrieval successful
  [i] Received 104263 domains, 18 domains invalid!
      Sample of invalid domains:
      - blog.n??tztjanix.net
      - c7paintedparts.com?5ybuk=ykszqajinq3luw
      - carlicenseplateframes.com?6vo5=aprqtoksauztgyytprgkycqzcqi
      - carlicenseplateframes.com?75hlk=foubcujinq3luw
      - chefbecktruefoodconfessions.com?8fpim=guboirsafwgnlzmpiacvmbyr3luw

  [i] Target: https://gitlab.com/quidsup/notrack-blocklists/raw/master/notrack-blocklist.txt
  [✓] Status: Retrieval successful
  [i] Received 741 domains

  [i] Target: https://gitlab.com/quidsup/notrack-blocklists/raw/master/notrack-malware.txt
  [✓] Status: Retrieval successful
  [i] Received 0 domains

  [i] Target: https://hostfiles.frogeye.fr/firstparty-trackers-hosts.txt
  [✓] Status: No changes detected
  [i] Received 36731 domains

  [i] Target: https://hosts-file.net/ad_servers.txt
  [✓] Status: No changes detected
  [i] Received 45736 domains

  [i] Target: https://hosts-file.net/emd.txt
  [✓] Status: No changes detected
  [i] Received 82343 domains

  [i] Target: https://hosts-file.net/exp.txt
  [✓] Status: No changes detected
  [i] Received 1156 domains

  [i] Target: https://hosts-file.net/grm.txt
  [✓] Status: No changes detected
  [i] Received 524 domains

  [i] Target: https://mirror.cedia.org.ec/malwaredomains/immortal_domains.txt
  [✓] Status: No changes detected
  [i] Received 3196 domains

  [i] Target: https://mirror1.malwaredomains.com/files/justdomains
  [✓] Status: No changes detected
  [i] Received 26857 domains

  [i] Target: https://phishing.army/download/phishing_army_blocklist_extended.txt
  [✓] Status: No changes detected
  [i] Received 13009 domains

  [i] Target: https://raw.githubusercontent.com/DandelionSprout/adfilt/master/Alternate%20versions%20Anti-Malware%20List/AntiMalwareHosts.txt
  [✓] Status: Retrieval successful
  [i] Received 117 domains

  [i] Target: https://raw.githubusercontent.com/Kees1958/WS3_annual_most_used_survey_blocklist/master/w3tech_hostfile.txt
  [✗] Status: Not found
  [✗] List download failed: using previously cached list
  [i] Received 38353 domains

  [i] Target: https://raw.githubusercontent.com/anudeepND/blacklist/master/adservers.txt
  [✓] Status: Retrieval successful
  [i] Received 38353 domains

  [i] Target: https://raw.githubusercontent.com/crazy-max/WindowsSpyBlocker/master/data/hosts/spy.txt
  [✓] Status: Retrieval successful
  [i] Received 365 domains

  [i] Target: https://reddestdream.github.io/Projects/MinimalHosts/etc/MinimalHostsBlocker/minimalhosts
  [✓] Status: Retrieval successful
  [i] Received 710 domains

  [i] Target: https://s3.amazonaws.com/lists.disconnect.me/simple_ad.txt
  [✓] Status: No changes detected
  [i] Received 2735 domains

  [i] Target: https://s3.amazonaws.com/lists.disconnect.me/simple_malvertising.txt
  [✓] Status: Retrieval successful
  [i] Received 2735 domains

  [i] Target: https://v.firebog.net/hosts/AdguardDNS.txt
  [✓] Status: No changes detected
  [i] Received 1946 domains

  [i] Target: https://v.firebog.net/hosts/Easylist.txt
  [✓] Status: No changes detected
  [i] Received 2630 domains

  [i] Target: https://v.firebog.net/hosts/Easyprivacy.txt
  [✓] Status: No changes detected
  [i] Received 3671 domains

  [i] Target: https://v.firebog.net/hosts/Prigent-Ads.txt
  [✓] Status: No changes detected
  [i] Received 29835 domains

  [i] Target: https://v.firebog.net/hosts/Prigent-Malware.txt
  [✓] Status: No changes detected
  [i] Received 19588 domains

  [i] Target: https://v.firebog.net/hosts/Prigent-Phishing.txt
  [✓] Status: No changes detected
  [i] Received 719 domains

  [i] Target: https://v.firebog.net/hosts/Shalla-mal.txt
  [✓] Status: Retrieval successful
  [i] Received 19588 domains

  [i] Target: https://v.firebog.net/hosts/static/w3kbl.txt
  [✓] Status: Retrieval successful
  [i] Received 719 domains

  [i] Target: https://www.github.developerdan.com/hosts/lists/ads-and-tracking-extended.txt
  [✓] Status: Retrieval successful
  [i] Received 108864 domains

  [i] Target: https://www.squidblacklist.org/downloads/dg-ads.acl
  [✗] Status: Connection Timed Out (Cloudflare)
  [✗] List download failed: no cached list available

  [i] Target: https://www.squidblacklist.org/downloads/dg-malicious.acl
  [✗] Status: Connection Timed Out (Cloudflare)
  [✗] List download failed: no cached list available

  [i] Target: https://zerodot1.gitlab.io/CoinBlockerLists/hosts_browser
  [✓] Status: Retrieval successful
  [i] Received 3294 domains

  [i] Target: https://raw.githubusercontent.com/jerryn70/GoodbyeAds/master/Hosts/GoodbyeAds.txt
  [✓] Status: Retrieval successful
  [i] Received 76535 domains

  [i] Target: https://github.com/ookangzheng/dbl-oisd-nl/raw/master/dbl.txt
  [✓] Status: Retrieval successful
  [i] Received 1412912 domains

  [i] Target: https://raw.githubusercontent.com/bambenek/block-doh/master/doh-hosts.txt
  [✓] Status: Retrieval successful
  [i] Received 15 domains

  [i] Target: https://raw.githubusercontent.com/aelisya/block-doh/patch-2/doh-hosts.txt
  [✓] Status: Retrieval successful
  [i] Received 47 domains

  [✓] Storing downloaded domains in new gravity database
  [✓] Building tree
  [✓] Swapping databases
  [i] Number of gravity domains: 2152229 (1655980 unique domains)
  [i] Number of exact blacklisted domains: 31
  [i] Number of regex blacklist filters: 19
  [i] Number of exact whitelisted domains: 7
  [i] Number of regex whitelist filters: 0
  [✓] Flushing DNS cache
  [✓] Cleaning up stray matter

  [✓] DNS service is running
  [✓] Pi-hole blocking is Enabled
pi@RaspPi:/etc/pihole$

Version info:

pi@RaspPi:/etc/pihole$ pihole version
  Pi-hole version is v4.3.5-445-g22ce5c0 (Latest: v4.4)
  AdminLTE version is v4.3.2-434-gaa51f01 (Latest: v4.3.3)
  FTL version is vDev-71e8498 (Latest: v4.3.1)

If so, are they identical to the ones in /etc/pihole ?

There are not. I would expect so since I've been running 5.0 for over a month now with minor tweaking here and there to the lists.

Here are the files after running pihole -g -r

pi@RaspPi:/etc/pihole$ ll *list
-rw-r--r-- 1 root root 770 Jan 29 17:37 black.list
-rw-r--r-- 1 root root 166 Feb 13 11:42 custom.list
-rw-r--r-- 1 root root 31M Jan 29 17:37 gravity.list
-rw-r--r-- 1 root root  41 Mar 10 15:16 local.list
pi@RaspPi:/etc/pihole$ ll migration_backup/
total 24K
drwxr-xr-x 2 root   root   4.0K Mar 10 15:10 ./
drwxrwxr-x 3 pihole pihole 4.0K Mar 10 15:23 ../
-rw-r--r-- 1 root   root   2.4K Mar 10 15:10 adlists.list
-rw-r--r-- 1 root   root    770 Mar 10 15:10 blacklist.txt
-rw-r--r-- 1 root   root    470 Mar 10 15:10 regex.list
-rw-r--r-- 1 root   root    141 Mar 10 15:10 whitelist.txt

[hiyan]

I did a clean install (uninstall, install v4, v5) and tried to checkout the debug version and it failed.

I've put the logs in gists.

pihole-install.log pihole-FTL.log

Also, logs replicating my original problem from release/v5.0 on clean install. pihole.log

[DL6ER]

You're seeing the crashed on release/v5.0 according to your logs. How does the crash look like on

pihole checkout ftl tweak/sqlite_debugging

?

[hiyan]

I cant get tweak/sqlite_debugging FTL to run. No obvious error shown in any logs -- Eg pihole-ftl, pihole, daemon, syslog etc.

Refer to pihole-install.log starting line 241.

[DL6ER]

Looking at your linked output, I only see one issue here: https://gist.github.com/hiyan/2d021d8f3882f791c0b48b5e6f9c4f65#file-pihole-ftl-log-L1937

It this what you referred to when saying "no obvious error"? I haven't seen this error message before (it comes from deep down in the system), so I'm also not sure if this may be a show-stopper or not. Could you try again to see if the same error pops up another time?

This may be helpful to trace the error if it is the same, again: https://easyengine.io/tutorials/linux/increase-open-files-limit/

[hiyan]

Not sure but don't think the file limit is related to my problem with running tweak/sqlite_debugging.

Maybe there were just too much info in my previous log dump.

My steps below:

1. Tail -f pihole-ftl.log (in separate putty).
2. Checkout sqlite_debugging
3. Netstat grep 53

Results: at this point, FTL is not running.

Shell log:

pi@RaspPi:~$ pihole checkout ftl tweak/sqlite_debugging
  Please note that changing branches severely alters your Pi-hole subsystems
  Features that work on the master branch, may not on a development branch
  This feature is NOT supported unless a Pi-hole developer explicitly asks!
  Have you read and understood this? [y/N] y

  [✓] Branch tweak/sqlite_debugging exists
  [✓] Downloading and Installing FTL
  [✓] Restarting pihole-FTL service...
  [✓] Enabling pihole-FTL service to start on reboot...
pi@RaspPi:~$ netstat -ant | grep 53
tcp        0      0 127.0.0.1:5353          0.0.0.0:*               LISTEN
tcp        0      0 0.0.0.0:853             0.0.0.0:*               LISTEN

pihole-FTL.log:

pi@RaspPi:/var/log$ tail -f pihole-FTL.log
[2020-03-16 11:15:19.041 508] Blocking status is enabled
[2020-03-16 11:15:19.322 508] INFO: No regex whitelist entries found
[2020-03-16 11:15:19.433 508] Compiled 0 whitelist and 6 blacklist regex filters in 144.1 msec
[2020-03-16 11:34:52.311 508] Resizing "/FTL-dns-cache" from 4096 to 8192
[2020-03-16 11:48:58.886 508] Resizing "/FTL-strings" from 36864 to 40960
[2020-03-16 12:47:11.156 508] Resizing "/FTL-dns-cache" from 8192 to 12288
[2020-03-16 13:57:23.240 508] Resizing "/FTL-strings" from 40960 to 45056
[2020-03-16 14:03:26.912 508] Resizing "/FTL-dns-cache" from 12288 to 16384
[2020-03-16 14:39:41.495 508] Resizing "/FTL-strings" from 45056 to 49152
[2020-03-16 16:08:50.523 508] Resizing "/FTL-dns-cache" from 16384 to 20480
[2020-03-16 16:29:43.417 508] Shutting down...
[2020-03-16 16:29:43.496 508] Finished final database update
[2020-03-16 16:29:43.506 508] ########## FTL terminated after 18867228.0 ms! ##########
[2020-03-16 16:29:44.927 20146] Using log file /var/log/pihole-FTL.log
[2020-03-16 16:29:44.930 20146] ########## FTL started! ##########
[2020-03-16 16:29:44.932 20146] FTL branch: tweak/sqlite_debugging
[2020-03-16 16:29:44.933 20146] FTL version: vDev-99bd5e7
[2020-03-16 16:29:44.934 20146] FTL commit: 99bd5e7
[2020-03-16 16:29:44.936 20146] FTL date: 2020-03-08 16:30:38 +0100
[2020-03-16 16:29:44.937 20146] FTL user: pihole
[2020-03-16 16:29:44.939 20146] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-03-16 16:29:44.941 20146] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-03-16 16:29:44.942 20146]    SOCKET_LISTENING: only local
[2020-03-16 16:29:44.943 20146]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-03-16 16:29:44.944 20146]    MAXDBDAYS: max age for stored queries is 365 days
[2020-03-16 16:29:44.945 20146]    RESOLVE_IPV6: Resolve IPv6 addresses
[2020-03-16 16:29:44.946 20146]    RESOLVE_IPV4: Resolve IPv4 addresses
[2020-03-16 16:29:44.947 20146]    DBINTERVAL: saving to DB file every minute
[2020-03-16 16:29:44.948 20146]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-03-16 16:29:44.949 20146]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-03-16 16:29:44.950 20146]    PRIVACYLEVEL: Set to 0
[2020-03-16 16:29:44.951 20146]    IGNORE_LOCALHOST: Show queries from localhost
[2020-03-16 16:29:44.952 20146]    BLOCKINGMODE: Null IPs for blocked domains
[2020-03-16 16:29:44.953 20146]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-03-16 16:29:44.954 20146]    DBIMPORT: Importing history from database
[2020-03-16 16:29:44.955 20146]    PIDFILE: Using /var/run/pihole-FTL.pid
[2020-03-16 16:29:44.956 20146]    PORTFILE: Using /var/run/pihole-FTL.port
[2020-03-16 16:29:44.957 20146]    SOCKETFILE: Using /var/run/pihole/FTL.sock
[2020-03-16 16:29:44.958 20146]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-03-16 16:29:44.959 20146]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-03-16 16:29:44.961 20146]    GRAVITYDB: Using /etc/pihole/gravity.db
[2020-03-16 16:29:44.962 20146]    PARSE_ARP_CACHE: Active
[2020-03-16 16:29:44.963 20146]    REGEX_IGNORECASE: Disabled. Regex is case sensitive
[2020-03-16 16:29:44.965 20146]    CNAME_DEEP_INSPECT: Active
[2020-03-16 16:29:44.966 20146] Finished config file parsing
[2020-03-16 16:29:44.974 20146] Database version is 5
[2020-03-16 16:29:44.975 20146] Database successfully initialized
[2020-03-16 16:29:44.984 20146] New upstream server: 127.0.0.1 (0/1024)
[2020-03-16 16:29:44.988 20146] New upstream server: 192.168.1.1 (1/1024)
[2020-03-16 16:29:45.006 20146] Resizing "/FTL-strings" from 4096 to 8192
[2020-03-16 16:29:45.072 20146] Resizing "/FTL-strings" from 8192 to 12288
[2020-03-16 16:29:45.140 20146] Resizing "/FTL-queries" from 229376 to 458752
[2020-03-16 16:29:45.167 20146] Resizing "/FTL-strings" from 12288 to 16384
[2020-03-16 16:29:45.281 20146] Resizing "/FTL-strings" from 16384 to 20480
[2020-03-16 16:29:45.361 20146] Resizing "/FTL-strings" from 20480 to 24576
[2020-03-16 16:29:45.521 20146] Resizing "/FTL-queries" from 458752 to 688128
[2020-03-16 16:29:45.587 20146] Resizing "/FTL-strings" from 24576 to 28672
[2020-03-16 16:29:45.864 20146] Resizing "/FTL-strings" from 28672 to 32768
[2020-03-16 16:29:45.972 20146] Resizing "/FTL-queries" from 688128 to 917504
[2020-03-16 16:29:46.048 20146] Imported 12942 queries from the long-term database
[2020-03-16 16:29:46.051 20146]  -> Total DNS queries: 12942
[2020-03-16 16:29:46.053 20146]  -> Cached DNS queries: 66
[2020-03-16 16:29:46.055 20146]  -> Forwarded DNS queries: 7322
[2020-03-16 16:29:46.056 20146]  -> Blocked DNS queries: 5553
[2020-03-16 16:29:46.058 20146]  -> Unknown DNS queries: 1
[2020-03-16 16:29:46.059 20146]  -> Unique domains: 1396
[2020-03-16 16:29:46.061 20146]  -> Unique clients: 16
[2020-03-16 16:29:46.062 20146]  -> Known forward destinations: 2
[2020-03-16 16:29:46.064 20146] Successfully accessed setupVars.conf
[2020-03-16 16:29:46.852 20149] PID of FTL process: 20149
[2020-03-16 16:29:46.857 20149] Listening on port 4711 for incoming IPv4 telnet connections
[2020-03-16 16:29:46.865 20149] Listening on port 4711 for incoming IPv6 telnet connections
[2020-03-16 16:29:46.874 20149] Listening on Unix socket
[2020-03-16 16:29:46.889 20149] Reloading DNS cache
[2020-03-16 16:29:46.905 20149] Blocking status is enabled

[DL6ER]

Sorry, it seems you need to start a debugging session so we can find out what happens:

https://docs.pi-hole.net/ftldns/debugging/

When FTL is non-responsive (but still running), you can directly type backtrace after connecting with the debugger. You may be stuck in some strange place and once we know where, we can look at why this is the case and how to resolve this...

[hiyan]

Just tried the debugging steps and am not able to do this with the debugging branch... reason being that the debugging FTL isn't starting for me. What can I do next to help?

[DL6ER]

You could try

sudo gdb $(which pihole-FTL) --ex "r d"

and check if it runs into a crash. This will mess up permissions somewhat, however, this will later automatically be corrected by the nest service pihole-FTL [re]start command.

[hiyan]

Here is the output..

pi@RaspPi:~$ pihole -v
  Pi-hole version is v4.3.5-452-g22ce5c0 (Latest: v4.4)
  AdminLTE version is v4.3.2-437-gbc9c656 (Latest: v4.3.3)
  FTL version is vDev-99bd5e7 (Latest: v4.3.1)
pi@RaspPi:~$ sudo gdb $(which pihole-FTL) --ex "r d"
GNU gdb (Raspbian 8.2.1-2) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "arm-linux-gnueabihf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/pihole-FTL...done.
Starting program: /usr/bin/pihole-FTL d
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".
[2020-03-17 18:13:33.370 20937] Using log file /var/log/pihole-FTL.log
[2020-03-17 18:13:33.373 20937] ########## FTL started! ##########
[2020-03-17 18:13:33.375 20937] FTL branch: tweak/sqlite_debugging
[2020-03-17 18:13:33.377 20937] FTL version: vDev-99bd5e7
[2020-03-17 18:13:33.379 20937] FTL commit: 99bd5e7
[2020-03-17 18:13:33.380 20937] FTL date: 2020-03-08 16:30:38 +0100
[2020-03-17 18:13:33.381 20937] FTL user: root
[2020-03-17 18:13:33.383 20937] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-03-17 18:13:33.389 20937] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-03-17 18:13:33.390 20937]    SOCKET_LISTENING: only local
[2020-03-17 18:13:33.391 20937]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-03-17 18:13:33.392 20937]    MAXDBDAYS: max age for stored queries is 365 days
[2020-03-17 18:13:33.394 20937]    RESOLVE_IPV6: Resolve IPv6 addresses
[2020-03-17 18:13:33.395 20937]    RESOLVE_IPV4: Resolve IPv4 addresses
[2020-03-17 18:13:33.396 20937]    DBINTERVAL: saving to DB file every minute
[2020-03-17 18:13:33.397 20937]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-03-17 18:13:33.398 20937]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-03-17 18:13:33.399 20937]    PRIVACYLEVEL: Set to 0
[2020-03-17 18:13:33.400 20937]    IGNORE_LOCALHOST: Show queries from localhost
[2020-03-17 18:13:33.401 20937]    BLOCKINGMODE: Null IPs for blocked domains
[2020-03-17 18:13:33.402 20937]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-03-17 18:13:33.403 20937]    DBIMPORT: Importing history from database
[2020-03-17 18:13:33.405 20937]    PIDFILE: Using /var/run/pihole-FTL.pid
[2020-03-17 18:13:33.406 20937]    PORTFILE: Using /var/run/pihole-FTL.port
[2020-03-17 18:13:33.407 20937]    SOCKETFILE: Using /var/run/pihole/FTL.sock
[2020-03-17 18:13:33.408 20937]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-03-17 18:13:33.409 20937]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-03-17 18:13:33.410 20937]    GRAVITYDB: Using /etc/pihole/gravity.db
[2020-03-17 18:13:33.411 20937]    PARSE_ARP_CACHE: Active
[2020-03-17 18:13:33.412 20937]    REGEX_IGNORECASE: Disabled. Regex is case sensitive
[2020-03-17 18:13:33.413 20937]    CNAME_DEEP_INSPECT: Active
[2020-03-17 18:13:33.414 20937] Finished config file parsing
[2020-03-17 18:13:33.417 20937] WARNING: Starting pihole-FTL as user root is not recommended
[2020-03-17 18:13:33.436 20937] Database version is 5
[2020-03-17 18:13:33.447 20937] Database successfully initialized
[2020-03-17 18:13:33.455 20937] New upstream server: 127.0.0.1 (0/1024)
[2020-03-17 18:13:33.459 20937] New upstream server: 192.168.1.1 (1/1024)
[2020-03-17 18:13:33.476 20937] Resizing "/FTL-strings" from 4096 to 8192
[2020-03-17 18:13:33.500 20937] Resizing "/FTL-strings" from 8192 to 12288
[2020-03-17 18:13:33.546 20937] Resizing "/FTL-strings" from 12288 to 16384
[2020-03-17 18:13:33.637 20937] Resizing "/FTL-strings" from 16384 to 20480
[2020-03-17 18:13:33.700 20937] Resizing "/FTL-queries" from 229376 to 458752
[2020-03-17 18:13:33.742 20937] Resizing "/FTL-strings" from 20480 to 24576
[2020-03-17 18:13:33.902 20937] Resizing "/FTL-strings" from 24576 to 28672
[2020-03-17 18:13:34.009 20937] Resizing "/FTL-queries" from 458752 to 688128
[2020-03-17 18:13:34.028 20937] Resizing "/FTL-strings" from 28672 to 32768
[2020-03-17 18:13:34.200 20937] Resizing "/FTL-strings" from 32768 to 36864
[2020-03-17 18:13:34.350 20937] Resizing "/FTL-queries" from 688128 to 917504
[2020-03-17 18:13:34.440 20937] Imported 13613 queries from the long-term database
[2020-03-17 18:13:34.443 20937]  -> Total DNS queries: 13613
[2020-03-17 18:13:34.445 20937]  -> Cached DNS queries: 69
[2020-03-17 18:13:34.447 20937]  -> Forwarded DNS queries: 7821
[2020-03-17 18:13:34.449 20937]  -> Blocked DNS queries: 5603
[2020-03-17 18:13:34.452 20937]  -> Unknown DNS queries: 120
[2020-03-17 18:13:34.454 20937]  -> Unique domains: 1719
[2020-03-17 18:13:34.456 20937]  -> Unique clients: 18
[2020-03-17 18:13:34.457 20937]  -> Known forward destinations: 2
[2020-03-17 18:13:34.458 20937] Successfully accessed setupVars.conf
[2020-03-17 18:13:34.477 20937] PID of FTL process: 20937
[2020-03-17 18:13:34.480 20937] Listening on port 4711 for incoming IPv4 telnet connections
[2020-03-17 18:13:34.483 20937] Listening on port 4711 for incoming IPv6 telnet connections
[2020-03-17 18:13:34.485 20937] Listening on Unix socket
[New Thread 0xb6c66460 (LWP 20940)]
[New Thread 0xb6465460 (LWP 20941)]
[New Thread 0xb5c64460 (LWP 20942)]
[New Thread 0xb5463460 (LWP 20943)]
[New Thread 0xb4c62460 (LWP 20944)]
[New Thread 0xb4461460 (LWP 20945)]
[2020-03-17 18:13:34.506 20937] Changing /FTL-lock (16) to 0:0
[2020-03-17 18:13:34.506 20937] Changing /FTL-strings (16) to 0:0
[2020-03-17 18:13:34.507 20937] Changing /FTL-counters (16) to 0:0
[2020-03-17 18:13:34.508 20937] Changing /FTL-domains (16) to 0:0
[2020-03-17 18:13:34.509 20937] Changing /FTL-clients (16) to 0:0
[2020-03-17 18:13:34.515 20937] Changing /FTL-queries (16) to 0:0
[2020-03-17 18:13:34.517 20937] Changing /FTL-upstreams (16) to 0:0
[2020-03-17 18:13:34.519 20937] Changing /FTL-overTime (16) to 0:0
[2020-03-17 18:13:34.521 20937] Changing /FTL-settings (16) to 0:0
[2020-03-17 18:13:34.522 20937] Changing /FTL-dns-cache (16) to 0:0
[2020-03-17 18:13:34.524 20937] Changing /FTL-per-client-regex (16) to 0:0
dnsmasq: started, version pi-hole-2.80 cache disabled
dnsmasq: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify dumpfile
dnsmasq: using local addresses only for domain use-application-dns.net
dnsmasq: using nameserver 192.168.1.1#53 for domain 1.168.192.in-addr.arpa
dnsmasq: using nameserver 192.168.1.1#53 for domain lan
dnsmasq: using nameserver 127.0.0.1#5353
[2020-03-17 18:13:34.540 20937] Reloading DNS cache
[2020-03-17 18:13:34.542 20937] Blocking status is enabled
[2020-03-17 18:13:46.301 20937] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-17 18:13:46.306 20937] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/gravity.db) -  (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-17 18:13:46.307 20937] gravityDB_open() - SQL error (14): unable to open database file
!!! WARNING: Writing to FTL's log file failed!
[2020-03-17 18:13:46.307 20937] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-17 18:13:46.308 20937] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/gravity.db) -  (14)
!!! WARNING: Writing to FTL's log file failed!

File permission:

root@RaspPi:/etc/pihole# ll gravity.db
-rw-rw-r-- 1 pihole pihole 118M Mar 16 10:47 gravity.db
root@RaspPi:/etc/pihole# ll /var/log/pihole-FTL.log
-rw-r--r-- 1 root root 21K Mar 17 18:13 /var/log/pihole-FTL.log

[DL6ER]

@dschaper Any ideas why not even root can access these files?

[dschaper]

Check mount and see if the filesystem is read-only?

[hiyan]

Check mount and see if the filesystem is read-only?

I dont think so since I have no problem running release/v5.0. The error happens in tweak/sqlite_debugging

Anyhow, here is the output of mount:

pi@RaspPi:~$ mount
/dev/mmcblk0p2 on / type ext4 (rw,noatime)
devtmpfs on /dev type devtmpfs (rw,relatime,size=241436k,nr_inodes=60359,mode=755)
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
proc on /proc type proc (rw,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755)
tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k)
tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755)
cgroup2 on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate)
cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd)
bpf on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls)
cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct)
cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=27,pgrp=1,timeout=0,minproto=5,maxproto=5,direct)
debugfs on /sys/kernel/debug type debugfs (rw,relatime)
mqueue on /dev/mqueue type mqueue (rw,relatime)
sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime)
configfs on /sys/kernel/config type configfs (rw,relatime)
/dev/mmcblk0p1 on /boot type vfat (rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro)
overlay on /var/lib/docker/overlay2/d559540db9f096000680383cf9978e2dc40c841a27e13d1341add82a5c1c9d19/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/6GJED5OCJZ3CDXO2Y2WTDSPGGJ:/var/lib/docker/overlay2/l/6D2UTUISDSSIDIQFWQWXPSWBVR:/var/lib/docker/overlay2/l/IUWGW3ETMYBM74IOSEMNEFIOXD:/var/lib/docker/overlay2/l/KIXHWADJ4BIGZ3QBV7YKL4DAH3:/var/lib/docker/overlay2/l/5ZH6CGJSNE3ASJZJNV54IPG543:/var/lib/docker/overlay2/l/XIQ4DRVOMJOGBT3ACPVGL44Y2Q:/var/lib/docker/overlay2/l/FXRWXXPZHK6MQDR6YSRKT4Q3RG:/var/lib/docker/overlay2/l/O3ZNZK223TXPB52DEVCBLQCZ2D:/var/lib/docker/overlay2/l/H4UBL2TE5J2KNOH2HALXTECSK6:/var/lib/docker/overlay2/l/54DFAUFC3NQRBOO36AO7BC5FXT:/var/lib/docker/overlay2/l/XA5TLT5PVILGHLF2GQOK4N2FYO:/var/lib/docker/overlay2/l/AFQS7CLOWYIQDCIHFRUANJ5DZJ:/var/lib/docker/overlay2/l/RGKA3PIFLEUAA2YNQGQXBLQAMQ:/var/lib/docker/overlay2/l/YJMPE4W4D4M2FR4AUMUJOGLQX4:/var/lib/docker/overlay2/l/FBKKMRB55WPGSFXSFE2Q2NSYMZ:/var/lib/docker/overlay2/l/ETYMXVDBAS3WJEO7AV5DEG2DIO:/var/lib/docker/overlay2/l/CHNZPPK6SB5EYA2ZXRQ4ZNXHT3:/var/lib/docker/overlay2/l/VDGJRGMRVZIUKI5YTIE2X5RR4J:/var/lib/docker/overlay2/l/TCMUTCTOOPSKBF7PBOZRBLMFQI:/var/lib/docker/overlay2/l/3EJOGKP3AH324WA4E7LOUQA3LR:/var/lib/docker/overlay2/l/YYSCNAQNBXXVXXRLCZKFC6YYPV:/var/lib/docker/overlay2/l/DTBUOKHPYBMIL6BSEZTWKJT6K3:/var/lib/docker/overlay2/l/AL63DD3VJ27T5SWNBCYUG52AFK,upperdir=/var/lib/docker/overlay2/d559540db9f096000680383cf9978e2dc40c841a27e13d1341add82a5c1c9d19/diff,workdir=/var/lib/docker/overlay2/d559540db9f096000680383cf9978e2dc40c841a27e13d1341add82a5c1c9d19/work)
nsfs on /run/docker/netns/0e5ea0ee69b0 type nsfs (rw)
tmpfs on /run/user/999 type tmpfs (rw,nosuid,nodev,relatime,size=49152k,mode=700,uid=999,gid=995)
tmpfs on /run/user/1000 type tmpfs (rw,nosuid,nodev,relatime,size=49152k,mode=700,uid=1000,gid=1000)

[DL6ER]

tweak/sqlite_debugging received some updates related to your description that should hopefully (!) resolve these issues. Please re-checkout/update.

[hiyan]

FTL doesn't outright crash now but not resolving.

pihole.log shows the error below when running tweak/sqlite_debugging

16:59:37: query[A] clients3.google.com from 192.168.1.176
16:59:37: config error is REFUSED
16:59:39: query[A] play.googleapis.com from 192.168.1.176
16:59:39: config error is REFUSED

running with gdb. gravityDB_open error happens (loop) when receive first dns request (i ran dig from another shell).

pi@RaspPi:/etc/pihole$ sudo gdb $(which pihole-FTL) --ex "r d"
GNU gdb (Raspbian 8.2.1-2) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "arm-linux-gnueabihf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/pihole-FTL...done.
Starting program: /usr/bin/pihole-FTL d
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".
[2020-03-23 17:07:02.163 23165] Using log file /var/log/pihole-FTL.log
[2020-03-23 17:07:02.167 23165] ########## FTL started! ##########
[2020-03-23 17:07:02.170 23165] FTL branch: tweak/sqlite_debugging
[2020-03-23 17:07:02.172 23165] FTL version: vDev-2fbdf7b
[2020-03-23 17:07:02.174 23165] FTL commit: 2fbdf7b
[2020-03-23 17:07:02.176 23165] FTL date: 2020-03-23 08:33:28 +0100
[2020-03-23 17:07:02.178 23165] FTL user: root
[2020-03-23 17:07:02.180 23165] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-03-23 17:07:02.182 23165] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-03-23 17:07:02.184 23165]    SOCKET_LISTENING: only local
[2020-03-23 17:07:02.186 23165]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-03-23 17:07:02.187 23165]    MAXDBDAYS: max age for stored queries is 365 days
[2020-03-23 17:07:02.189 23165]    RESOLVE_IPV6: Resolve IPv6 addresses
[2020-03-23 17:07:02.191 23165]    RESOLVE_IPV4: Resolve IPv4 addresses
[2020-03-23 17:07:02.192 23165]    DBINTERVAL: saving to DB file every minute
[2020-03-23 17:07:02.194 23165]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-03-23 17:07:02.196 23165]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-03-23 17:07:02.197 23165]    PRIVACYLEVEL: Set to 0
[2020-03-23 17:07:02.199 23165]    IGNORE_LOCALHOST: Show queries from localhost
[2020-03-23 17:07:02.201 23165]    BLOCKINGMODE: Null IPs for blocked domains
[2020-03-23 17:07:02.202 23165]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-03-23 17:07:02.204 23165]    DBIMPORT: Importing history from database
[2020-03-23 17:07:02.206 23165]    PIDFILE: Using /var/run/pihole-FTL.pid
[2020-03-23 17:07:02.207 23165]    PORTFILE: Using /var/run/pihole-FTL.port
[2020-03-23 17:07:02.209 23165]    SOCKETFILE: Using /var/run/pihole/FTL.sock
[2020-03-23 17:07:02.211 23165]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-03-23 17:07:02.212 23165]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-03-23 17:07:02.214 23165]    GRAVITYDB: Using /etc/pihole/gravity.db
[2020-03-23 17:07:02.216 23165]    PARSE_ARP_CACHE: Active
[2020-03-23 17:07:02.218 23165]    REGEX_IGNORECASE: Disabled. Regex is case sensitive
[2020-03-23 17:07:02.220 23165]    CNAME_DEEP_INSPECT: Active
[2020-03-23 17:07:02.222 23165] Finished config file parsing
[2020-03-23 17:07:02.227 23165] WARNING: Starting pihole-FTL as user root is not recommended
[2020-03-23 17:07:02.234 23165] Database version is 5
[2020-03-23 17:07:02.236 23165] Database successfully initialized
[2020-03-23 17:07:02.241 23165] New upstream server: 127.0.0.1 (0/1024)
[2020-03-23 17:07:02.248 23165] New upstream server: 192.168.1.1 (1/1024)
[2020-03-23 17:07:02.259 23165] Resizing "/FTL-strings" from 4096 to 8192
[2020-03-23 17:07:02.283 23165] Resizing "/FTL-strings" from 8192 to 12288
[2020-03-23 17:07:02.327 23165] Resizing "/FTL-strings" from 12288 to 16384
[2020-03-23 17:07:02.419 23165] Resizing "/FTL-strings" from 16384 to 20480
[2020-03-23 17:07:02.493 23165] Resizing "/FTL-queries" from 229376 to 458752
[2020-03-23 17:07:02.591 23165] Resizing "/FTL-strings" from 20480 to 24576
[2020-03-23 17:07:02.764 23165] Resizing "/FTL-strings" from 24576 to 28672
[2020-03-23 17:07:02.803 23165] Resizing "/FTL-queries" from 458752 to 688128
[2020-03-23 17:07:02.907 23165] Resizing "/FTL-strings" from 28672 to 32768
[2020-03-23 17:07:03.140 23165] Resizing "/FTL-strings" from 32768 to 36864
[2020-03-23 17:07:03.301 23165] Resizing "/FTL-queries" from 688128 to 917504
[2020-03-23 17:07:03.430 23165] Resizing "/FTL-strings" from 36864 to 40960
[2020-03-23 17:07:03.685 23165] Resizing "/FTL-queries" from 917504 to 1146880
[2020-03-23 17:07:03.777 23165] Resizing "/FTL-strings" from 40960 to 45056
[2020-03-23 17:07:04.043 23165] Imported 19595 queries from the long-term database
[2020-03-23 17:07:04.048 23165]  -> Total DNS queries: 19595
[2020-03-23 17:07:04.051 23165]  -> Cached DNS queries: 175
[2020-03-23 17:07:04.054 23165]  -> Forwarded DNS queries: 10546
[2020-03-23 17:07:04.057 23165]  -> Blocked DNS queries: 8874
[2020-03-23 17:07:04.059 23165]  -> Unknown DNS queries: 0
[2020-03-23 17:07:04.061 23165]  -> Unique domains: 1942
[2020-03-23 17:07:04.063 23165]  -> Unique clients: 15
[2020-03-23 17:07:04.065 23165]  -> Known forward destinations: 2
[2020-03-23 17:07:04.067 23165] Successfully accessed setupVars.conf
[2020-03-23 17:07:04.073 23165] PID of FTL process: 23165
[2020-03-23 17:07:04.077 23165] Listening on port 4711 for incoming IPv4 telnet connections
[2020-03-23 17:07:04.081 23165] Listening on port 4711 for incoming IPv6 telnet connections
[2020-03-23 17:07:04.085 23165] Listening on Unix socket
[New Thread 0xb6c66460 (LWP 23168)]
[New Thread 0xb6465460 (LWP 23169)]
[New Thread 0xb5c64460 (LWP 23170)]
[New Thread 0xb5463460 (LWP 23171)]
[New Thread 0xb4c62460 (LWP 23172)]
[New Thread 0xb4461460 (LWP 23173)]
[2020-03-23 17:07:04.112 23165] Changing /FTL-lock (16) to 0:0
[2020-03-23 17:07:04.113 23165] Changing /FTL-strings (16) to 0:0
[2020-03-23 17:07:04.115 23165] Changing /FTL-counters (16) to 0:0
[2020-03-23 17:07:04.117 23165] Changing /FTL-domains (16) to 0:0
[2020-03-23 17:07:04.120 23165] Changing /FTL-clients (16) to 0:0
[2020-03-23 17:07:04.122 23165] Changing /FTL-queries (16) to 0:0
[2020-03-23 17:07:04.124 23165] Changing /FTL-upstreams (16) to 0:0
[2020-03-23 17:07:04.127 23165] Changing /FTL-overTime (16) to 0:0
[2020-03-23 17:07:04.129 23165] Changing /FTL-settings (16) to 0:0
[2020-03-23 17:07:04.131 23165] Changing /FTL-dns-cache (16) to 0:0
[2020-03-23 17:07:04.133 23165] Changing /FTL-per-client-regex (16) to 0:0
dnsmasq: started, version pi-hole-2.80 cache disabled
dnsmasq: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify dumpfile
dnsmasq: using local addresses only for domain use-application-dns.net
dnsmasq: using nameserver 192.168.1.1#53 for domain 1.168.192.in-addr.arpa
dnsmasq: using nameserver 192.168.1.1#53 for domain lan
dnsmasq: using nameserver 127.0.0.1#5353
[2020-03-23 17:07:04.152 23165] Reloading DNS cache
[2020-03-23 17:07:04.154 23165] Blocking status is enabled
[2020-03-23 17:07:14.063 23165] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.066 23165] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/gravity.db) -  (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.068 23165] gravityDB_open() - SQL error (14): unable to open database file
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.070 23165] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.070 23165] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/gravity.db) -  (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.072 23165] gravityDB_open() - SQL error (14): unable to open database file
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.073 23165] SQLite3 message: cannot open file at line 38761 of [18db032d05] (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.074 23165] SQLite3 message: os_unix.c:38761: (24) open(/etc/pihole/gravity.db) -  (14)
!!! WARNING: Writing to FTL's log file failed!
[2020-03-23 17:07:14.075 23165] gravityDB_open() - SQL error (14): unable to open database file
!!! WARNING: Writing to FTL's log file failed!

[DL6ER]

Please try again with the most recent version, sorry for the slow process but I want to make sure we get there!

The REFUSED error likely comes from no upstream server found, this might be an intermittent issue.

[hiyan]

I'm getting checksum error.

  [✓] Branch tweak/sqlite_debugging exists
  [i] Downloading and Installing FTL...pihole-FTL-arm-linux-gnueabi: FAILED
sha1sum: WARNING: 1 computed checksum did NOT match
  [✗] Downloading and Installing FTL
  Error: Download of https://ftl.pi-hole.net/tweak/sqlite_debugging/pihole-FTL-arm-linux-gnueabi failed (checksum error)

[DL6ER]

@hiyan Please try again, this most likely points to a failed download. The checksums on the server seem to be correct (download succeeds for me).

[hiyan]

Got it working. I'll report back later.

[hiyan]

Error Logs simulating my original problem.

[2020-03-25 11:37:29.034 15231] SQLite3 message: API called with finalized prepared statement (21)
[2020-03-25 11:37:29.037 15231] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-03-25 11:37:29.038 15231] domain_in_list("g.whatsapp.net"): Failed to bind domain: bad parameter or other API misuse
[2020-03-25 11:37:29.040 15231] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-03-25 11:37:29.042 15231] ---------------------------->  FTL crashed!  <----------------------------
[2020-03-25 11:37:29.043 15231] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-03-25 11:37:29.045 15231] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-03-25 11:37:29.046 15231] and include in your report already the following details:
[2020-03-25 11:37:29.048 15231] FTL has been running for 1679 seconds
[2020-03-25 11:37:29.048 15231] FTL branch: tweak/sqlite_debugging
[2020-03-25 11:37:29.050 15231] FTL version: vDev-2b2e19d
[2020-03-25 11:37:29.051 15231] FTL commit: 2b2e19d
[2020-03-25 11:37:29.053 15231] FTL date: 2020-03-24 13:46:15 +0100
[2020-03-25 11:37:29.054 15231] FTL user: started as pihole, ended as pihole
[2020-03-25 11:37:29.055 15231] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-03-25 11:37:29.057 15231] Received signal: Segmentation fault
[2020-03-25 11:37:29.058 15231]      at address: 0x260000ad
[2020-03-25 11:37:29.059 15231]      with code: SEGV_MAPERR (Address not mapped to object)
[2020-03-25 11:37:29.062 15231] Backtrace:
[2020-03-25 11:37:29.065 15231] B[0000]: 0x523a98, /usr/bin/pihole-FTL(+0x2ba98) [0x523a98]
[2020-03-25 11:37:29.066 15231] B[0001]: 0xb6dbb130, /lib/arm-linux-gnueabihf/libc.so.6(__default_rt_sa_restorer+0) [0xb6dbb130]
[2020-03-25 11:37:29.068 15231] B[0002]: 0x5cd864, /usr/bin/pihole-FTL(sqlite3_bind_text+0x28) [0x5cd864]
[2020-03-25 11:37:29.070 15231] B[0003]: 0x51c350, /usr/bin/pihole-FTL(in_blacklist+0x60) [0x51c350]
[2020-03-25 11:37:29.071 15231] B[0004]: 0x527a40, /usr/bin/pihole-FTL(+0x2fa40) [0x527a40]
[2020-03-25 11:37:29.073 15231] B[0005]: 0x528f24, /usr/bin/pihole-FTL(_FTL_new_query+0x684) [0x528f24]
[2020-03-25 11:37:29.074 15231] B[0006]: 0x5408f4, /usr/bin/pihole-FTL(tcp_request+0x6a4) [0x5408f4]
[2020-03-25 11:37:29.076 15231] B[0007]: 0x557884, /usr/bin/pihole-FTL(+0x5f884) [0x557884]
[2020-03-25 11:37:29.077 15231] B[0008]: 0x559568, /usr/bin/pihole-FTL(main_dnsmasq+0xe90) [0x559568]
[2020-03-25 11:37:29.079 15231] B[0009]: 0x516aec, /usr/bin/pihole-FTL(main+0xd8) [0x516aec]
[2020-03-25 11:37:29.081 15231] B[0010]: 0xb6da5718, /lib/arm-linux-gnueabihf/libc.so.6(__libc_start_main+0x10c) [0xb6da5718]
[2020-03-25 11:37:29.081 15231] ------ Listing content of directory /dev/shm ------
[2020-03-25 11:37:29.083 15231] File Mode User:Group  Filesize Filename
[2020-03-25 11:37:29.085 15231] rwxrwxrwx root:root 260 .
[2020-03-25 11:37:29.087 15231] rwxr-xr-x root:root 3K ..
[2020-03-25 11:37:29.089 15231] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-03-25 11:37:29.091 15231] rw------- pihole:pihole 12K FTL-dns-cache
[2020-03-25 11:37:29.093 15231] rw------- pihole:pihole 53K FTL-overTime
[2020-03-25 11:37:29.095 15231] rw------- pihole:pihole 2M FTL-queries
[2020-03-25 11:37:29.097 15231] rw------- pihole:pihole 20K FTL-upstreams
[2020-03-25 11:37:29.099 15231] rw------- pihole:pihole 20K FTL-clients
[2020-03-25 11:37:29.101 15231] rw------- pihole:pihole 66K FTL-domains
[2020-03-25 11:37:29.103 15231] rw------- pihole:pihole 66K FTL-strings
[2020-03-25 11:37:29.106 15231] rw------- pihole:pihole 12 FTL-settings
[2020-03-25 11:37:29.108 15231] rw------- pihole:pihole 120 FTL-counters
[2020-03-25 11:37:29.111 15231] rw------- pihole:pihole 28 FTL-lock
[2020-03-25 11:37:29.112 15231] ---------------------------------------------------
[2020-03-25 11:37:29.113 15231] Thank you for helping us to improve our FTL engine!
[2020-03-25 11:37:29.115 15231] FTL terminated!
[2020-03-25 11:37:29.393 15232] SQLite3 message: API called with finalized prepared statement (21)
[2020-03-25 11:37:29.395 15232] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-03-25 11:37:29.397 15232] domain_in_list("g.whatsapp.net"): Failed to bind domain: bad parameter or other API misuse
[2020-03-25 11:37:29.399 15232] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-03-25 11:37:29.400 15232] ---------------------------->  FTL crashed!  <----------------------------
[2020-03-25 11:37:29.401 15232] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-03-25 11:37:29.403 15232] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-03-25 11:37:29.404 15232] and include in your report already the following details:
[2020-03-25 11:37:29.405 15232] FTL has been running for 1679 seconds
[2020-03-25 11:37:29.406 15232] FTL branch: tweak/sqlite_debugging
[2020-03-25 11:37:29.407 15232] FTL version: vDev-2b2e19d
[2020-03-25 11:37:29.408 15232] FTL commit: 2b2e19d
[2020-03-25 11:37:29.409 15232] FTL date: 2020-03-24 13:46:15 +0100
[2020-03-25 11:37:29.411 15232] FTL user: started as pihole, ended as pihole
[2020-03-25 11:37:29.412 15232] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-03-25 11:37:29.414 15232] Received signal: Segmentation fault
[2020-03-25 11:37:29.415 15232]      at address: 0x260000ad
[2020-03-25 11:37:29.417 15232]      with code: SEGV_MAPERR (Address not mapped to object)
[2020-03-25 11:37:29.419 15232] Backtrace:
[2020-03-25 11:37:29.424 15232] B[0000]: 0x523a98, /usr/bin/pihole-FTL(+0x2ba98) [0x523a98]
[2020-03-25 11:37:29.425 15232] B[0001]: 0xb6dbb130, /lib/arm-linux-gnueabihf/libc.so.6(__default_rt_sa_restorer+0) [0xb6dbb130]
[2020-03-25 11:37:29.427 15232] B[0002]: 0x5cd864, /usr/bin/pihole-FTL(sqlite3_bind_text+0x28) [0x5cd864]
[2020-03-25 11:37:29.428 15232] B[0003]: 0x51c350, /usr/bin/pihole-FTL(in_blacklist+0x60) [0x51c350]
[2020-03-25 11:37:29.430 15232] B[0004]: 0x527a40, /usr/bin/pihole-FTL(+0x2fa40) [0x527a40]
[2020-03-25 11:37:29.432 15232] B[0005]: 0x528f24, /usr/bin/pihole-FTL(_FTL_new_query+0x684) [0x528f24]
[2020-03-25 11:37:29.433 15232] B[0006]: 0x5408f4, /usr/bin/pihole-FTL(tcp_request+0x6a4) [0x5408f4]
[2020-03-25 11:37:29.434 15232] B[0007]: 0x557884, /usr/bin/pihole-FTL(+0x5f884) [0x557884]
[2020-03-25 11:37:29.436 15232] B[0008]: 0x559568, /usr/bin/pihole-FTL(main_dnsmasq+0xe90) [0x559568]
[2020-03-25 11:37:29.438 15232] B[0009]: 0x516aec, /usr/bin/pihole-FTL(main+0xd8) [0x516aec]
[2020-03-25 11:37:29.439 15232] B[0010]: 0xb6da5718, /lib/arm-linux-gnueabihf/libc.so.6(__libc_start_main+0x10c) [0xb6da5718]
[2020-03-25 11:37:29.441 15232] ------ Listing content of directory /dev/shm ------
[2020-03-25 11:37:29.443 15232] File Mode User:Group  Filesize Filename
[2020-03-25 11:37:29.445 15232] rwxrwxrwx root:root 260 .
[2020-03-25 11:37:29.447 15232] rwxr-xr-x root:root 3K ..
[2020-03-25 11:37:29.450 15232] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-03-25 11:37:29.452 15232] rw------- pihole:pihole 12K FTL-dns-cache
[2020-03-25 11:37:29.455 15232] rw------- pihole:pihole 53K FTL-overTime
[2020-03-25 11:37:29.457 15232] rw------- pihole:pihole 2M FTL-queries
[2020-03-25 11:37:29.459 15232] rw------- pihole:pihole 20K FTL-upstreams
[2020-03-25 11:37:29.463 15232] rw------- pihole:pihole 20K FTL-clients
[2020-03-25 11:37:29.465 15232] rw------- pihole:pihole 66K FTL-domains
[2020-03-25 11:37:29.468 15232] rw------- pihole:pihole 66K FTL-strings
[2020-03-25 11:37:29.470 15232] rw------- pihole:pihole 12 FTL-settings
[2020-03-25 11:37:29.473 15232] rw------- pihole:pihole 120 FTL-counters
[2020-03-25 11:37:29.475 15232] rw------- pihole:pihole 28 FTL-lock
[2020-03-25 11:37:29.477 15232] ---------------------------------------------------
[2020-03-25 11:37:29.478 15232] Thank you for helping us to improve our FTL engine!
[2020-03-25 11:37:29.480 15232] FTL terminated!

[DL6ER]

@hiyan Okay, can you send me the entire log file somehow? Via mail if you prefer to send it private, I will not leak any private information (there shouldn't be any in it, but still...). Send it to <my username>@pi-hole.net and tell me to check my inbox if you are okay with it.

[DL6ER]

Okay, before sending anything, please update and try again. I think I found why FTL might have died for you. You are seeing something I have not seen before, that is that the database file, even though all permissions and ownership seems to be correct, isn't readable. As it is the single source of truth for Pi-hole, it caused issues the most recent update (a few minutes ago) should have resolved now.

Please also try the following:

sqlite3 /etc/pihole/gravity.db "SELECT COUNT(DISTINCT domain) FROM vw_gravity;"
sqlite3 /etc/pihole/gravity.db "SELECT * FROM vw_gravity LIMIT 5;"

and provide the output.

[hiyan]

@DL6ER check your email

[DL6ER]

Did you try again with my updated version? If not,please try branch fix/TCP_forks (the other one was merged meanwhile).

I checked your log file meanwhile and it is very confusing. Can you confirm that you have only one pihole-FTL process running at the same time? I assume the error comes from forked versions of pihole-FTL when working on TCP requests. I will try to reproduce this, it would certainly explain at least parts of the issue you're seeing.

[hiyan]

No I did not test anything last week.

Just tested fix/TCP_forks... error log below.

Phone was on wifi when FTL started. At ~11:01, switched to mobile network.

[2020-04-03 10:45:34.752 23662] ########## FTL started! ##########
[2020-04-03 10:45:34.753 23662] FTL branch: fix/TCP_forks
[2020-04-03 10:45:34.754 23662] FTL version: vDev-53bc882
[2020-04-03 10:45:34.756 23662] FTL commit: 53bc8829
[2020-04-03 10:45:34.757 23662] FTL date: 2020-04-02 19:33:50 +0000
[2020-04-03 10:45:34.759 23662] FTL user: pihole
[2020-04-03 10:45:34.760 23662] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-04-03 10:45:34.762 23662] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-04-03 10:45:34.763 23662]    SOCKET_LISTENING: only local
[2020-04-03 10:45:34.765 23662]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-04-03 10:45:34.766 23662]    MAXDBDAYS: max age for stored queries is 365 days
[2020-04-03 10:45:34.767 23662]    RESOLVE_IPV6: Resolve IPv6 addresses
[2020-04-03 10:45:34.768 23662]    RESOLVE_IPV4: Resolve IPv4 addresses
[2020-04-03 10:45:34.769 23662]    DBINTERVAL: saving to DB file every minute
[2020-04-03 10:45:34.770 23662]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-04-03 10:45:34.772 23662]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-04-03 10:45:34.773 23662]    PRIVACYLEVEL: Set to 0
[2020-04-03 10:45:34.774 23662]    IGNORE_LOCALHOST: Show queries from localhost
[2020-04-03 10:45:34.776 23662]    BLOCKINGMODE: Null IPs for blocked domains
[2020-04-03 10:45:34.777 23662]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-04-03 10:45:34.779 23662]    DBIMPORT: Importing history from database
[2020-04-03 10:45:34.779 23662]    PIDFILE: Using /var/run/pihole-FTL.pid
[2020-04-03 10:45:34.780 23662]    PORTFILE: Using /var/run/pihole-FTL.port
[2020-04-03 10:45:34.782 23662]    SOCKETFILE: Using /var/run/pihole/FTL.sock
[2020-04-03 10:45:34.783 23662]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-04-03 10:45:34.784 23662]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-04-03 10:45:34.786 23662]    GRAVITYDB: Using /etc/pihole/gravity.db
[2020-04-03 10:45:34.787 23662]    PARSE_ARP_CACHE: Active
[2020-04-03 10:45:34.788 23662]    REGEX_IGNORECASE: Disabled. Regex is case sensitive
[2020-04-03 10:45:34.790 23662]    CNAME_DEEP_INSPECT: Active
[2020-04-03 10:45:34.790 23662]    DELAY_STARTUP: No delay requested.
[2020-04-03 10:45:34.792 23662] Finished config file parsing
[2020-04-03 10:45:34.800 23662] Database version is 5
[2020-04-03 10:45:34.803 23662] Database successfully initialized
[2020-04-03 10:45:34.812 23662] New upstream server: 127.0.0.1 (0/1024)
[2020-04-03 10:45:34.814 23662] New upstream server: 192.168.1.1 (1/1024)
[2020-04-03 10:45:34.824 23662] Resizing "/FTL-strings" from 4096 to 8192
[2020-04-03 10:45:34.851 23662] Resizing "/FTL-strings" from 8192 to 12288
[2020-04-03 10:45:34.923 23662] Resizing "/FTL-strings" from 12288 to 16384
[2020-04-03 10:45:35.007 23662] Resizing "/FTL-queries" from 229376 to 458752
[2020-04-03 10:45:35.011 23662] Resizing "/FTL-strings" from 16384 to 20480
[2020-04-03 10:45:35.105 23662] Resizing "/FTL-strings" from 20480 to 24576
[2020-04-03 10:45:35.228 23662] Resizing "/FTL-strings" from 24576 to 28672
[2020-04-03 10:45:35.278 23662] Resizing "/FTL-queries" from 458752 to 688128
[2020-04-03 10:45:35.348 23662] Resizing "/FTL-strings" from 28672 to 32768
[2020-04-03 10:45:35.542 23662] Resizing "/FTL-strings" from 32768 to 36864
[2020-04-03 10:45:35.584 23662] Resizing "/FTL-queries" from 688128 to 917504
[2020-04-03 10:45:35.736 23662] Resizing "/FTL-strings" from 36864 to 40960
[2020-04-03 10:45:36.098 23662] Resizing "/FTL-strings" from 40960 to 45056
[2020-04-03 10:45:36.119 23662] Resizing "/FTL-queries" from 917504 to 1146880
[2020-04-03 10:45:36.510 23662] Resizing "/FTL-queries" from 1146880 to 1376256
[2020-04-03 10:45:36.516 23662] Resizing "/FTL-strings" from 45056 to 49152
[2020-04-03 10:45:36.805 23662] Resizing "/FTL-strings" from 49152 to 53248
[2020-04-03 10:45:37.014 23662] Resizing "/FTL-queries" from 1376256 to 1605632
[2020-04-03 10:45:37.049 23662] Imported 24782 queries from the long-term database
[2020-04-03 10:45:37.054 23662]  -> Total DNS queries: 24782
[2020-04-03 10:45:37.056 23662]  -> Cached DNS queries: 349
[2020-04-03 10:45:37.057 23662]  -> Forwarded DNS queries: 12157
[2020-04-03 10:45:37.058 23662]  -> Blocked DNS queries: 12196
[2020-04-03 10:45:37.060 23662]  -> Unknown DNS queries: 80
[2020-04-03 10:45:37.061 23662]  -> Unique domains: 2522
[2020-04-03 10:45:37.063 23662]  -> Unique clients: 16
[2020-04-03 10:45:37.064 23662]  -> Known forward destinations: 2
[2020-04-03 10:45:37.065 23662] Successfully accessed setupVars.conf
[2020-04-03 10:45:37.098 23664] PID of FTL process: 23664
[2020-04-03 10:45:37.102 23664] Listening on port 4711 for incoming IPv4 telnet connections
[2020-04-03 10:45:37.108 23664] Listening on port 4711 for incoming IPv6 telnet connections
[2020-04-03 10:45:37.113 23664] Listening on Unix socket
[2020-04-03 10:45:37.156 23664] Reloading DNS cache
[2020-04-03 10:45:37.162 23664] Blocking status is enabled
[2020-04-03 10:45:37.390 23664] INFO: No regex whitelist entries found
[2020-04-03 10:45:37.489 23664] Compiled 0 whitelist and 8 blacklist regex filters in 119.6 msec
[2020-04-03 10:46:00.394 23664] Resizing "/FTL-strings" from 53248 to 57344
[2020-04-03 10:50:01.756 23664] Resizing "/FTL-dns-cache" from 4096 to 8192
[2020-04-03 10:55:20.073 23664] Resizing "/FTL-strings" from 57344 to 61440
[2020-04-03 10:55:26.450 24514] Remapping "/FTL-strings" from 57344 to 61440
[2020-04-03 10:58:17.905 23664] Resizing "/FTL-dns-cache" from 8192 to 12288
[2020-04-03 11:01:04.152 24971] SQLite3 message: API called with finalized prepared statement (21)
[2020-04-03 11:01:04.155 24971] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-04-03 11:01:04.156 24971] domain_in_list("49fb2fc1-dnsotls-ds.metric.gstatic.com", 0x19425a8, whitelist): Failed to bind domain: bad parameter or other API misuse
[2020-04-03 11:01:04.157 24971] SQLite3 message: API called with finalized prepared statement (21)
[2020-04-03 11:01:04.159 24971] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-04-03 11:01:04.160 24971] domain_in_list("49fb2fc1-dnsotls-ds.metric.gstatic.com", 0x1a4fee0, blacklist): Failed to bind domain: bad parameter or other API misuse
[2020-04-03 11:01:04.161 24971] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-04-03 11:01:04.163 24971] ---------------------------->  FTL crashed!  <----------------------------
[2020-04-03 11:01:04.164 24971] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-04-03 11:01:04.165 24971] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-04-03 11:01:04.166 24971] and include in your report already the following details:
[2020-04-03 11:01:04.167 24971] FTL has been running for 930 seconds
[2020-04-03 11:01:04.168 24971] FTL branch: fix/TCP_forks
[2020-04-03 11:01:04.169 24971] FTL version: vDev-53bc882
[2020-04-03 11:01:04.170 24971] FTL commit: 53bc8829
[2020-04-03 11:01:04.171 24971] FTL date: 2020-04-02 19:33:50 +0000
[2020-04-03 11:01:04.173 24971] FTL user: started as pihole, ended as pihole
[2020-04-03 11:01:04.174 24971] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-04-03 11:01:04.177 24971] Received signal: Segmentation fault
[2020-04-03 11:01:04.180 24971]      at address: 0xf
[2020-04-03 11:01:04.181 24971]      with code: SEGV_MAPERR (Address not mapped to object)
[2020-04-03 11:01:04.182 24971] Backtrace:
[2020-04-03 11:01:04.189 24971] B[0000]: 0x448da4, /usr/bin/pihole-FTL(+0x2cda4) [0x448da4]
[2020-04-03 11:01:04.191 24971] B[0001]: 0xb6d94130, /lib/arm-linux-gnueabihf/libc.so.6(__default_rt_sa_restorer+0) [0xb6d94130]
[2020-04-03 11:01:04.193 24971] B[0002]: 0x4f2d54, /usr/bin/pihole-FTL(sqlite3_bind_text+0x28) [0x4f2d54]
[2020-04-03 11:01:04.195 24971] B[0003]: 0x440ce0, /usr/bin/pihole-FTL(in_gravity+0x54) [0x440ce0]
[2020-04-03 11:01:04.197 24971] B[0004]: 0x44ceb0, /usr/bin/pihole-FTL(+0x30eb0) [0x44ceb0]
[2020-04-03 11:01:04.199 24971] B[0005]: 0x44e2d0, /usr/bin/pihole-FTL(_FTL_new_query+0x69c) [0x44e2d0]
[2020-04-03 11:01:04.200 24971] B[0006]: 0x465de4, /usr/bin/pihole-FTL(tcp_request+0x6a4) [0x465de4]
[2020-04-03 11:01:04.201 24971] B[0007]: 0x47cd74, /usr/bin/pihole-FTL(+0x60d74) [0x47cd74]
[2020-04-03 11:01:04.203 24971] B[0008]: 0x47ea58, /usr/bin/pihole-FTL(main_dnsmasq+0xe90) [0x47ea58]
[2020-04-03 11:01:04.204 24971] B[0009]: 0x43ab90, /usr/bin/pihole-FTL(main+0xdc) [0x43ab90]
[2020-04-03 11:01:04.205 24971] B[0010]: 0xb6d7e718, /lib/arm-linux-gnueabihf/libc.so.6(__libc_start_main+0x10c) [0xb6d7e718]
[2020-04-03 11:01:04.206 24971] ------ Listing content of directory /dev/shm ------
[2020-04-03 11:01:04.209 24971] File Mode User:Group  Filesize Filename
[2020-04-03 11:01:04.212 24971] rwxrwxrwx root:root 260 .
[2020-04-03 11:01:04.215 24971] rwxr-xr-x root:root 3K ..
[2020-04-03 11:01:04.217 24971] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-04-03 11:01:04.220 24971] rw------- pihole:pihole 12K FTL-dns-cache
[2020-04-03 11:01:04.223 24971] rw------- pihole:pihole 29K FTL-overTime
[2020-04-03 11:01:04.225 24971] rw------- pihole:pihole 2M FTL-queries
[2020-04-03 11:01:04.228 24971] rw------- pihole:pihole 20K FTL-upstreams
[2020-04-03 11:01:04.231 24971] rw------- pihole:pihole 20K FTL-clients
[2020-04-03 11:01:04.234 24971] rw------- pihole:pihole 66K FTL-domains
[2020-04-03 11:01:04.238 24971] rw------- pihole:pihole 61K FTL-strings
[2020-04-03 11:01:04.241 24971] rw------- pihole:pihole 12 FTL-settings
[2020-04-03 11:01:04.244 24971] rw------- pihole:pihole 124 FTL-counters
[2020-04-03 11:01:04.247 24971] rw------- pihole:pihole 28 FTL-lock
[2020-04-03 11:01:04.250 24971] ---------------------------------------------------
[2020-04-03 11:01:04.253 24971] Thank you for helping us to improve our FTL engine!
[2020-04-03 11:01:04.254 24971] FTL terminated!
[2020-04-03 11:01:04.503 24972] SQLite3 message: API called with finalized prepared statement (21)
[2020-04-03 11:01:04.505 24972] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-04-03 11:01:04.507 24972] domain_in_list("dev.appboy.com", 0x19425a8, whitelist): Failed to bind domain: bad parameter or other API misuse
[2020-04-03 11:01:04.508 24972] SQLite3 message: API called with finalized prepared statement (21)
[2020-04-03 11:01:04.509 24972] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-04-03 11:01:04.511 24972] domain_in_list("dev.appboy.com", 0x1a4fee0, blacklist): Failed to bind domain: bad parameter or other API misuse
[2020-04-03 11:01:04.512 24972] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-04-03 11:01:04.513 24972] ---------------------------->  FTL crashed!  <----------------------------
[2020-04-03 11:01:04.515 24972] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-04-03 11:01:04.516 24972] Please report a bug at https://github.com/pi-hole/FTL/issues
[2020-04-03 11:01:04.517 24972] and include in your report already the following details:
[2020-04-03 11:01:04.517 24972] FTL has been running for 930 seconds
[2020-04-03 11:01:04.518 24972] FTL branch: fix/TCP_forks
[2020-04-03 11:01:04.519 24972] FTL version: vDev-53bc882
[2020-04-03 11:01:04.520 24972] FTL commit: 53bc8829
[2020-04-03 11:01:04.521 24972] FTL date: 2020-04-02 19:33:50 +0000
[2020-04-03 11:01:04.522 24972] FTL user: started as pihole, ended as pihole
[2020-04-03 11:01:04.523 24972] Compiled for arm (compiled on CI) using arm-linux-gnueabihf-gcc (crosstool-NG crosstool-ng-1.22.0-88-g8460611) 4.9.3
[2020-04-03 11:01:04.524 24972] Received signal: Segmentation fault
[2020-04-03 11:01:04.525 24972]      at address: 0xf
[2020-04-03 11:01:04.526 24972]      with code: SEGV_MAPERR (Address not mapped to object)
[2020-04-03 11:01:04.527 24972] Backtrace:
[2020-04-03 11:01:04.530 24972] B[0000]: 0x448da4, /usr/bin/pihole-FTL(+0x2cda4) [0x448da4]
[2020-04-03 11:01:04.531 24972] B[0001]: 0xb6d94130, /lib/arm-linux-gnueabihf/libc.so.6(__default_rt_sa_restorer+0) [0xb6d94130]
[2020-04-03 11:01:04.532 24972] B[0002]: 0x4f2d54, /usr/bin/pihole-FTL(sqlite3_bind_text+0x28) [0x4f2d54]
[2020-04-03 11:01:04.533 24972] B[0003]: 0x440ce0, /usr/bin/pihole-FTL(in_gravity+0x54) [0x440ce0]
[2020-04-03 11:01:04.534 24972] B[0004]: 0x44ceb0, /usr/bin/pihole-FTL(+0x30eb0) [0x44ceb0]
[2020-04-03 11:01:04.535 24972] B[0005]: 0x44e2d0, /usr/bin/pihole-FTL(_FTL_new_query+0x69c) [0x44e2d0]
[2020-04-03 11:01:04.536 24972] B[0006]: 0x465de4, /usr/bin/pihole-FTL(tcp_request+0x6a4) [0x465de4]
[2020-04-03 11:01:04.537 24972] B[0007]: 0x47cd74, /usr/bin/pihole-FTL(+0x60d74) [0x47cd74]
[2020-04-03 11:01:04.537 24972] B[0008]: 0x47ea58, /usr/bin/pihole-FTL(main_dnsmasq+0xe90) [0x47ea58]
[2020-04-03 11:01:04.538 24972] B[0009]: 0x43ab90, /usr/bin/pihole-FTL(main+0xdc) [0x43ab90]
[2020-04-03 11:01:04.540 24972] B[0010]: 0xb6d7e718, /lib/arm-linux-gnueabihf/libc.so.6(__libc_start_main+0x10c) [0xb6d7e718]
[2020-04-03 11:01:04.541 24972] ------ Listing content of directory /dev/shm ------
[2020-04-03 11:01:04.542 24972] File Mode User:Group  Filesize Filename
[2020-04-03 11:01:04.543 24972] rwxrwxrwx root:root 260 .
[2020-04-03 11:01:04.545 24972] rwxr-xr-x root:root 3K ..
[2020-04-03 11:01:04.546 24972] rw------- pihole:pihole 4K FTL-per-client-regex
[2020-04-03 11:01:04.548 24972] rw------- pihole:pihole 12K FTL-dns-cache
[2020-04-03 11:01:04.550 24972] rw------- pihole:pihole 29K FTL-overTime
[2020-04-03 11:01:04.551 24972] rw------- pihole:pihole 2M FTL-queries
[2020-04-03 11:01:04.553 24972] rw------- pihole:pihole 20K FTL-upstreams
[2020-04-03 11:01:04.555 24972] rw------- pihole:pihole 20K FTL-clients
[2020-04-03 11:01:04.556 24972] rw------- pihole:pihole 66K FTL-domains
[2020-04-03 11:01:04.558 24972] rw------- pihole:pihole 61K FTL-strings
[2020-04-03 11:01:04.560 24972] rw------- pihole:pihole 12 FTL-settings
[2020-04-03 11:01:04.562 24972] rw------- pihole:pihole 124 FTL-counters
[2020-04-03 11:01:04.564 24972] rw------- pihole:pihole 28 FTL-lock
[2020-04-03 11:01:04.565 24972] ---------------------------------------------------
[2020-04-03 11:01:04.566 24972] Thank you for helping us to improve our FTL engine!
[2020-04-03 11:01:04.567 24972] FTL terminated!
[2020-04-03 11:01:04.921 24973] SQLite3 message: API called with finalized prepared statement (21)
[2020-04-03 11:01:04.923 24973] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-04-03 11:01:04.925 24973] domain_in_list("dev.appboy.com", 0x19425a8, whitelist): Failed to bind domain: bad parameter or other API misuse
[2020-04-03 11:01:04.926 24973] SQLite3 message: API called with finalized prepared statement (21)
[2020-04-03 11:01:04.928 24973] SQLite3 message: misuse at line 82937 of [18db032d05] (21)
[2020-04-03 11:01:04.929 24973] domain_in_list("dev.appboy.com", 0x1a4fee0, blacklist): Failed to bind domain: bad parameter or other API misuse
[2020-04-03 11:01:04.930 24973] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2020-04-03 11:01:04.933 24973] ---------------------------->  FTL crashed!  <----------------------------
[2020-04-03 11:01:04.934 24973] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

[hiyan]

Just to add, between FTL start and before 11am, I did try to switch between wifi and mobile, no issue then.

[DL6ER]

In the square brackets, right at the end, we show the process identifier (PID) of the current process. The first increase (always be two) during startup is expired while FTL goes daemon. You can see that the PID of the crashed FTL instance is different, again. This very likely means that FTL forked to reply to queries received over a TCP connection. I will investigate on this further.

[DL6ER]

I was able to reproduce the issue locally and this will be a tough issue to resolve: This problem is that SQLite3 does not support sharing prepared statements across (real) process forks and, since we share all cata across the forks, FTL tries to access memory owned by another fork what can obviously not work out.

The solution will be to take the prepared client statements out of shared memory and into a dedicated SQLite3 vector (which still has to be invented). Stand by.

[DL6ER]

@hiyan In addition to the already existing thread-safety, I did now add another layer of fork-safety on top of the gravity database routines. This should resolve the issues you're seeing.

Please update/re-checkout and test. And thanks for your patience!

[hiyan]

I've been running the latest fix/TCP_forks for few hours now, original problem seems to have been fixed.

However, early on, occasionally when switching from wifi to mobile, android reports no internet ("!" symbol in signal strength icon). (Note: no problem switching mobile to wifi.) Disconnecting mobile data and re-enabling it fixes it. In the last hour (or 2), I cant seem to replicate it.

Since there is no crashes in FTL, maybe it's a android thing(?).

I'll continue testing it and will report back if I can simulate the issue consistently.

[DL6ER]

Since there is no crashes in FTL, maybe it's a android thing(?).

Yes, especially since it appears after switching from WiFi to Cellular data. The phone is then not connected to your Pi-hole at all, I don't see how Pi-hole/FTL could affect anything on your phone after disconnecting from your local network.

Otherwise: Great, thanks for confirming our fix!

[DL6ER]

Pi-hole v5.0 has just been released.