Have to restart FTL every now and then

Help
1

Howdy, new member but been using pihole a while now.

I don't know if it's a memory issue or what, but since last update the FTLi listener keeps shutting down or crashing with funky error.

---= Detecting existence of /var/log/lighttpd/error.log:

2017-05-14 06:25:14: (server.c.1242) logfiles cycled UID = 0 PID = 3735
2017-05-16 00:22:25: (server.c.1558) server stopped by UID = 0 PID = 1
2017-05-16 00:22:47: (log.c.164) server started
2017-05-16 00:22:47: (server.c.1045) WARNING: unknown config-key: alias.url (ignored)
2017-05-17 09:27:22: (mod_fastcgi.c.2702) FastCGI-stderr: PHP Warning: socket_read(): unable to read from socket [104]: Connection reset by peer in /var/www/html/admin/scripts/pi-hole/php/FTL.php on line 98
2017-05-17 09:27:22: (mod_fastcgi.c.2702) FastCGI-stderr: PHP Warning: socket_read(): unable to read from socket [104]: Connection reset by peer in /var/www/html/admin/scripts/pi-hole/php/FTL.php on line 98
2017-05-17 09:27:22: (mod_fastcgi.c.2702) FastCGI-stderr: PHP Warning: socket_read(): unable to read from socket [104]: Connection reset by peer in /var/www/html/admin/scripts/pi-hole/php/FTL.php on line 98

that last line repeats hundreds of times in the debug log.

here is my info:
---=== Your debug token is : 86m3gfnm9g

I know it's being looked into, just adding my debug log token just in case it may help out any or maybe not, anyhow, thanks!

Still using it though temporarily I just set bash script that checks if FTL is running or not, if not restart it. Then set a cron to run script every 30 minutes.

Only as a temporary "band-aid"

2

What version of FTL are you using?

pihole-FTL version

Should be v2.7.3

If you are already on the most recent version, we have to get serious with debugging. Are there any interesting lines in /var/log/pihole-FTL.log?

1 Like
3

Oops when my reply got split off, it doesn't restart every 30 mins, in my post I was just saying for a "bandaid" i just set the cron for 30 minutes, I never paid real close attention on timing.

It could be memory, but I have the memory split all on ram with no gpu really since it's just a headless pi box.

and I only have 133k list and cpu usage stays nice and low at that level. And it still works great, I blacklist some manually that get through.

Here is the pihole-ftl.log that looks funky, maybe memory? I dunno, I can't force it to happen. with it's setup as is.

[2017-05-16 00:22:56.691] Reading from /var/log/pihole.log (rw-r--r--)
[2017-05-16 00:22:56.717] New client: 127.0.0.1 localhost (7/10)
[2017-05-16 00:22:56.727] New client: 192.168.254.65 raspberrypi (8/10)
[2017-05-16 00:22:56.749] Finished initial log file parsing
[2017-05-16 00:22:56.749] -> Total DNS queries: 2637
[2017-05-16 00:22:56.750] -> Cached DNS queries: 505
[2017-05-16 00:22:56.750] -> Blocked DNS queries: 981
[2017-05-16 00:22:56.751] -> Unknown DNS queries: 0
[2017-05-16 00:22:56.751] -> Unique domains: 437
[2017-05-16 00:22:56.751] -> Unique clients: 9
[2017-05-16 00:22:56.752] Successfully accessed setupVars.conf
[2017-05-16 00:22:56.753] Listening on port 4711
[2017-05-16 00:24:26.876] NOTICE: pihole.log has been flushed
[2017-05-16 00:24:26.876] Resetting internal data structure
[2017-05-16 00:24:26.877] Queries in memory before flushing: 2639
[2017-05-16 00:24:27.578] Gravity list entries: 133175
[2017-05-16 00:24:27.579] Blacklist entries: 9
[2017-05-16 00:24:27.589] No wildcard blocking list present
[2017-05-16 00:24:27.590] Reading from /var/log/pihole.log.1 (rw-r--r--)
[2017-05-16 00:24:27.590] Notice: Increasing forwarded struct size from 0 to 4 (387.00 B)
[2017-05-16 00:24:27.610] New forward server: 8.8.8.8 google-public-dns-a.google.com (0/4)
[2017-05-16 00:24:27.611] Notice: Increasing overTime struct size from 0 to 100 (3.63 KB)
[2017-05-16 00:24:27.612] Notice: Increasing queries struct size from 0 to 10000 (323.63 KB)
[2017-05-16 00:24:27.612] Notice: Increasing domains struct size from 0 to 1000 (343.63 KB)
[2017-05-16 00:24:27.613] Notice: Increasing clients struct size from 0 to 10 (343.82 KB)
[2017-05-16 00:24:27.622] New client: 192.168.254.42 (0/10)
[2017-05-16 00:24:27.637] New client: 192.168.254.7 (1/10)
[2017-05-16 00:24:27.657] New forward server: 8.8.4.4 google-public-dns-b.google.com (1/4)
[2017-05-16 00:24:27.677] New client: 192.168.254.82 (2/10)
[2017-05-16 00:24:27.688] New client: 192.168.254.200 (3/10)
[2017-05-16 00:24:27.716] New client: 192.168.254.3 (4/10)
[2017-05-16 00:24:27.734] New client: 127.0.0.1 localhost (5/10)
[2017-05-16 00:24:27.744] New client: 192.168.254.65 raspberrypi (6/10)
[2017-05-16 00:24:27.767] Reading from /var/log/pihole.log (rw-r--r--)
[2017-05-16 00:24:52.819] New client: 192.168.254.12 (7/10)
[2017-05-16 00:26:31.012] dnsmasq process restarted
[2017-05-16 00:26:32.421] Gravity list entries: 133190
[2017-05-16 00:26:32.422] Blacklist entries: 9
[2017-05-16 00:26:32.422] No wildcard blocking list present
[2017-05-16 00:27:14.296] NOTICE: pihole.log has been flushed
[2017-05-16 00:27:14.296] Resetting internal data structure
[2017-05-16 00:27:14.297] Queries in memory before flushing: 126
[2017-05-16 00:27:15.234] Gravity list entries: 133190
[2017-05-16 00:27:15.234] Blacklist entries: 9
[2017-05-16 00:27:15.235] No wildcard blocking list present
[2017-05-16 00:27:15.235] Reading from /var/log/pihole.log.1 (rw-r--r--)
[2017-05-16 00:27:15.236] Notice: Increasing queries struct size from 0 to 10000 (320.54 KB)
[2017-05-16 00:27:15.236] Notice: Increasing overTime struct size from 0 to 100 (323.74 KB)
[2017-05-16 00:27:15.237] Notice: Increasing forwarded struct size from 0 to 4 (323.81 KB)
[2017-05-16 00:27:15.282] New forward server: 8.8.4.4 google-public-dns-b.google.com (0/4)
[2017-05-16 00:27:15.283] Notice: Increasing domains struct size from 0 to 1000 (343.85 KB)
[2017-05-16 00:27:15.283] Notice: Increasing clients struct size from 0 to 10 (344.03 KB)
[2017-05-16 00:27:15.293] New client: 192.168.254.12 (0/10)
[2017-05-16 00:27:15.341] New forward server: 8.8.8.8 google-public-dns-a.google.com (1/4)
[2017-05-16 00:27:15.342] New client: 127.0.0.1 localhost (1/10)
[2017-05-16 00:27:15.372] New client: 192.168.254.82 (2/10)
[2017-05-16 00:27:15.392] New client: 192.168.254.3 (3/10)
[2017-05-16 00:27:15.393] Reading from /var/log/pihole.log (rw-r--r--)
[2017-05-16 00:30:03.673] New client: 192.168.254.42 (4/10)
[2017-05-16 00:31:21.609] New client: 192.168.254.7 (5/10)
[2017-05-16 00:39:12.376] New client: 192.168.254.200 (6/10)
[2017-05-16 15:56:52.092] New client: 192.168.254.4 (7/10)
[2017-05-16 16:50:40.961] Notice: Increasing overTime struct size from 100 to 200 (352.05 KB)
[2017-05-17 00:00:02.336] NOTICE: pihole.log has been flushed
[2017-05-17 00:00:02.337] Resetting internal data structure
[2017-05-17 00:00:02.337] Queries in memory before flushing: 2172
[2017-05-17 00:00:02.835] Gravity list entries: 133190
[2017-05-17 00:00:02.835] Blacklist entries: 9
[2017-05-17 00:00:02.836] No wildcard blocking list present
[2017-05-17 00:00:02.836] Reading from /var/log/pihole.log.1 (rw-r--r--)
[2017-05-17 00:00:02.837] Notice: Increasing forwarded struct size from 0 to 4 (815.00 B)
[2017-05-17 00:00:02.845] New forward server: 8.8.4.4 google-public-dns-b.google.com (0/4)
[2017-05-17 00:00:02.846] Notice: Increasing overTime struct size from 0 to 100 (4.05 KB)
[2017-05-17 00:00:02.846] Notice: Increasing queries struct size from 0 to 10000 (324.06 KB)
[2017-05-17 00:00:02.847] Notice: Increasing domains struct size from 0 to 1000 (344.06 KB)
[2017-05-17 00:00:02.848] Notice: Increasing clients struct size from 0 to 10 (344.24 KB)
[2017-05-17 00:00:02.856] New client: 192.168.254.12 (0/10)
[2017-05-17 00:00:02.864] New client: 192.168.254.42 (1/10)
[2017-05-17 00:00:02.873] New client: 192.168.254.7 (2/10)
[2017-05-17 00:00:02.882] New forward server: 8.8.8.8 google-public-dns-a.google.com (1/4)
[2017-05-17 00:00:02.890] New client: 192.168.254.82 (3/10)
[2017-05-17 00:00:02.911] New client: 192.168.254.200 (4/10)
[2017-05-17 00:00:03.027] New client: 192.168.254.3 (5/10)
[2017-05-17 00:00:03.220] New client: 192.168.254.4 (6/10)
[2017-05-17 00:00:03.235] Notice: Increasing overTime struct size from 100 to 200 (352.01 KB)
[2017-05-17 00:00:03.515] Reading from /var/log/pihole.log (rw-r--r--)
[2017-05-17 10:15:38.128] ########## FTL started! ##########
[2017-05-17 10:15:38.162] FTL branch: (no branch)
[2017-05-17 10:15:38.163] FTL hash: v2.7.3
[2017-05-17 10:15:38.163] FTL date: 2017-05-15 14:20:25 +0200
[2017-05-17 10:15:38.163] FTL user: pihole
[2017-05-17 10:15:38.164] Notice: Found no readable FTL config file
[2017-05-17 10:15:38.164] Using default settings
[2017-05-17 10:15:38.165] Starting config file parsing
[2017-05-17 10:15:38.165] SOCKET_LISTENING: only local
[2017-05-17 10:15:38.165] TIMEFRAME: Rolling 24h
[2017-05-17 10:15:38.166] QUERY_DISPLAY: Show queries
[2017-05-17 10:15:38.166] Finished config file parsing
[2017-05-17 10:15:38.276] Found no other running pihole-FTL process
[2017-05-17 10:15:38.345] PID of FTL process: 540
[2017-05-17 10:15:40.926] Gravity list entries: 133190
[2017-05-17 10:15:40.927] Blacklist entries: 9
[2017-05-17 10:15:40.927] No wildcard blocking list present
[2017-05-17 10:15:40.928] Starting initial log file parsing
[2017-05-17 10:15:40.928] Reading from /var/log/pihole.log.1 (rw-r--r--)
[2017-05-17 10:15:40.931] Notice: Increasing forwarded struct size from 0 to 4 (152.00 B)
[2017-05-17 10:15:48.475] New forward server: 8.8.4.4 google-public-dns-b.google.com (0/4)
[2017-05-17 10:15:48.476] Notice: Increasing overTime struct size from 0 to 100 (3.39 KB)
[2017-05-17 10:15:48.519] New forward server: 8.8.8.8 google-public-dns-a.google.com (1/4)
[2017-05-17 10:15:48.692] Notice: Increasing queries struct size from 0 to 10000 (324.00 KB)
[2017-05-17 10:15:48.702] Notice: Increasing domains struct size from 0 to 1000 (344.00 KB)
[2017-05-17 10:15:48.702] Notice: Increasing clients struct size from 0 to 10 (344.18 KB)
[2017-05-17 10:15:48.712] New client: 192.168.254.82 (0/10)
[2017-05-17 10:15:48.723] New client: 192.168.254.200 (1/10)
[2017-05-17 10:15:48.735] New client: 192.168.254.7 (2/10)
[2017-05-17 10:15:48.746] New client: 192.168.254.12 (3/10)
[2017-05-17 10:15:48.758] New client: 192.168.254.42 (4/10)
[2017-05-17 10:15:48.890] New client: 192.168.254.4 (5/10)
[2017-05-17 10:15:48.920] Notice: Increasing overTime struct size from 100 to 200 (350.29 KB)
[2017-05-17 10:15:49.213] New client: 192.168.254.3 (6/10)
[2017-05-17 10:15:49.223] Reading from /var/log/pihole.log (rw-r--r--)
[2017-05-17 10:15:49.621] New client: 127.0.0.1 localhost (7/10)
[2017-05-17 10:15:49.631] New client: 192.168.254.65 raspberrypi (8/10)
[2017-05-17 10:15:49.649] Notice: Increasing overTime struct size from 200 to 300 (358.53 KB)
[2017-05-17 10:15:49.673] Finished initial log file parsing
[2017-05-17 10:15:49.673] -> Total DNS queries: 2416
[2017-05-17 10:15:49.673] -> Cached DNS queries: 501
[2017-05-17 10:15:49.674] -> Blocked DNS queries: 865
[2017-05-17 10:15:49.674] -> Unknown DNS queries: 0
[2017-05-17 10:15:49.675] -> Unique domains: 307
[2017-05-17 10:15:49.675] -> Unique clients: 9
[2017-05-17 10:15:49.675] Successfully accessed setupVars.conf
[2017-05-17 10:15:49.677] Listening on port 4711

pi@raspberrypi:/var/log $ pihole-FTL version
v2.7.3

edited to add I meant 133K haha i got little 3-happy there on the list size originally.

updated info:

pi@raspberrypi:/var/log $ uptime
13:10:22 up 2:54, 1 user, load average: 0.30, 0.14, 0.10

Web interface stats as of nearly 3 hours uptime since last reboot:

Status
Active Temp: 47.6 °C
Load: 0.08 0.1 0.09
Memory usage: 9.4 %

FTL stats from web image:
http://image.dude-suit.net/albums/userpics/10002/pihole1.PNG

From earlier in 'daemon.log'

May 17 09:33:59 raspberrypi lighttpd[594]: /opt/pihole/piholeDebug.sh: line 441: read: read error: 0: Invalid argument
May 17 09:45:42 raspberrypi lighttpd[594]: cat: write error: Broken pipe

in damon.log found more broken pipes from yesterday:

root@raspberrypi:/var/log# cat daemon.log|grep pipe
May 16 00:19:34 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 398: printf: write error: Broken pipe
May 16 00:19:40 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 394: printf: write error: Broken pipe
May 16 00:19:40 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 398: printf: write error: Broken pipe
May 16 00:19:45 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 394: printf: write error: Broken pipe
May 16 00:19:45 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 398: printf: write error: Broken pipe
May 16 00:19:50 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 394: printf: write error: Broken pipe
May 16 00:19:50 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 398: printf: write error: Broken pipe
May 16 00:19:55 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 394: printf: write error: Broken pipe
May 16 00:19:55 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 398: printf: write error: Broken pipe
May 16 00:20:00 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 394: printf: write error: Broken pipe
May 16 00:20:00 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 398: printf: write error: Broken pipe
May 16 00:20:05 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 425: echo: write error: Broken pipe
May 16 00:20:06 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 436: echo: write error: Broken pipe
May 16 00:20:06 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 438: echo: write error: Broken pipe
May 16 00:20:06 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 453: echo: write error: Broken pipe
May 16 00:20:06 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 454: echo: write error: Broken pipe
May 16 00:20:06 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 455: echo: write error: Broken pipe
May 16 00:20:06 raspberrypi lighttpd[601]: /opt/pihole/piholeDebug.sh: line 460: echo: write error: Broken pipe
May 17 09:45:42 raspberrypi lighttpd[594]: cat: write error: Broken pipe
root@raspberrypi:/var/log#

thats not good sign

Here's current memory usage even though all is fine at the moment. I'll keep a tail running on log file, I have doc appt at 3pm est when I get back I'll update if I "catch it in the act" haha.

root@raspberrypi:/var/log# free -h
                         total       used       free     shared    buffers     cached
           Mem:          465M       166M       299M       9.7M        18M       100M
-/+ buffers/cache:        46M       418M
           Swap:          99M         0B        99M
4

I adjusted the title slightly, but that is also not so important :wink:

This is something I don't really understand. It is as if FTL got killed (if it crashes, it logs that to the log file before quitting!) externally via SIGKILL.

Everything else seems perfectly fine on your system - except the pipe issues, but I have never seen them before:

pi@raspberrypi:~ $ cat daemon.log|grep pipe
pi@raspberrypi:~ $

Asking @DanSchaper if he has seen this before.

5

thanks for taking a look for me. I've turned off the cron I set, although I tested and it's not killing or restarting it as that's first place I went , I have a terminal on another system taking multiple logs, so when it happens again I'll update here with everything, plus could/memory/etc

it's weirdest thing.

I looked at other logs and when FTL "disappears" just before it does there's a lot of "broken pipe" messages it restarts on its own or recovers not sure, then it stops and stays down. what has stumped me is just what you mentioned, there is no 'ftl crashed!' error message at all it just shuts down, it does a few resize messages then broken pipes then all that spam in log file of error on line 98.

let me get log where just before it disappears and some strangeness...

This is some of the strange junk that may be the culprit honestly now that I see this

May 17 20:39:21 dnsmasq[1956]: reply settings-crashlytics-b-103974621.us-east-1.elb.amazonaws.com is 54.225.98.79
▒0▒0@w▒OYzp0E▒R'ϒl֟seq▒5▒▒]▒▒?▒F▒▒y▒?ֽ▒▒▒9g▒▒kr▒9▒▒8▒▒D▒5▒▒
▒y▒[▒f▒I;▒ h▒ ▒%▒Wui~q▒▒▒s▒▒
r▒AxCs▒▒▒!>7▒l▒;O}▒T▒▒0H8'▒0▒▒▒{▒0▒▒54▒Z+b▒O▒s}2P̅▒ǐ▒▒!▒▒▒▒W▒l▒▒uv|▒▒j▒▒@r▒;ۈG,@z▒▒eZ▒I▒a▒6▒▒aQ▒-,م▒▒▒]▒ٽ#▒▒jk▒▒a8h▒▒▒▒C▒#▒_C▒5▒g1▒C▒▒▒▒▒▒TQv▒▒$▒ @x▒▒cX▒▒!▒▒ ▒▒ft,<4[}▒b▒▒▒"▒9▒▒▒o Os▒8▒C4▒P▒▒i▒▒K▒▒▒o▒▒/▒{▒▒▒<b 4▒Nu▒ݳ▒wwT▒▒▒]▒▒~▒▒$▒▒>▒V▒▒▒;▒98x▒PR▒m▒\▒r▒<▒̉f:3s)▒l
▒x[Ep▒Y▒▒▒▒uʪI29׼▒y▒▒6▒▒▒襩▒ӡy▒▒▒{TY!>▒▒E▒▒▒▒b▒▒7▒^<i▒j▒U
▒▒\Ŋ{▒dF▒1W1▒▒90y▒P▒Aj▒▒▒▒▒z▒f▒▒.׊▒▒▒

I don't know if this means anything I don't know what "action 17" means...

==> syslog <==
May 17 19:39:01 raspberrypi CRON[6051]: (root) CMD ( [ -x /usr/lib/php5/sessionclean ] && /usr/lib/php5/sessionclean)
May 17 20:09:01 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed May 17 20:09:31 2017 [try You searched for error 2007 - rsyslog ]

==> messages <==
May 17 20:09:01 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed May 17 20:09:31 2017 [try You searched for error 2007 - rsyslog ]

==> syslog <==
May 17 20:09:01 raspberrypi CRON[6087]: (root) CMD ( [ -x /usr/lib/php5/sessionclean ] && /usr/lib/php5/sessionclean)
May 17 20:17:01 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed May 17 20:17:31 2017 [try You searched for error 2007 - rsyslog ]

==> messages <==
May 17 20:17:01 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed May 17 20:17:31 2017 [try You searched for error 2007 - rsyslog ]

Here is a log of the "Error on line 98" begins from a timeout...

"FastCGI-stderr: PHP Warning: socket_read(): unable to read from socket [104]: Connection reset by peer in /var/www/html/admin/scripts/pi-hole/php/FTL.php on line 98"

ok what is line 98?

            $out = socket_read($socket, 2048, PHP_NORMAL_READ);

Don't really know why that's causing this old pi issues, course it is an old one, just a pi b+, not the newer ones.