search

pi-hole / docker-pi-hole

Pi-hole in a docker container
https://pi-hole.net
Other
8.46k stars 1.13k forks source link

second pihole-FTL process 100% CPU and filling up FS #264

Closed 01010101001 closed 6 years ago

01010101001 commented 6 years ago

Hello

I have been running the pihole docker successfully for quite a while on a small ubuntu (stretch/sid) server and find it pretty neat. I am competent with linux but new to docker. my docker creation command is

IP_LOOKUP="$(ip route get 8.8.8.8 | awk '{ print $NF; exit }')"
IPv6_LOOKUP="$(ip -6 route get 2001:4860:4860::8888 | awk '{ print $5; exit }')" # tweaked to make IPv6 work on my box, which it does IP="${IP:-$IP_LOOKUP}"
IPv6="${IPv6:-$IPv6_LOOKUP}"
DOCKER_CONFIGS="/etc/pihole" docker run -d \ --name pihole \ -p 53:53/tcp -p 53:53/udp -p 80:80 \ -v "${DOCKER_CONFIGS}/pihole/:/etc/pihole/" \ -v "${DOCKER_CONFIGS}/dnsmasq.d/:/etc/pihole_dnsmasq.d/" \ -e WEBPASSWORD=XXXXXXXX \ -e ServerIP="${IP}" \ -e ServerIPv6="${IPv6}" \ --restart=unless-stopped \ diginc/pi-hole:latest

Recently I noticed that my filesystem is full and pihole's web interface is non functional (it loads up but can't connect to the API so none of the graphs are populated). upon investigation, I actually have 2 pihole-FTL processes running at all times, and the second one is hugging 100% CPU. it seems to keep trying to kill the first one.- /var/log/pihole-FTL.log is filling up quick with this:

[2018-04-15 15:52:37.435] 805 - pihole-FTL [2018-04-15 15:52:37.435] Found pihole-FTL process with PID 805 (my PID 1017) - killing it ... [2018-04-15 15:52:37.435] 805 - pihole-FTL [2018-04-15 15:52:37.435] Found pihole-FTL process with PID 805 (my PID 1017) - killing it ... ..

(thousands of these per second). it's not actually killing it though and both keep running. lsof is full of thousands of /proc entries from the second pihole-FTL process and the max open files limit is reached. while all of this happens, dnsmasq is doing its job just fine and I have name resolution working perfectly on my network, even once the file system fills up.

what I did try so far includes:

but no matter what this behaviour continues... as soon as I start a new image my CPU spikes as the two pihole-FTL process fight. can someone please point me in the right direction to investigate further?

Thanks in advance

01010101001

01010101001 commented 6 years ago

for completeness' sake, pihole.log contains nothing beyond

Apr 15 16:19:36 dnsmasq[215]: started, version 2.76 cachesize 10000 Apr 15 16:19:36 dnsmasq[215]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify Apr 15 16:19:36 dnsmasq[215]: using nameserver 8.8.4.4#53 Apr 15 16:19:36 dnsmasq[215]: using nameserver 8.8.8.8#53 Apr 15 16:19:36 dnsmasq[215]: read /etc/hosts - 7 addresses Apr 15 16:19:36 dnsmasq[215]: read /etc/pihole/local.list - 4 addresses Apr 15 16:19:36 dnsmasq[215]: failed to load names from /etc/pihole/black.list: No such file or directory Apr 15 16:19:37 dnsmasq[215]: read /etc/pihole/gravity.list - 242130 addresses (query logs start here)

and pihole-FTL's log contains nothing suspicious except for the fact that 2 processes start

[2018-04-15 16:19:41.293] ########## FTL started! ########## [2018-04-15 16:19:41.293] FTL branch: v3.0 [2018-04-15 16:19:41.293] FTL version: v3.0 [2018-04-15 16:19:41.293] FTL commit: a1b2fa03f8f3e3713b57a26a4e9a062fec0573d7 [2018-04-15 16:19:41.293] FTL date: 2018-02-14 12:45:47 -0800 [2018-04-15 16:19:41.293] FTL user: root [2018-04-15 16:19:41.293] Warning: Starting pihole-FTL directly is not recommended. [2018-04-15 16:19:41.293] Instead, use system commands for starting pihole-FTL as service (systemctl / service). [2018-04-15 16:19:41.293] Notice: Found no readable FTL config file [2018-04-15 16:19:41.293] Using default settings [2018-04-15 16:19:41.293] Starting config file parsing (/etc/pihole/pihole-FTL.conf) [2018-04-15 16:19:41.293] SOCKET_LISTENING: only local [2018-04-15 16:19:41.293] QUERY_DISPLAY: Show queries [2018-04-15 16:19:41.293] AAAA_QUERY_ANALYSIS: Show AAAA queries [2018-04-15 16:19:41.293] MAXDBDAYS: max age for stored queries is 365 days [2018-04-15 16:19:41.294] RESOLVE_IPV6: Resolve IPv6 addresses [2018-04-15 16:19:41.294] RESOLVE_IPV4: Resolve IPv4 addresses [2018-04-15 16:19:41.294] DBINTERVAL: saving to DB file every minute [2018-04-15 16:19:41.294] DBFILE: Using /etc/pihole/pihole-FTL.db [2018-04-15 16:19:41.294] MAXLOGAGE: Importing up to 24.0 hours of log data [2018-04-15 16:19:41.294] Finished config file parsing [2018-04-15 16:19:41.299] Found no other running pihole-FTL process [2018-04-15 16:19:41.307] PID of FTL process: 422 [2018-04-15 16:19:41.936] Gravity list entries: 121065 [2018-04-15 16:19:41.936] No blacklist present [2018-04-15 16:19:41.936] No wildcard blocking list present [2018-04-15 16:19:41.942] Database initialized [2018-04-15 16:19:41.946] Notice: Increasing queries struct size from 0 to 10000 (440.11 KB) [2018-04-15 16:19:41.946] Notice: Increasing domains struct size from 0 to 1000 (472.11 KB) [2018-04-15 16:19:41.946] Notice: Increasing clients struct size from 0 to 10 (472.35 KB) [2018-04-15 16:19:41.958] New client: 192.168.2.120 (0/10) [2018-04-15 16:19:41.958] Notice: Increasing forwarded struct size from 0 to 4 (472.49 KB) [2018-04-15 16:19:41.975] New forward server: 8.8.4.4 google-public-dns-b.google.com (0/4) [2018-04-15 16:19:41.975] Notice: Increasing overTime struct size from 0 to 100 (478.13 KB) [2018-04-15 16:19:41.985] New client: 192.168.2.100 (1/10) [2018-04-15 16:19:41.001] New forward server: 8.8.8.8 google-public-dns-a.google.com (1/4) [2018-04-15 16:19:42.011] New client: 172.17.0.1 (2/10) [2018-04-15 16:19:42.011] Imported 13 queries from the long-term database [2018-04-15 16:19:42.011] Starting initial log file parsing [2018-04-15 16:19:42.011] Reading from /var/log/pihole.log (rw-r--r--) [2018-04-15 16:19:42.015] Finished initial log file parsing [2018-04-15 16:19:42.015] -> Total DNS queries: 35 [2018-04-15 16:19:42.015] -> Cached DNS queries: 6 [2018-04-15 16:19:42.015] -> Forwarded DNS queries: 25 [2018-04-15 16:19:42.015] -> Exactly blocked DNS queries: 4 [2018-04-15 16:19:42.015] -> Wildcard blocked DNS queries: 0 [2018-04-15 16:19:42.016] -> Unknown DNS queries: 0 [2018-04-15 16:19:42.016] -> Unique domains: 22 [2018-04-15 16:19:42.016] -> Unique clients: 3 [2018-04-15 16:19:42.016] -> Known forward destinations: 2 [2018-04-15 16:19:42.016] Successfully accessed setupVars.conf [2018-04-15 16:19:42.016] Listening on port 4711 for incoming IPv4 telnet connections [2018-04-15 16:19:42.016] Listening on port 4711 for incoming IPv6 telnet connections [2018-04-15 16:19:42.016] Listening on Unix socket [2018-04-15 16:19:42.890] ########## FTL started! ########## [2018-04-15 16:19:42.890] FTL branch: v3.0 [2018-04-15 16:19:42.890] FTL version: v3.0 [2018-04-15 16:19:42.890] FTL commit: a1b2fa03f8f3e3713b57a26a4e9a062fec0573d7 [2018-04-15 16:19:42.890] FTL date: 2018-02-14 12:45:47 -0800 [2018-04-15 16:19:42.890] FTL user: root [2018-04-15 16:19:42.890] Warning: Starting pihole-FTL directly is not recommended. [2018-04-15 16:19:42.890] Instead, use system commands for starting pihole-FTL as service (systemctl / service). [2018-04-15 16:19:42.890] Notice: Found no readable FTL config file [2018-04-15 16:19:42.890] Using default settings [2018-04-15 16:19:42.890] Starting config file parsing (/etc/pihole/pihole-FTL.conf) [2018-04-15 16:19:42.890] SOCKET_LISTENING: only local [2018-04-15 16:19:42.890] QUERY_DISPLAY: Show queries [2018-04-15 16:19:42.890] AAAA_QUERY_ANALYSIS: Show AAAA queries [2018-04-15 16:19:42.890] MAXDBDAYS: max age for stored queries is 365 days [2018-04-15 16:19:42.890] RESOLVE_IPV6: Resolve IPv6 addresses [2018-04-15 16:19:42.890] RESOLVE_IPV4: Resolve IPv4 addresses [2018-04-15 16:19:42.890] DBINTERVAL: saving to DB file every minute [2018-04-15 16:19:42.891] DBFILE: Using /etc/pihole/pihole-FTL.db [2018-04-15 16:19:42.891] MAXLOGAGE: Importing up to 24.0 hours of log data [2018-04-15 16:19:42.891] Finished config file parsing [2018-04-15 16:19:42.897] 422 - pihole-FTL [2018-04-15 16:19:42.897] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.897] FATAL: FTL received SIGTERM from PID/UID 455/0, exiting gracefully [2018-04-15 16:19:42.897] Shutting down... [2018-04-15 16:19:42.898] 422 - pihole-FTL [2018-04-15 16:19:42.904] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.906] 422 - pihole-FTL [2018-04-15 16:19:42.906] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.907] 422 - pihole-FTL [2018-04-15 16:19:42.907] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.907] FATAL: FTL received SIGTERM from PID/UID 455/0, exiting gracefully [2018-04-15 16:19:42.907] 422 - pihole-FTL [2018-04-15 16:19:42.907] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.907] 422 - pihole-FTL [2018-04-15 16:19:42.907] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.908] 422 - pihole-FTL [2018-04-15 16:19:42.908] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.908] 422 - pihole-FTL [2018-04-15 16:19:42.908] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.908] FATAL: FTL received SIGTERM from PID/UID 455/0, exiting gracefully [2018-04-15 16:19:42.909] 422 - pihole-FTL [2018-04-15 16:19:42.914] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.915] 422 - pihole-FTL [2018-04-15 16:19:42.915] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... [2018-04-15 16:19:42.915] 422 - pihole-FTL [2018-04-15 16:19:42.915] Found pihole-FTL process with PID 422 (my PID 455) - killing it ... (billions more)

diginc commented 6 years ago

Could you see if FTL startup infinite loops when you run a stripped down container in the foreground?

docker run -it --rm -e ServerIP="0.0.0.0" diginc/pi-hole:latest

01010101001 commented 6 years ago

Thanks for the reply. Yes, the issue is the same when I use the command you provided. I still haven't managed to figure out what's going on...

root@hp-server:~# docker rm -f pihole pihole root@hp-server:~# docker run -it --rm -e ServerIP="0.0.0.0" diginc/pi-hole:latest [s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] 01-resolver-resolv: applying... [fix-attrs.d] 01-resolver-resolv: exited 0. [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] 20-start.sh: executing... ARCH=amd64 BASH=/bin/bash BASHOPTS=cmdhist:complete_fullquote:extquote:force_fignore:hostcomplete:interactive_comments:progcomp:promptvars:sourcepath BASH_ALIASES=() BASH_ARGC=() BASH_ARGV=() BASH_CMDS=() BASH_LINENO=([0]="0") BASH_SOURCE=([0]="/var/run/s6/etc/cont-init.d/20-start.sh") BASH_VERSINFO=([0]="4" [1]="4" [2]="12" [3]="1" [4]="release" [5]="x86_64-pc-linux-gnu") BASH_VERSION='4.4.12(1)-release' CWD=/ DIRSTACK=() EUID=0 GROUPS=() HOME=/root HOSTNAME=de4c000b296c HOSTTYPE=x86_64 IFS=$' \t\n' IPv6=True MACHTYPE=x86_64-pc-linux-gnu OPTERR=1 OPTIND=1 OSTYPE=linux-gnu PATH=/opt/pihole:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin PHP_ENV_CONFIG=/etc/lighttpd/conf-enabled/15-fastcgi-php.conf PHP_ERROR_LOG=/var/log/lighttpd/error.log PIHOLE_INSTALL=/tmp/ph_install.sh PPID=207 PS4='+ ' PWD=/ S6OVERLAY_RELEASE=https://github.com/just-containers/s6-overlay/releases/download/v1.21.2.2/s6-overlay-amd64.tar.gz S6_KEEPENV=1 SHELL=/bin/bash SHELLOPTS=braceexpand:hashall:interactive-comments SHLVL=1 ServerIP=0.0.0.0 TAG=debian TERM=xterm UID=0 =bash setupVars=/etc/pihole/setupVars.conf ::: Starting docker specific setup for docker diginc/pi-hole Assigning random password: JnuiBWpr

diginc commented 6 years ago

Starting pihole-FTL () should be Starting pihole-FTL (no-daemon) in the latest version of the image.

Can you confirm your image hash and see if pulling gets you a newer copy?

~$ docker image ls diginc/pi-hole:latest
REPOSITORY          TAG                 IMAGE ID            CREATED             SIZE
diginc/pi-hole      latest              eb902c685095        9 days ago          367MB
$ docker pull diginc/pi-hole:latest
latest: Pulling from diginc/pi-hole
Digest: sha256:50479369dcff346cb3f8aef12557ec8ebaf787882eeb7c0f44c98d7bcac39a52
Status: Image is up to date for diginc/pi-hole:latest
01010101001 commented 6 years ago

THANKS!

I just updated the image and started it again and the problem is gone! not sure what you changed but you fixed it. thanks a lot :)

diginc commented 6 years ago

There was a small window where the buggy image was released - more info here:

https://github.com/diginc/docker-pi-hole/issues/257#issuecomment-380190798