FTL Crashing after 30-60 mins interval

rhakbari commented 3 years ago

Versions

Pi-hole: v5.2
AdminLTE: v5.2
FTL: v5.3.1

Platform

OS and version:
Platform: Raspberry Pi OS Lite

Actual behavior / bug

The pihole FTL service crashes and then the webpage says unable to connect to API and then i have to restart the DNS resolver in order to fix it temporarily. This has start doing this after this latest update before that it was working alright. A clear and concise description of what the bug is.

Debug Token

URL: https://tricorder.pi-hole.net/l62sqajeyi

DL6ER commented 3 years ago

Can you please check the log file /var/log/pihole-FTL.log for a crash report? Look for lines with !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

jeremych1000 commented 3 years ago

I'm getting crashes after 5-10 minutes.

Latest log lines of FTL, tons of sql errors here.

spoiler

``` [2020-12-01 17:20:56.629 3439M] ########## FTL started! ########## [2020-12-01 17:20:56.630 3439M] FTL branch: release/v5.1.1 [2020-12-01 17:20:56.630 3439M] FTL version: vDev-58ebe22 [2020-12-01 17:20:56.630 3439M] FTL commit: 58ebe22 [2020-12-01 17:20:56.630 3439M] FTL date: 2020-07-24 07:39:31 +0200 [2020-12-01 17:20:56.630 3439M] FTL user: pihole [2020-12-01 17:20:56.630 3439M] Compiled for armhf (compiled on CI) using arm-linux-gnueabihf-gcc (Debian 6.3.0-18) 6.3.0 20170516 [2020-12-01 17:20:56.630 3439M] Starting config file parsing (/etc/pihole/pihole-FTL.conf) [2020-12-01 17:20:56.631 3439M] SOCKET_LISTENING: only local [2020-12-01 17:20:56.631 3439M] AAAA_QUERY_ANALYSIS: Show AAAA queries [2020-12-01 17:20:56.631 3439M] MAXDBDAYS: max age for stored queries is 365 days [2020-12-01 17:20:56.631 3439M] RESOLVE_IPV6: Resolve IPv6 addresses [2020-12-01 17:20:56.631 3439M] RESOLVE_IPV4: Resolve IPv4 addresses [2020-12-01 17:20:56.631 3439M] DBINTERVAL: saving to DB file every minute [2020-12-01 17:20:56.631 3439M] DBFILE: Using /etc/pihole/pihole-FTL.db [2020-12-01 17:20:56.632 3439M] MAXLOGAGE: Importing up to 24.0 hours of log data [2020-12-01 17:20:56.632 3439M] PRIVACYLEVEL: Set to 0 [2020-12-01 17:20:56.632 3439M] IGNORE_LOCALHOST: Show queries from localhost [2020-12-01 17:20:56.632 3439M] BLOCKINGMODE: Null IPs for blocked domains [2020-12-01 17:20:56.632 3439M] ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries [2020-12-01 17:20:56.632 3439M] DBIMPORT: Importing history from database [2020-12-01 17:20:56.632 3439M] PIDFILE: Using /run/pihole-FTL.pid [2020-12-01 17:20:56.632 3439M] PORTFILE: Using /run/pihole-FTL.port [2020-12-01 17:20:56.633 3439M] SOCKETFILE: Using /run/pihole/FTL.sock [2020-12-01 17:20:56.633 3439M] SETUPVARSFILE: Using /etc/pihole/setupVars.conf [2020-12-01 17:20:56.633 3439M] MACVENDORDB: Using /etc/pihole/macvendor.db [2020-12-01 17:20:56.633 3439M] GRAVITYDB: Using /etc/pihole/gravity.db [2020-12-01 17:20:56.633 3439M] PARSE_ARP_CACHE: Active [2020-12-01 17:20:56.633 3439M] CNAME_DEEP_INSPECT: Active [2020-12-01 17:20:56.633 3439M] DELAY_STARTUP: No delay requested. [2020-12-01 17:20:56.634 3439M] NICE: Set process niceness to -10 (default) [2020-12-01 17:20:56.634 3439M] BLOCK_ESNI: Enabled, blocking _esni.{blocked domain} [2020-12-01 17:20:56.634 3439M] NAMES_FROM_NETDB: Enabled, trying to get names from network database [2020-12-01 17:20:56.634 3439M] Finished config file parsing [2020-12-01 17:20:56.636 3439M] Database version is 9 [2020-12-01 17:20:56.636 3439M] Database successfully initialized [2020-12-01 17:20:56.637 3439M] New upstream server: 2606:4700:4700::1001 (0/1024) [2020-12-01 17:20:56.641 3439M] Resizing "/FTL-strings" from 4096 to 8192 [2020-12-01 17:20:56.649 3439M] New upstream server: 1.0.0.1 (1/1024) [2020-12-01 17:20:56.655 3439M] Resizing "/FTL-strings" from 8192 to 12288 [2020-12-01 17:20:56.673 3439M] Resizing "/FTL-strings" from 12288 to 16384 [2020-12-01 17:20:56.703 3439M] Resizing "/FTL-strings" from 16384 to 20480 [2020-12-01 17:20:56.711 3439M] Resizing "/FTL-queries" from 229376 to 458752 [2020-12-01 17:20:56.740 3439M] New upstream server: 2606:4700:4700::1111 (2/1024) [2020-12-01 17:20:56.752 3439M] Resizing "/FTL-strings" from 20480 to 24576 [2020-12-01 17:20:56.787 3439M] Resizing "/FTL-strings" from 24576 to 28672 [2020-12-01 17:20:56.807 3439M] Resizing "/FTL-queries" from 458752 to 688128 [2020-12-01 17:20:56.850 3439M] Resizing "/FTL-strings" from 28672 to 32768 [2020-12-01 17:20:56.867 3439M] New upstream server: 1.1.1.1 (3/1024) [2020-12-01 17:20:56.896 3439M] Resizing "/FTL-queries" from 688128 to 917504 [2020-12-01 17:20:56.980 3439M] Resizing "/FTL-queries" from 917504 to 1146880 [2020-12-01 17:20:57.004 3439M] Resizing "/FTL-strings" from 32768 to 36864 [2020-12-01 17:20:57.092 3439M] Resizing "/FTL-queries" from 1146880 to 1376256 [2020-12-01 17:20:57.096 3439M] Resizing "/FTL-strings" from 36864 to 40960 [2020-12-01 17:20:57.201 3439M] Resizing "/FTL-queries" from 1376256 to 1605632 [2020-12-01 17:20:57.253 3439M] Resizing "/FTL-strings" from 40960 to 45056 [2020-12-01 17:20:57.281 3439M] Resizing "/FTL-queries" from 1605632 to 1835008 [2020-12-01 17:20:57.368 3439M] Resizing "/FTL-queries" from 1835008 to 2064384 [2020-12-01 17:20:57.436 3439M] Resizing "/FTL-queries" from 2064384 to 2293760 [2020-12-01 17:20:57.499 3439M] Resizing "/FTL-strings" from 45056 to 49152 [2020-12-01 17:20:57.508 3439M] Resizing "/FTL-strings" from 49152 to 53248 [2020-12-01 17:20:57.521 3439M] Resizing "/FTL-queries" from 2293760 to 2523136 [2020-12-01 17:20:57.572 3439M] Resizing "/FTL-strings" from 53248 to 57344 [2020-12-01 17:20:57.649 3439M] Resizing "/FTL-queries" from 2523136 to 2752512 [2020-12-01 17:20:57.694 3439M] Resizing "/FTL-strings" from 57344 to 61440 [2020-12-01 17:20:57.772 3439M] Resizing "/FTL-queries" from 2752512 to 2981888 [2020-12-01 17:20:57.845 3439M] Resizing "/FTL-strings" from 61440 to 65536 [2020-12-01 17:20:57.890 3439M] Resizing "/FTL-queries" from 2981888 to 3211264 [2020-12-01 17:20:57.985 3439M] New upstream server: 2606:4700:4700::1001#53 (4/1024) [2020-12-01 17:20:57.986 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.986 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.987 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.987 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.987 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.987 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.988 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.988 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.989 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.989 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.989 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.989 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.990 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.990 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.991 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:57.991 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:57.993 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:57.993 3439M] New upstream server: 2606:4700:4700::1111#53 (5/1024) [2020-12-01 17:20:58.013 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.015 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.016 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.016 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.016 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.017 3439M] Resizing "/FTL-queries" from 3211264 to 3440640 [2020-12-01 17:20:58.026 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.026 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.026 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.026 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.028 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.028 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.029 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.029 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.030 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.031 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.031 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.031 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.032 3439M] Resizing "/FTL-strings" from 65536 to 69632 [2020-12-01 17:20:58.033 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.033 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.033 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.033 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.039 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.039 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.040 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.040 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.040 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.040 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.042 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.042 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.042 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.042 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.043 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.043 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.044 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.044 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.045 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.045 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.045 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.045 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.046 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.046 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.047 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.047 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.049 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.049 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.049 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.049 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.050 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.050 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.051 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.051 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.059 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.059 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.059 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.060 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.060 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.066 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.075 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.075 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.082 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.102 3439M] Resizing "/FTL-strings" from 69632 to 73728 [2020-12-01 17:20:58.102 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.102 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.103 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.103 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.109 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.110 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.110 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.110 3439M] New upstream server: 1.0.0.1#53 (6/1024) [2020-12-01 17:20:58.111 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.117 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.117 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.117 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.117 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.118 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.118 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.124 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.124 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.127 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.132 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.132 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.133 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.133 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.135 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.135 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.135 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.135 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.136 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.136 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.158 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.158 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.159 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.159 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.172 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.183 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.195 3439M] Resizing "/FTL-queries" from 3440640 to 3670016 [2020-12-01 17:20:58.200 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.200 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.200 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.200 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.201 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.201 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.202 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.202 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.202 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.202 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.202 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.202 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.203 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.203 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.203 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.204 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.205 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.205 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.205 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.205 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.205 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.205 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.206 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.206 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.206 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.206 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.220 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.220 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.222 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.222 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.224 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.230 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.231 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.233 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.233 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.239 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.241 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.242 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.244 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.245 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.245 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.251 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.251 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.255 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.255 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.258 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.258 3439M] FTL_db warn: STATUS should be within [0,11] but is 12 [2020-12-01 17:20:58.260 3439M] SQLite3 message: bind on a busy prepared statement: [SELECT * FROM queries WHERE timestamp >= 1606756856] (21) [2020-12-01 17:20:58.260 3439M] SQLite3 message: misuse at line 83855 of [3bfa9cc97d] (21) [2020-12-01 17:20:58.260 3439M] Imported 62794 queries from the long-term database [2020-12-01 17:20:58.262 3439M] -> Total DNS queries: 62794 [2020-12-01 17:20:58.262 3439M] -> Cached DNS queries: 10055 [2020-12-01 17:20:58.262 3439M] -> Forwarded DNS queries: 28318 [2020-12-01 17:20:58.262 3439M] -> Blocked DNS queries: 24418 [2020-12-01 17:20:58.262 3439M] -> Unknown DNS queries: 3 [2020-12-01 17:20:58.262 3439M] -> Unique domains: 2759 [2020-12-01 17:20:58.262 3439M] -> Unique clients: 11 [2020-12-01 17:20:58.262 3439M] -> Known forward destinations: 7 [2020-12-01 17:20:58.262 3439M] Successfully accessed setupVars.conf [2020-12-01 17:20:58.267 3441M] PID of FTL process: 3441 [2020-12-01 17:20:58.268 3441/T3442] Listening on port 4711 for incoming IPv4 telnet connections [2020-12-01 17:20:58.272 3441/T3444] Listening on Unix socket [2020-12-01 17:20:58.274 3441/T3443] Listening on port 4711 for incoming IPv6 telnet connections [2020-12-01 17:20:58.274 3441M] Reloading DNS cache [2020-12-01 17:20:58.275 3441M] Blocking status is enabled [2020-12-01 17:20:58.986 3441M] Compiled 2 whitelist and 2 blacklist regex filters for 11 clients in 6.9 msec [2020-12-01 17:21:03.971 3441/T3447] SQLite3 message: no such column: name in "SELECT name FROM network WHERE id = (SELECT network_id FROM network_addresses WHERE ip = ?);" (1) [2020-12-01 17:21:03.971 3441/T3447] getDatabaseHostname("192.168.1.101") - SQL error prepare: SQL logic error [2020-12-01 17:21:03.997 3441M] Resizing "/FTL-strings" from 73728 to 77824 [2020-12-01 17:21:18.673 3441M] Resizing "/FTL-dns-cache" from 4096 to 8192 ```

DL6ER commented 3 years ago

Oh, you're still using an old version of FTL, this makes sense because the underling database structure has evolved since back in the days.

[2020-12-01 17:20:56.630 3439M] FTL branch: release/v5.1.1

Please run

pihole checkout master

to get back on track with the most recent versions of Pi-hole

jeremych1000 commented 3 years ago

@DL6ER Sorry, you're right, that's after I tried to downgrade pihole - the newest version still crashes for me after 5 minutes.

DL6ER commented 3 years ago

With the same SQL errors?

jeremych1000 commented 3 years ago

On latest master, tailing the log file:

``` [2020-12-01 17:31:36.998 5151M] Reloading DNS cache [2020-12-01 17:31:36.998 5151M] Blocking status is enabled [2020-12-01 17:31:37.869 5151/T5155] Compiled 2 whitelist and 2 blacklist regex filters for 11 clients in 23.8 msec [2020-12-01 17:31:55.624 5151M] Reloading DNS cache [2020-12-01 17:31:55.625 5151M] Blocking status is enabled [2020-12-01 17:31:56.747 5151/T5155] SQLite3 message: file unlinked while open: /etc/pihole/gravity.db (28) [2020-12-01 17:31:56.763 5151/T5155] Compiled 2 whitelist and 2 blacklist regex filters for 11 clients in 12.3 msec [2020-12-01 17:38:41.263 5692M] Using log file /var/log/pihole-FTL.log ***************** --- DNS QUERIES ARE UNRESPONSIVE HERE, HAD TO DO pihole restartdns ***************** [2020-12-01 17:38:41.263 5692M] ########## FTL started! ########## [2020-12-01 17:38:41.263 5692M] FTL branch: master [2020-12-01 17:38:41.263 5692M] FTL version: v5.3.1 [2020-12-01 17:38:41.264 5692M] FTL commit: e1db31d [2020-12-01 17:38:41.264 5692M] FTL date: 2020-11-28 21:59:12 +0100 [2020-12-01 17:38:41.264 5692M] FTL user: pihole [2020-12-01 17:38:41.264 5692M] Compiled for armv7hf (compiled on CI) using arm-linux-gnueabihf-gcc (Debian 6.3.0-18) 6.3.0 20170516 ```

Had to also restart FTL couple of times:

``` root@jeremy-rpi:/etc/.pihole# pihole restartdns [i] Restarting DNS server... [✗] Job for pihole-FTL.service failed because the control process exited with error code. See "systemctl status pihole-FTL.service" and "journalctl -xe" for details. root@jeremy-rpi:/etc/.pihole# root@jeremy-rpi:/etc/.pihole# systemctl status pihole-FTL.service ● pihole-FTL.service - LSB: pihole-FTL daemon Loaded: loaded (/etc/init.d/pihole-FTL; generated; vendor preset: enabled) Active: failed (Result: exit-code) since Tue 2020-12-01 17:38:09 GMT; 5s ago Docs: man:systemd-sysv-generator(8) Process: 5574 ExecStop=/etc/init.d/pihole-FTL stop (code=exited, status=1/FAILURE) Process: 5591 ExecStart=/etc/init.d/pihole-FTL start (code=exited, status=1/FAILURE) Dec 01 17:38:04 jeremy-rpi systemd[1]: Starting LSB: pihole-FTL daemon... Dec 01 17:38:09 jeremy-rpi pihole-FTL[5591]: ..... Dec 01 17:38:09 jeremy-rpi pihole-FTL[5591]: Not stopped; may still be shutting down or shutdown Dec 01 17:38:09 jeremy-rpi systemd[1]: pihole-FTL.service: Control process exited, code=exited st Dec 01 17:38:09 jeremy-rpi systemd[1]: Failed to start LSB: pihole-FTL daemon. Dec 01 17:38:09 jeremy-rpi systemd[1]: pihole-FTL.service: Unit entered failed state. Dec 01 17:38:09 jeremy-rpi systemd[1]: pihole-FTL.service: Failed with result 'exit-code'. ...skipping... ● pihole-FTL.service - LSB: pihole-FTL daemon Loaded: loaded (/etc/init.d/pihole-FTL; generated; vendor preset: enabled) Active: failed (Result: exit-code) since Tue 2020-12-01 17:38:09 GMT; 5s ago Docs: man:systemd-sysv-generator(8) Process: 5574 ExecStop=/etc/init.d/pihole-FTL stop (code=exited, status=1/FAILURE) Process: 5591 ExecStart=/etc/init.d/pihole-FTL start (code=exited, status=1/FAILURE) Dec 01 17:38:04 jeremy-rpi systemd[1]: Starting LSB: pihole-FTL daemon... Dec 01 17:38:09 jeremy-rpi pihole-FTL[5591]: ..... Dec 01 17:38:09 jeremy-rpi pihole-FTL[5591]: Not stopped; may still be shutting down or shutdown Dec 01 17:38:09 jeremy-rpi systemd[1]: pihole-FTL.service: Control process exited, code=exited st Dec 01 17:38:09 jeremy-rpi systemd[1]: Failed to start LSB: pihole-FTL daemon. Dec 01 17:38:09 jeremy-rpi systemd[1]: pihole-FTL.service: Unit entered failed state. Dec 01 17:38:09 jeremy-rpi systemd[1]: pihole-FTL.service: Failed with result 'exit-code'. ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ root@jeremy-rpi:/etc/.pihole# pihole restartdns [✗] Job for pihole-FTL.service failed because the control process exited with error code. See "systemctl status pihole-FTL.service" and "journalctl -xe" for details. root@jeremy-rpi:/etc/.pihole# pihole restartdns [✓] Restarting DNS server ```

DL6ER commented 3 years ago

This does not yet contain anything pointing us to the source of the problem. Is there anything interesting in /var/log/pihole.log ?

jeremych1000 commented 3 years ago

This does not yet contain anything pointing us to the source of the problem. Is there anything interesting in /var/log/pihole.log ?

I was looking, but no obvious crashing logs. DNS queries just completely fail until I successfully run pihole restartdns.

I'm trying to look at any logs in /var/log/pihole.log, but nothing interesting really.

DL6ER commented 3 years ago

What did you do in between these messages:

[2020-12-01 17:31:36.998 5151M] Reloading DNS cache
[2020-12-01 17:31:36.998 5151M] Blocking status is enabled
[2020-12-01 17:31:37.869 5151/T5155] Compiled 2 whitelist and 2 blacklist regex filters for 11 clients in 23.8 msec

<----->

[2020-12-01 17:31:55.624 5151M] Reloading DNS cache
[2020-12-01 17:31:55.625 5151M] Blocking status is enabled

I suppose you ran pihole -g.

Is there anything you can do to reliably trigger this or is Pi-hole just getting unresponsive after having worked correctly for some time?

jeremych1000 commented 3 years ago

Is there anything you can do to reliably trigger this or is Pi-hole just getting unresponsive after having worked correctly for some time?

It turned unresponsive and websites wouldn't load because dns wasn't resolved.

Currently it's running fine for the last 15 minutes (of course it is after I comment on a github issue :P), will post here again if it crashes.

DL6ER commented 3 years ago

Okay, let's see. Point is that I haven't seen anything really pointing towards a crash. Maybe it is rather like a deadlock scenario, however, I haven't seen one in a very long time (this does not mean there are none left, maybe you just hit the super-edgecase).

jeremych1000 commented 3 years ago

DNS queries failed just now, there's one FATAL log line but upon googling it seems to be fixed in https://github.com/pi-hole/FTL/pull/671

Here's the tail of /var/log/pihole-FTL.log

``` [2020-12-03 11:53:42.436 6625/F5694] Resizing "FTL-dns-cache" from 139264 to (8960 * 16) == 143360 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 11:53:43.129 5694M] Remapping "FTL-dns-cache" from 139264 to (8960 * 16) == 143360 [2020-12-03 11:59:00.818 5694/T5698] Notice: Database size is 3697.50 MB, deleted 663 rows [2020-12-03 13:00:02.711 5694/T5698] Notice: Database size is 3697.50 MB, deleted 718 rows [2020-12-03 13:02:35.054 5694M] Resizing "FTL-strings" from 155648 to (159744 * 1) == 159744 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 13:07:04.397 5694M] Resizing "FTL-dns-cache" from 143360 to (9216 * 16) == 147456 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 14:00:01.423 5694/T5698] Notice: Database size is 3697.50 MB, deleted 713 rows [2020-12-03 14:10:01.537 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 14:10:01.604 5694M] Resizing "FTL-dns-cache" from 147456 to (9472 * 16) == 151552 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 14:10:01.605 5694M] FATAL: realloc_shm(): Failed to resize "FTL-dns-cache" (26) to 151552: Interrupted system call (-1) ```

and here's the pihole debug log (I did it while DNS queries weren't working):

``` This process collects information from your Pi-hole, and optionally uploads it to a unique and random directory on tricorder.pi-hole.net. The intent of this script is to allow users to self-diagnose their installations. This is accomplished by running tests against our software and providing the user with links to FAQ articles when a problem is detected. Since we are a small team and Pi-hole has been growing steadily, it is our hope that this will help us spend more time on development. NOTE: All log files auto-delete after 48 hours and ONLY the Pi-hole developers can access your data via the given token. We have taken these extra steps to secure your data and will work to further reduce any personal information gathered. *** [ INITIALIZING ] [i] 2020-12-03:14:10:26 debug log has been initialized. *** [ INITIALIZING ] Sourcing setup variables [i] Sourcing /etc/pihole/setupVars.conf... *** [ DIAGNOSING ]: Core version [i] Core: v5.2 (https://discourse.pi-hole.net/t/how-do-i-update-pi-hole/249) [i] Remotes: origin https://github.com/pi-hole/pi-hole.git (fetch) origin https://github.com/pi-hole/pi-hole.git (push) [i] Branch: master [i] Commit: v5.2-0-gfee1b8b7 *** [ DIAGNOSING ]: Web version [i] Web: v5.2 (https://discourse.pi-hole.net/t/how-do-i-update-pi-hole/249) [i] Remotes: origin https://github.com/pi-hole/AdminLTE.git (fetch) origin https://github.com/pi-hole/AdminLTE.git (push) [i] Branch: master [i] Commit: v5.2-0-g2c2d9f5f *** [ DIAGNOSING ]: FTL version [✓] FTL: v5.3.1 (https://discourse.pi-hole.net/t/how-do-i-update-pi-hole/249) *** [ DIAGNOSING ]: lighttpd version [i] 1.4.45 *** [ DIAGNOSING ]: php version [i] 7.0.33 *** [ DIAGNOSING ]: Operating system [i] dig return code: 10 [i] dig response: dig: couldn't get address for 'ns1.pi-hole.net': failure [✗] Distro: Raspbian [✗] Error: Raspbian is not a supported distro (https://docs.pi-hole.net/main/prerequisites/) *** [ DIAGNOSING ]: SELinux [i] SELinux not detected *** [ DIAGNOSING ]: FirewallD [i] Firewalld service inactive *** [ DIAGNOSING ]: Processor [✓] armv7l *** [ DIAGNOSING ]: Networking [✓] IPv4 address(es) bound to the eth0 interface: 192.168.1.253/24 matches the IP found in /etc/pihole/setupVars.conf [✓] IPv6 address(es) bound to the eth0 interface: 2a00:23c6:f08a:ab01:f121:ab4f:31a1:8c13 does not match the IP found in /etc/pihole/setupVars.conf (https://discourse.pi-hole.net/t/use-ipv6-ula-addresses-for-pi-hole/2127) fe80::7456:9a79:20b0:ee49 does not match the IP found in /etc/pihole/setupVars.conf (https://discourse.pi-hole.net/t/use-ipv6-ula-addresses-for-pi-hole/2127) ^ Please note that you may have more than one IP address listed. As long as one of them is green, and it matches what is in /etc/pihole/setupVars.conf, there is no need for concern. The link to the FAQ is for an issue that sometimes occurs when the IPv6 address changes, which is why we check for it. [i] Default IPv4 gateway: 192.168.1.254 * Pinging 192.168.1.254... [✓] Gateway responded. [i] Default IPv6 gateway: fe80::e8e:29ff:fe1b:cf18 * Pinging fe80::e8e:29ff:fe1b:cf18... [✓] Gateway responded. *** [ DIAGNOSING ]: Ports in use *:5900 vncserver- (IPv6) *:5900 vncserver- (IPv4) *:36253 librespot (IPv4) *:22 sshd (IPv4) *:22 sshd (IPv6) [80] is in use by lighttpd [80] is in use by lighttpd *** [ DIAGNOSING ]: Name resolution (IPv4) using a random blocked domain and a known ad-serving domain [✗] Failed to resolve zap352660-1.plesk05.zap-webspace.com via localhost (127.0.0.1) [✗] Failed to resolve zap352660-1.plesk05.zap-webspace.com via Pi-hole (192.168.1.253) [✓] doubleclick.com is 216.58.211.174 via a remote, public DNS server (8.8.8.8) *** [ DIAGNOSING ]: Name resolution (IPv6) using a random blocked domain and a known ad-serving domain [✗] Failed to resolve jgoode7.busa345.com via localhost (::1) [✗] Failed to resolve jgoode7.busa345.com via Pi-hole (fdaa:bbcc:ddee:0:8e3f:c85c:59c7:8ca8) [✓] doubleclick.com is 2a00:1450:4009:800::200e via a remote, public DNS server (2001:4860:4860::8888) *** [ DIAGNOSING ]: Discovering active DHCP servers (takes 10 seconds) Scanning all your interfaces for DHCP servers Timeout: 10 seconds DHCP packets received on interface lo: 0 DHCP packets received on interface wlan0: 0 DHCP packets received on interface eth0: 0 *** [ DIAGNOSING ]: Pi-hole processes [✓] lighttpd daemon is active [✓] pihole-FTL daemon is active *** [ DIAGNOSING ]: Pi-hole-FTL full status ● pihole-FTL.service - LSB: pihole-FTL daemon Loaded: loaded (/etc/init.d/pihole-FTL; generated; vendor preset: enabled) Active: active (exited) since Tue 2020-12-01 17:38:42 GMT; 1 day 20h ago Docs: man:systemd-sysv-generator(8) Process: 5574 ExecStop=/etc/init.d/pihole-FTL stop (code=exited, status=1/FAILURE) Process: 5661 ExecStart=/etc/init.d/pihole-FTL start (code=exited, status=0/SUCCESS) Tasks: 0 (limit: 4915) CGroup: /system.slice/pihole-FTL.service Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. *** [ DIAGNOSING ]: Setup variables CONDITIONAL_FORWARDING=false DNSMASQ_LISTENING=single PIHOLE_DNS_3=2606:4700:4700::1111 PIHOLE_DNS_4=2606:4700:4700::1001 DNS_FQDN_REQUIRED=true DNS_BOGUS_PRIV=true DNSSEC=false REV_SERVER=false ADMIN_EMAIL= WEBUIBOXEDLAYOUT=boxed WEBTHEME=default-light DHCP_ACTIVE=true DHCP_START=192.168.1.64 DHCP_END=192.168.1.252 DHCP_ROUTER=192.168.1.254 DHCP_LEASETIME=24 PIHOLE_DOMAIN=lan DHCP_IPv6=false DHCP_rapid_commit=false BLOCKING_ENABLED=true PIHOLE_INTERFACE=eth0 IPV4_ADDRESS=192.168.1.253/24 IPV6_ADDRESS=fdaa:bbcc:ddee:0:8e3f:c85c:59c7:8ca8 PIHOLE_DNS_1=1.1.1.1 PIHOLE_DNS_2=1.0.0.1 QUERY_LOGGING=true INSTALL_WEB_SERVER=true INSTALL_WEB_INTERFACE=true LIGHTTPD_ENABLED=true CACHE_SIZE=10000 *** [ DIAGNOSING ]: Dashboard and block page [✗] Block page X-Header: X-Header does not match or could not be retrieved. HTTP/1.1 200 OK Content-type: text/html; charset=UTF-8 Expires: Thu, 03 Dec 2020 14:10:47 GMT Cache-Control: max-age=0 Date: Thu, 03 Dec 2020 14:10:47 GMT Server: lighttpd/1.4.45 [✓] Web interface X-Header: X-Pi-hole: The Pi-hole Web interface is working! *** [ DIAGNOSING ]: Gravity List and Database -rw-rw-r-- 1 pihole pihole 6598656 Dec 1 17:31 /etc/pihole/gravity.db *** [ DIAGNOSING ]: Info table property value -------------------- ---------------------------------------- version 13 updated 1606843912 gravity_count 98280 Last gravity run finished at: Tue Dec 1 17:31:52 GMT 2020 ----- First 10 Gravity Domains ----- localhost.localdomain n2019cov.000webhostapp.com webmail-who-int.000webhostapp.com 010sec.com 01mspmd5yalky8.com 0byv9mgbn0.com ns6.0pendns.org dns.0pengl.com ios.0pengl.com 0x4fc271.tk *** [ DIAGNOSING ]: Groups id enabled name date_added date_modified description ---- ------- -------------------------------------------------- ------------------- ------------------- -------------------------------------------------- 0 1 Default 2020-05-27 15:14:56 2020-05-27 15:14:56 The default group *** [ DIAGNOSING ]: Domainlist (0/1 = exact white-/blacklist, 2/3 = regex white-/blacklist) id type enabled group_ids domain date_added date_modified comment ---- ---- ------- ------------ ---------------------------------------------------------------------------------------------------- ------------------- ------------------- -------------------------------------------------- 1 0 1 0 raw.githubusercontent.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 2 0 1 0 mirror1.malwaredomains.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 3 0 1 0 sysctl.org 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 4 0 1 0 zeustracker.abuse.ch 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 5 0 1 0 s3.amazonaws.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 6 0 1 0 hosts-file.net 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 7 0 1 0 binance.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 8 0 1 0 track.webgains.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 9 0 1 0 api.spotify.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 10 0 1 0 spclient.wg.spotify.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 11 0 1 0 click.aliexpress.com 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/whitelist.txt 14 3 1 0 (^|\.)redshell\.io$ 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/regex.list 15 3 1 0 (^|\.)treasuredata\.com$ 2020-05-27 15:14:57 2020-05-27 15:14:57 Migrated from /etc/pihole/regex.list 16 2 1 0 (\.|^)datadoghq\.com$ 2020-05-29 01:45:41 2020-05-29 01:45:41 18 2 1 0 (\.|^)ojrq\.net$ 2020-09-23 15:26:38 2020-09-23 15:26:38 *** [ DIAGNOSING ]: Clients *** [ DIAGNOSING ]: Adlists id enabled group_ids address date_added date_modified comment ---- ------- ------------ ---------------------------------------------------------------------------------------------------- ------------------- ------------------- -------------------------------------------------- 1 1 0 https://raw.githubusercontent.com/StevenBlack/hosts/master/hosts 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list 2 1 0 https://mirror1.malwaredomains.com/files/justdomains 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list 3 1 0 http://sysctl.org/cameleon/hosts 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list 4 1 0 https://zeustracker.abuse.ch/blocklist.php?download=domainblocklist 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list 5 1 0 https://s3.amazonaws.com/lists.disconnect.me/simple_tracking.txt 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list 6 1 0 https://s3.amazonaws.com/lists.disconnect.me/simple_ad.txt 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list 7 1 0 https://hosts-file.net/ad_servers.txt 2020-05-27 15:14:56 2020-05-27 15:14:56 Migrated from /etc/pihole/adlists.list *** [ DIAGNOSING ]: contents of /etc/pihole -rw-r--r-- 1 root root 140 Dec 1 17:31 /etc/pihole/local.list 192.168.1.253 jeremy-rpi fdaa:bbcc:ddee:0:8e3f:c85c:59c7:8ca8 jeremy-rpi 192.168.1.253 pi.hole fdaa:bbcc:ddee:0:8e3f:c85c:59c7:8ca8 pi.hole -rw-r--r-- 1 root root 234 Dec 1 17:30 /etc/pihole/logrotate /var/log/pihole.log { su root root daily copytruncate rotate 5 compress delaycompress notifempty nomail } /var/log/pihole-FTL.log { su root root weekly copytruncate rotate 3 compress delaycompress notifempty nomail } -rw-rw-r-- 1 pihole pihole 15 Dec 1 17:31 /etc/pihole/pihole-FTL.conf PRIVACYLEVEL=0 *** [ DIAGNOSING ]: contents of /etc/dnsmasq.d -rw-r--r-- 1 root root 1479 Dec 1 17:31 /etc/dnsmasq.d/01-pihole.conf addn-hosts=/etc/pihole/local.list addn-hosts=/etc/pihole/custom.list localise-queries no-resolv cache-size=10000 log-queries log-facility=/var/log/pihole.log local-ttl=2 log-async server=1.1.1.1 server=1.0.0.1 server=2606:4700:4700::1111 server=2606:4700:4700::1001 domain-needed expand-hosts bogus-priv interface=eth0 server=/use-application-dns.net/ -rw-r--r-- 1 root root 496 Dec 1 17:31 /etc/dnsmasq.d/02-pihole-dhcp.conf dhcp-authoritative dhcp-range=192.168.1.64,192.168.1.252,24h dhcp-option=option:router,192.168.1.254 dhcp-leasefile=/etc/pihole/dhcp.leases domain=lan local=/lan/ *** [ DIAGNOSING ]: contents of /etc/lighttpd -rw-r--r-- 1 root root 0 Dec 1 17:30 /etc/lighttpd/external.conf -rw-r--r-- 1 root root 4066 Dec 1 17:30 /etc/lighttpd/lighttpd.conf server.modules = ( "mod_access", "mod_accesslog", "mod_auth", "mod_expire", "mod_compress", "mod_redirect", "mod_setenv", "mod_rewrite" ) server.document-root = "/var/www/html" server.error-handler-404 = "/pihole/index.php" server.upload-dirs = ( "/var/cache/lighttpd/uploads" ) server.errorlog = "/var/log/lighttpd/error.log" server.pid-file = "/run/lighttpd.pid" server.username = "www-data" server.groupname = "www-data" server.port = 80 accesslog.filename = "/var/log/lighttpd/access.log" accesslog.format = "%{%s}t|%V|%r|%s|%b" index-file.names = ( "index.php", "index.html", "index.lighttpd.html" ) url.access-deny = ( "~", ".inc", ".md", ".yml", ".ini" ) static-file.exclude-extensions = ( ".php", ".pl", ".fcgi" ) compress.cache-dir = "/var/cache/lighttpd/compress/" compress.filetype = ( "application/json", "application/vnd.ms-fontobject", "application/xml", "font/eot", "font/opentype", "font/otf", "font/ttf", "image/bmp", "image/svg+xml", "image/vnd.microsoft.icon", "image/x-icon", "text/css", "text/html", "text/javascript", "text/plain", "text/xml" ) mimetype.assign = ( ".ico" => "image/x-icon", ".jpeg" => "image/jpeg", ".jpg" => "image/jpeg", ".png" => "image/png", ".svg" => "image/svg+xml", ".css" => "text/css; charset=utf-8", ".html" => "text/html; charset=utf-8", ".js" => "text/javascript; charset=utf-8", ".json" => "application/json; charset=utf-8", ".map" => "application/json; charset=utf-8", ".txt" => "text/plain; charset=utf-8", ".eot" => "application/vnd.ms-fontobject", ".otf" => "font/otf", ".ttc" => "font/collection", ".ttf" => "font/ttf", ".woff" => "font/woff", ".woff2" => "font/woff2" ) include_shell "/usr/share/lighttpd/use-ipv6.pl " + server.port include_shell "find /etc/lighttpd/conf-enabled -name '*.conf' -a ! -name 'letsencrypt.conf' -printf 'include \"%p\" ' 2>/dev/null" $HTTP["url"] =~ "^/admin/" { setenv.add-response-header = ( "X-Pi-hole" => "The Pi-hole Web interface is working!", "X-Frame-Options" => "DENY" ) $HTTP["url"] =~ "\.(eot|otf|tt[cf]|woff2?)$" { setenv.add-response-header = ( "Access-Control-Allow-Origin" => "*" ) } } $HTTP["url"] =~ "^/admin/\.(.*)" { url.access-deny = ("") } expire.url = ( "" => "access plus 0 seconds" ) include_shell "cat external.conf 2>/dev/null" *** [ DIAGNOSING ]: contents of /etc/cron.d -rw-r--r-- 1 root root 1755 Dec 1 17:30 /etc/cron.d/pihole 11 3 * * 7 root PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updateGravity >/var/log/pihole_updateGravity.log || cat /var/log/pihole_updateGravity.log 00 00 * * * root PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole flush once quiet @reboot root /usr/sbin/logrotate /etc/pihole/logrotate */10 * * * * root PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local 55 13 * * * root PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker remote @reboot root PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker remote reboot *** [ DIAGNOSING ]: contents of /var/log/lighttpd -rw-r--r-- 1 www-data www-data 3232 Dec 3 14:10 /var/log/lighttpd/error.log -----head of error.log------ 2020-11-30 06:25:03: (server.c.1534) logfiles cycled UID = 0 PID = 28619 2020-12-01 15:23:18: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 15:23:19: (log.c.217) server started 2020-12-01 15:23:19: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 16:16:56: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 16:18:34: (log.c.217) server started 2020-12-01 16:18:34: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 16:53:19: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-01 16:53:19: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-01 16:54:17: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 16:54:27: (log.c.217) server started 2020-12-01 16:54:27: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 16:55:33: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 16:55:47: (log.c.217) server started 2020-12-01 16:55:47: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 17:23:08: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-01 17:23:08: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-01 17:31:26: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 17:31:27: (log.c.217) server started 2020-12-01 17:31:27: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 17:46:00: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-01 17:46:00: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-02 06:25:03: (server.c.1534) logfiles cycled UID = 0 PID = 26638 2020-12-02 10:09:38: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-02 10:09:38: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 -----tail of error.log------ 2020-12-01 16:18:34: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 16:53:19: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-01 16:53:19: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-01 16:54:17: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 16:54:27: (log.c.217) server started 2020-12-01 16:54:27: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 16:55:33: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 16:55:47: (log.c.217) server started 2020-12-01 16:55:47: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 17:23:08: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-01 17:23:08: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-01 17:31:26: (server.c.1828) server stopped by UID = 0 PID = 1 2020-12-01 17:31:27: (log.c.217) server started 2020-12-01 17:31:27: (server.c.1295) WARNING: unknown config-key: alias.url (ignored) 2020-12-01 17:46:00: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-01 17:46:00: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-02 06:25:03: (server.c.1534) logfiles cycled UID = 0 PID = 26638 2020-12-02 10:09:38: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-02 10:09:38: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-03 14:05:41: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-03 14:05:41: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-03 14:10:47: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-03 14:10:47: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 2020-12-03 14:10:47: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: viewPort in /var/www/html/pihole/index.php on line 73 2020-12-03 14:10:47: (mod_fastcgi.c.2543) FastCGI-stderr: PHP Notice: Undefined variable: serverName in /var/www/html/pihole/index.php on line 74 *** [ DIAGNOSING ]: contents of /var/log -rw-r--r-- 1 pihole pihole 2919 Dec 3 14:10 /var/log/pihole-FTL.log -----head of pihole-FTL.log------ [2020-12-03 00:59:01.442 5694/T5698] Notice: Database size is 3697.50 MB, deleted 3224 rows [2020-12-03 02:00:00.338 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1700 rows [2020-12-03 02:06:07.506 5694M] Resizing "FTL-dns-cache" from 131072 to (8448 * 16) == 135168 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 02:59:00.436 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1246 rows [2020-12-03 03:59:00.298 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1266 rows [2020-12-03 04:59:00.751 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1248 rows [2020-12-03 05:59:00.434 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1301 rows [2020-12-03 06:22:01.998 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 06:45:20.174 5694M] Resizing "FTL-strings" from 147456 to (151552 * 1) == 151552 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 06:59:03.851 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1196 rows [2020-12-03 07:59:00.570 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1390 rows [2020-12-03 09:00:01.858 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1536 rows [2020-12-03 10:00:00.363 5694/T5698] Notice: Database size is 3697.50 MB, deleted 705 rows [2020-12-03 10:03:19.062 5694M] Resizing "FTL-dns-cache" from 135168 to (8704 * 16) == 139264 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 10:59:00.393 5694/T5698] Notice: Database size is 3697.50 MB, deleted 761 rows [2020-12-03 10:59:02.089 4934/F5694] Resizing "FTL-strings" from 151552 to (155648 * 1) == 155648 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 10:59:02.805 5694M] Remapping "FTL-strings" from 151552 to (155648 * 1) == 155648 [2020-12-03 11:36:04.338 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 11:53:42.436 6625/F5694] Resizing "FTL-dns-cache" from 139264 to (8960 * 16) == 143360 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 11:53:43.129 5694M] Remapping "FTL-dns-cache" from 139264 to (8960 * 16) == 143360 [2020-12-03 11:59:00.818 5694/T5698] Notice: Database size is 3697.50 MB, deleted 663 rows [2020-12-03 13:00:02.711 5694/T5698] Notice: Database size is 3697.50 MB, deleted 718 rows [2020-12-03 13:02:35.054 5694M] Resizing "FTL-strings" from 155648 to (159744 * 1) == 159744 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 13:07:04.397 5694M] Resizing "FTL-dns-cache" from 143360 to (9216 * 16) == 147456 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 14:00:01.423 5694/T5698] Notice: Database size is 3697.50 MB, deleted 713 rows [2020-12-03 14:10:01.537 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 14:10:01.604 5694M] Resizing "FTL-dns-cache" from 147456 to (9472 * 16) == 151552 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 14:10:01.605 5694M] FATAL: realloc_shm(): Failed to resize "FTL-dns-cache" (26) to 151552: Interrupted system call (-1) -----tail of pihole-FTL.log------ [2020-12-03 00:59:01.442 5694/T5698] Notice: Database size is 3697.50 MB, deleted 3224 rows [2020-12-03 02:00:00.338 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1700 rows [2020-12-03 02:06:07.506 5694M] Resizing "FTL-dns-cache" from 131072 to (8448 * 16) == 135168 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 02:59:00.436 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1246 rows [2020-12-03 03:59:00.298 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1266 rows [2020-12-03 04:59:00.751 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1248 rows [2020-12-03 05:59:00.434 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1301 rows [2020-12-03 06:22:01.998 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 06:45:20.174 5694M] Resizing "FTL-strings" from 147456 to (151552 * 1) == 151552 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 06:59:03.851 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1196 rows [2020-12-03 07:59:00.570 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1390 rows [2020-12-03 09:00:01.858 5694/T5698] Notice: Database size is 3697.50 MB, deleted 1536 rows [2020-12-03 10:00:00.363 5694/T5698] Notice: Database size is 3697.50 MB, deleted 705 rows [2020-12-03 10:03:19.062 5694M] Resizing "FTL-dns-cache" from 135168 to (8704 * 16) == 139264 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 10:59:00.393 5694/T5698] Notice: Database size is 3697.50 MB, deleted 761 rows [2020-12-03 10:59:02.089 4934/F5694] Resizing "FTL-strings" from 151552 to (155648 * 1) == 155648 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 10:59:02.805 5694M] Remapping "FTL-strings" from 151552 to (155648 * 1) == 155648 [2020-12-03 11:36:04.338 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 11:53:42.436 6625/F5694] Resizing "FTL-dns-cache" from 139264 to (8960 * 16) == 143360 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 11:53:43.129 5694M] Remapping "FTL-dns-cache" from 139264 to (8960 * 16) == 143360 [2020-12-03 11:59:00.818 5694/T5698] Notice: Database size is 3697.50 MB, deleted 663 rows [2020-12-03 13:00:02.711 5694/T5698] Notice: Database size is 3697.50 MB, deleted 718 rows [2020-12-03 13:02:35.054 5694M] Resizing "FTL-strings" from 155648 to (159744 * 1) == 159744 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 13:07:04.397 5694M] Resizing "FTL-dns-cache" from 143360 to (9216 * 16) == 147456 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 14:00:01.423 5694/T5698] Notice: Database size is 3697.50 MB, deleted 713 rows [2020-12-03 14:10:01.537 5694/T5695] IPv4 telnet error: Interrupted system call (4) [2020-12-03 14:10:01.604 5694M] Resizing "FTL-dns-cache" from 147456 to (9472 * 16) == 151552 (/dev/shm: 4.5MB used, 483.2MB total) [2020-12-03 14:10:01.605 5694M] FATAL: realloc_shm(): Failed to resize "FTL-dns-cache" (26) to 151552: Interrupted system call (-1) *** [ DIAGNOSING ]: contents of /dev/shm -rw------- 1 pihole pihole 339968 Dec 1 17:38 /dev/shm/FTL-clients -rw------- 1 pihole pihole 152 Dec 1 17:38 /dev/shm/FTL-counters -rw------- 1 pihole pihole 147456 Dec 1 17:38 /dev/shm/FTL-dns-cache -rw------- 1 pihole pihole 131072 Dec 1 17:38 /dev/shm/FTL-domains -rw------- 1 pihole pihole 28 Dec 3 14:10 /dev/shm/FTL-lock -rw------- 1 pihole pihole 20480 Dec 1 17:38 /dev/shm/FTL-overTime -rw------- 1 pihole pihole 4096 Dec 1 17:42 /dev/shm/FTL-per-client-regex -rw------- 1 pihole pihole 3670016 Dec 3 11:47 /dev/shm/FTL-queries -rw------- 1 pihole pihole 12 Dec 1 17:38 /dev/shm/FTL-settings -rw------- 1 pihole pihole 159744 Dec 3 14:10 /dev/shm/FTL-strings -rw------- 1 pihole pihole 28672 Dec 1 17:38 /dev/shm/FTL-upstreams *** [ DIAGNOSING ]: Pi-hole diagnosis messages *** [ DIAGNOSING ]: Locale LANG= *** [ DIAGNOSING ]: Pi-hole log -rw-r--r-- 1 pihole pihole 9800231 Dec 3 14:10 /var/log/pihole.log -----head of pihole.log------ Dec 3 00:00:07 dnsmasq[21068]: query[A] etorologsapi.etoro.com from 192.168.1.214 Dec 3 00:00:07 dnsmasq[21068]: forwarded etorologsapi.etoro.com to 1.0.0.1 Dec 3 00:00:07 dnsmasq[21068]: reply etorologsapi.etoro.com is Dec 3 00:00:07 dnsmasq[21068]: reply prod-client-logs.trafficmanager.net is Dec 3 00:00:07 dnsmasq[21068]: reply prod-clientlogs-w.westeurope.cloudapp.azure.com is 20.54.209.212 Dec 3 00:00:08 dnsmasq[5694]: query[AAAA] ssl.google-analytics.com from 192.168.1.183 Dec 3 00:00:08 dnsmasq[5694]: gravity blocked ssl.google-analytics.com is :: Dec 3 00:00:08 dnsmasq[5694]: query[A] ssl.google-analytics.com from 192.168.1.183 Dec 3 00:00:08 dnsmasq[5694]: gravity blocked ssl.google-analytics.com is 0.0.0.0 Dec 3 00:00:10 dnsmasq[5694]: query[AAAA] me.xdrig.com from 192.168.1.65 Dec 3 00:00:10 dnsmasq[5694]: gravity blocked me.xdrig.com is :: Dec 3 00:00:10 dnsmasq[5694]: query[A] me.xdrig.com from 192.168.1.65 Dec 3 00:00:10 dnsmasq[5694]: gravity blocked me.xdrig.com is 0.0.0.0 Dec 3 00:00:13 dnsmasq[21072]: query[A] assets.adobedtm.com from 192.168.1.214 Dec 3 00:00:13 dnsmasq[21072]: gravity blocked assets.adobedtm.com is 0.0.0.0 Dec 3 00:00:24 dnsmasq[5694]: query[A] api.apple-cloudkit.com from 192.168.1.214 Dec 3 00:00:24 dnsmasq[5694]: forwarded api.apple-cloudkit.com to 1.0.0.1 Dec 3 00:00:24 dnsmasq[5694]: reply api.apple-cloudkit.com is Dec 3 00:00:24 dnsmasq[5694]: reply api.apple-cloudkit.fe.apple-dns.net is 17.248.144.142 Dec 3 00:00:24 dnsmasq[5694]: reply api.apple-cloudkit.fe.apple-dns.net is 17.248.144.137 ******************************************** ******************************************** [✓] ** FINISHED DEBUGGING! ** * The debug log can be uploaded to tricorder.pi-hole.net for sharing with developers only. * For more information, see: https://pi-hole.net/2016/11/07/crack-our-medical-tricorder-win-a-raspberry-pi-3/ * If available, we'll use openssl to upload the log, otherwise it will fall back to netcat. * Log will NOT be uploaded to tricorder. * A local copy of the debug log can be found at: /var/log/pihole_debug.log ```

DL6ER commented 3 years ago

Interrupted system call (-1)

is something new. #671 did not fix this. Reading on this error in the context of shared memory suggests that this has to do with running out of inter-process memory. However, this doesn't seem to be the case looking at

/dev/shm: 4.5MB used, 483.2MB total

However, looking at the rest of your log, we see this a couple of times in different places:

[2020-12-03 14:10:01.537 5694/T5695] IPv4 telnet error: Interrupted system call (4)

or

[2020-12-03 11:36:04.338 5694/T5695] IPv4 telnet error: Interrupted system call (4)

and

[2020-12-03 06:22:01.998 5694/T5695] IPv4 telnet error: Interrupted system call (4)

Interrupted system call means something went wrong in the lower-level subroutines of your operating system. Did you do anything fancy? How are your disks mounted? Do you have some remote filesystems attached to your system?

Such system errors are typically hard to debug, however, we will surely try our best!

jeremych1000 commented 3 years ago

I realise I've rather hijacked OP's issue :P

In terms of the interrupted system call messages, I did do a Raspian upgrade a month ago, but pihole was running alright before updating to the latest version a couple of days ago. No fancy disk mounting.

I also saw some logs regarding cloudflared.service stopped working in journalctl -xe.

As my pi only runs a couple of things, I basically reimaged my SD card to the latest Raspian version, and reinstalled pihole on it. Hasn't crashed since, but will keep an eye out for it.

pi-hole / FTL