FTL Crashed!

[norrkin]

Upgraded yesterday and now FTL keeps going offline.

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

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

How familiar are you with the codebase?:

0

[BUG | ISSUE] Expected Behaviour:

FTL to be online

[BUG | ISSUE] Actual Behaviour:

FTL crashing with Segmentation fault

[BUG | ISSUE] Steps to reproduce:

Upgrade to latest pihole v3.1 & FTL v2.9.2

Log file output [if available]

Log output;

[2017-06-21 18:59:01.115] > Please report a bug at https://github.com/pi-hole/FTL/issues
[2017-06-21 18:59:01.115] > and include in your report already the following details:
[2017-06-21 18:59:01.115] >
[2017-06-21 18:59:01.115] > Received signal: Segmentation fault
[2017-06-21 18:59:01.115] at address: 104
[2017-06-21 18:59:01.115] with code: SEGV_MAPERR (Address not mapped to object)
[2017-06-21 18:59:01.115] > Memory usage (structs): 356428
[2017-06-21 18:59:01.115] > Memory usage (dynamic): 7851
[2017-06-21 18:59:01.115] >
[2017-06-21 18:59:01.115] > Thank you for helping us to improve our FTL engine!
[2017-06-21 18:59:01.115] FTL terminated!

But before that output is does moan about the database being locked;

[2017-06-21 16:59:01.044] SQL error (5): database is locked
[2017-06-21 16:59:01.044] DB-GC error: Deleting queries due to age of entries failed!
[2017-06-21 17:59:01.100] SQL error (5): database is locked
[2017-06-21 17:59:01.109] DB-GC error: Deleting queries due to age of entries failed!

Device specifics

Hardware Type: VPS
OS: Debian

[DL6ER]

We see issues with sqlite3_changes() and will release FTL v2.9.3 shortly to fix this. However, it is unclear if your issue is caused by the same problem. Could you help debugging where the crash is happening if it is reproducible?

We have compiled a set of instructions here:
https://github.com/pi-hole/FTL#debugging-pihole-ftl

Since FTL is working for you at least temporarily, you can skip steps 4.-7. and use the simplified debugging instructions given underneath.

Since the recent updates (FTL v2.9.3) my FTL behave to crash, too.
I run Pi-hole at NanoPi NEO and DietPi.

pihole-FTL.log:

[2017-06-21 20:34:44.968] Listening on port 4711 for incoming connections
[2017-06-21 20:59:01.023] SQL error (5): database is locked
[2017-06-21 20:59:01.024] DB-GC error: Deleting queries due to age of entries failed!
[2017-06-21 21:59:01.095] SQL error (5): database is locked
[2017-06-21 21:59:01.096] DB-GC error: Deleting queries due to age of entries failed!
[2017-06-21 21:59:01.096] SQL error (5): database is locked
alot of this mesages, snip
[2017-06-21 22:59:01.062] SQL error (5): database is locked
[2017-06-21 22:59:01.063] DB-GC error: Deleting queries due to age of entries failed!
[2017-06-21 22:59:01.064] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2017-06-21 22:59:01.064] ----------------------------> FTL crashed! <----------------------------
[2017-06-21 22:59:01.065] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2017-06-21 22:59:01.065] > Please report a bug at https://github.com/pi-hole/FTL/issues
[2017-06-21 22:59:01.065] > and include in your report already the following details:
[2017-06-21 22:59:01.066] >
[2017-06-21 22:59:01.066] > Received signal: Segmentation fault
[2017-06-21 22:59:01.067] at address: 1650552437
[2017-06-21 22:59:01.067] with code: SEGV_MAPERR (Address not mapped to object)
[2017-06-21 22:59:01.068] > Memory usage (structs): 343544
[2017-06-21 22:59:01.068] > Memory usage (dynamic): 10437
[2017-06-21 22:59:01.068] >
[2017-06-21 22:59:01.069] > Thank you for helping us to improve our FTL engine!
[2017-06-21 22:59:01.069] FTL terminated!

[DL6ER]

Is this with v2.9.2 or v2.9.3?

Ok, edited to slow. FTL v2.9.3 it is.

[technicalpyro]

could it be that the SQL db is being written then deleted by the dietpi log flush sequence?

Another hint, a second Pi-hole at RPi v1 and Raspbian no crashes so far.

[DL6ER]

Hmm, could you also follow the debug instructions and post that on a new issue to lower the chance that things get mixed up? It is not yet clear if both of you are affected by exactly the same problem

@technicalpyro I set "Log System: None". This should disable all sort of Ramlog or Logrotate.

[AzureMarker]

Check the file permissions: sudo chown -R pihole /etc/pihole/

@Mcat12 You are onto something. It seems that folder has odd permissions.

/etc/pihole look like this:

-rw-r--r-- 1 root root 1088 Jun 19 15:59 adlists.list
-rw-r--r-- 1 root root 253 Jun 21 16:59 black.list
-rw-r--r-- 1 root root 175 Jun 19 16:23 blacklist.txt
-rw-r--r-- 1 root root 4684029 Jun 21 16:59 gravity.list
-rw-r--r-- 1 root root 811 Jun 21 16:58 install.log
-rw------- 1 root root 1115644 Jun 21 16:58 list.0.raw.githubusercontent.com.domains
-rw------- 1 root root 1584793 Jun 21 16:59 list.10.malwaredomains.lehigh.edu.domains
-rw------- 1 root root 1016402 Jun 21 16:59 list.11.raw.github.com.domains
-rw------- 1 root root 1985092 Jun 21 16:59 list.12.raw.github.com.domains
-rw------- 1 root root 515136 Jun 21 16:58 list.1.mirror1.malwaredomains.com.domains
-rw------- 1 root root 660314 Jun 21 16:58 list.2.sysctl.org.domains
-rw------- 1 root root 7314 Jun 21 16:59 list.3.zeustracker.abuse.ch.domains
-rw------- 1 root root 613 Jun 21 16:59 list.4.s3.amazonaws.com.domains
-rw------- 1 root root 43642 Jun 21 16:59 list.5.s3.amazonaws.com.domains
-rw------- 1 root root 1830943 Jun 21 16:59 list.6.hosts-file.net.domains
-rw------- 1 root root 9221 Jun 21 16:59 list.7.raw.githubusercontent.com.domains
-rw------- 1 root root 335362 Jun 21 16:59 list.8.raw.githubusercontent.com.domains
-rw------- 1 root root 155018 Jun 21 16:59 list.9.raw.githubusercontent.com.domains
-rw-r--r-- 1 root root 2944537 Jun 21 16:59 list.preEventHorizon
-rw-r--r-- 1 root root 54 Jun 21 16:59 local.list
-rw-r--r-- 1 root root 234 Jun 21 16:58 logrotate
-rw-r--r-- 1 pihole pihole 245760 Jun 22 00:26 pihole-FTL.db
-rw-r--r-- 1 root root 300 Jun 21 16:58 setupVars.conf
-rw-r--r-- 1 root root 286 Jun 21 16:58 setupVars.conf.update.bak
-rw-r--r-- 1 root root 197 Jun 19 16:24 whitelist.txt

[DL6ER]

-rw-r--r-- 1 pihole pihole 245760 Jun 22 00:26 pihole-FTL.db is fine for the database file

Another coincidence, all crashes occurred at xx:59:01.xxx after some uptime.
What happens every hour at minute 59:01?

[DL6ER]

Database cleaning (remove old entries). That should anyhow not crash (and doesn't always crash for you!). Please provide the debug backtrace in a new issue

[DocHolzfaust]

hey, sorry, closed to fast.

if have clear my database after last crash, but now it crashes again:

my system is : Linux minedeb 3.16.0-4-amd64 #1 SMP Debian 3.16.43-2 (2017-04-30) x86_64 GNU/Linux

pihole-FTL.log
[2017-06-22 10:19:32.561] ########## FTL started! ##########
[2017-06-22 10:19:32.561] FTL branch: (no branch)
[2017-06-22 10:19:32.561] FTL hash: v2.9.3
[2017-06-22 10:19:32.561] FTL date: 2017-06-21 20:19:49 +0200
[2017-06-22 10:19:32.561] FTL user: pihole
[2017-06-22 10:19:32.561] Starting config file parsing
[2017-06-22 10:19:32.561] SOCKET_LISTENING: only local
[2017-06-22 10:19:32.561] TIMEFRAME: Rolling 24h
[2017-06-22 10:19:32.561] QUERY_DISPLAY: Show queries
[2017-06-22 10:19:32.561] AAAA_QUERY_ANALYSIS: Show AAAA queries
[2017-06-22 10:19:32.561] MAXDBDAYS: max age for stored queries is 365 days
[2017-06-22 10:19:32.561] Finished config file parsing
[2017-06-22 10:19:32.563] Found no other running pihole-FTL process
[2017-06-22 10:19:32.564] PID of FTL process: 1571
[2017-06-22 10:19:32.595] Gravity list entries: 110160
[2017-06-22 10:19:32.595] Blacklist entries: 6
[2017-06-22 10:19:32.595] No wildcard blocking list present
[2017-06-22 10:19:32.595] Cannot open database: unable to open database file
[2017-06-22 10:19:32.595] Creating new (empty) database
[2017-06-22 10:19:32.613] Database initialized
[2017-06-22 10:19:32.613] Starting initial log file parsing
[2017-06-22 10:19:32.613] Warning: Reading of rotated log file /var/log/pihole.log.1 failed
[2017-06-22 10:19:32.613] Reading from /var/log/pihole.log (rw-rw-rw-)
[2017-06-22 10:19:32.613] Notice: Increasing queries struct size from 0 to 10000 (320.09 KB)
[2017-06-22 10:19:32.613] Notice: Increasing overTime struct size from 0 to 100 (324.09 KB)
[2017-06-22 10:19:32.613] Notice: Increasing domains struct size from 0 to 1000 (356.10 KB)
[2017-06-22 10:19:32.613] Notice: Increasing clients struct size from 0 to 10 (356.36 KB)
[2017-06-22 10:19:32.613] New client: 192.168.10.112 minedeb (0/10)
[2017-06-22 10:19:32.613] Notice: Increasing forwarded struct size from 0 to 4 (356.47 KB)
[2017-06-22 10:19:32.613] New forward server: 192.168.178.1 GW-WT-INET (0/4)
[2017-06-22 10:19:32.613] New forward server: 127.0.0.1 ip6-localhost (1/4)
[2017-06-22 10:19:32.614] New client: 192.168.11.158 IMAC-A38036 (1/10)
[2017-06-22 10:19:32.628] Finished initial log file parsing
[2017-06-22 10:19:32.628] -> Total DNS queries: 937
[2017-06-22 10:19:32.628] -> Cached DNS queries: 3
[2017-06-22 10:19:32.628] -> Blocked DNS queries: 59
[2017-06-22 10:19:32.628] -> Unknown DNS queries: 0
[2017-06-22 10:19:32.628] -> Unique domains: 577
[2017-06-22 10:19:32.628] -> Unique clients: 2
[2017-06-22 10:19:32.628] Successfully accessed setupVars.conf
[2017-06-22 10:19:32.628] Listening on port 4711 for incoming connections
[2017-06-22 11:10:17.388] New client: fe80::4170:3e4c:35a:7a90 (2/10)
[2017-06-22 11:12:04.127] Notice: Increasing domains struct size from 1000 to 2000 (411.62 KB)
[2017-06-22 12:56:59.906] New client: fe80::fd47:38df:1e0f:3c3 (3/10)
[2017-06-22 13:59:01.017] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2017-06-22 13:59:01.017] ----------------------------> FTL crashed! <----------------------------
[2017-06-22 13:59:01.017] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2017-06-22 13:59:01.017] > Please report a bug at https://github.com/pi-hole/FTL/issues
[2017-06-22 13:59:01.017] > and include in your report already the following details:
[2017-06-22 13:59:01.017] >
[2017-06-22 13:59:01.017] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2017-06-22 13:59:01.017] ----------------------------> FTL crashed! <----------------------------
[2017-06-22 13:59:01.017] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2017-06-22 13:59:01.017] > Please report a bug at https://github.com/pi-hole/FTL/issues
[2017-06-22 13:59:01.017] > and include in your report already the following details:
[2017-06-22 13:59:01.017] >
[2017-06-22 13:59:01.017] > Received signal: Segmentation fault
[2017-06-22 13:59:01.017] at address: 140462610448383
[2017-06-22 13:59:01.017] with code: SEGV_MAPERR (Address not mapped to object)
[2017-06-22 13:59:01.017] > Memory usage (structs): 388428
[2017-06-22 13:59:01.017] > Memory usage (dynamic): 40137
[2017-06-22 13:59:01.018] >
[2017-06-22 13:59:01.018] > Thank you for helping us to improve our FTL engine!
[2017-06-22 13:59:01.018] FTL terminated!

[red217]

I have also run into the same issue. I'm a very new user to Pi-hole and only started ~2 days ago, but this did not seem to happen before the Pi-hole 3.1 update, if that helps. I'm running it on an original Raspberry Pi B with Raspbian 7.11.

I've attached a part of the log where FTL crashed, then I started it again and left it running until it started spamming the log with "DB thread - SQL error: database is locked" again. Once that happens it crashes/segfaults again after a while.
pihole-FTL.txt