Pihole should give me the dns and collecting some data about clients.
The problem is that pihole not collect query data and not give me dns until I go to the main web interface, from here without touching nothing, it start working normally.
Mhh sounds a bit like whats described in the first part of this post. Are you running DietPi?
Thank you for the reply,
Yes seem the same problem but I don't know how to solve.
I running armbian.
I noticed also the the time of the FTL Started is two hour back, however the system date time is correct.
As far as I understood pihole should run fine from now on.
Pinging @DL6ER as he has already heard about this behavior. This is the second (?) time a user reports pihole not starting (completely?) unless the WEB GUI is accessed.
Maybe there is some code that requires resolving pi.hole before FTL starts properly and in a few circumstances this doesn't happen automatically?
Interesting assumption, but no. When developing mobile, I run pihole-FTL on my laptop. I have neither the rest of Pi-hole installed nor any web server at all. I even start it on a different port so there is typically no external connection to FTL at all in this environment. I've never seen a delay in startup.
The only thing I can really imagine is a dangling memory lock, however, this should immediately affect a ton of users, but let's go down this path, first.
@luccio96 Please try the following:
Put
DEBUG_ALL=true
into /etc/pihole/pihole-FTL.conf and restart your Pi-hole.
Then copy the last few lines of /var/log/pihole-FTL.log and /var/log/pihole.log before accessing the web interface (so before anything is working again) and the first few new lines after accessing the web interface (when DNS service is restored). You may want to remove the DEBUG_ALL line afterwards as logging will be very verbose.
The logs before:
[2020-04-09 18:15:00.022 1159] Waiting for lock in resolveClients() (resolve.c:121)
[2020-04-09 18:15:00.022 1159] Obtained lock for resolveClients() (resolve.c:121)
[2020-04-09 18:15:00.022 1159] Removed lock in resolveClients() (resolve.c:125)
[2020-04-09 18:15:00.022 1159] Waiting for lock in resolveForwardDestinations() (resolve.c:149)
[2020-04-09 18:15:00.022 1159] Obtained lock for resolveForwardDestinations() (resolve.c:149)
[2020-04-09 18:15:00.023 1159] Removed lock in resolveForwardDestinations() (resolve.c:151)
[2020-04-09 18:15:00.023 1159] Waiting for lock in resolveForwardDestinations() (resolve.c:158)
[2020-04-09 18:15:00.023 1159] Obtained lock for resolveForwardDestinations() (resolve.c:158)
[2020-04-09 18:15:00.023 1159] Removed lock in resolveForwardDestinations() (resolve.c:162)
[2020-04-09 18:15:00.023 1159] Waiting for lock in resolveForwardDestinations() (resolve.c:158)
[2020-04-09 18:15:00.023 1159] Obtained lock for resolveForwardDestinations() (resolve.c:158)
[2020-04-09 18:15:00.024 1159] Removed lock in resolveForwardDestinations() (resolve.c:162)
[2020-04-09 18:15:00.030 1159] Waiting for lock in DB_thread() (database.c:634)
[2020-04-09 18:15:00.031 1159] Obtained lock for DB_thread() (database.c:634)
[2020-04-09 18:15:00.033 1159] dbquery: BEGIN TRANSACTION
[2020-04-09 18:15:00.033 1159] dbquery: END TRANSACTION
[2020-04-09 18:15:00.034 1159] Notice: Queries stored in DB: 0 (took 2.8 ms, last SQLite ID 377835)
[2020-04-09 18:15:00.034 1159] Removed lock in DB_thread() (database.c:640)
[2020-04-09 18:15:00.034 1159] dbquery: BEGIN TRANSACTION
[2020-04-09 18:15:00.037 1159] Waiting for lock in parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.037 1159] Obtained lock for parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.037 1159] dbquery: UPDATE network SET lastQuery = MAX(lastQuery, 1586431072) WHERE id = 49;
[2020-04-09 18:15:00.038 1159] dbquery: UPDATE network SET numQueries = numQueries + 0 WHERE id = 49;
[2020-04-09 18:15:00.038 1159] dbquery: UPDATE network SET name = '_gateway' WHERE id = 49;
[2020-04-09 18:15:00.038 1159] Removed lock in parse_arp_cache() (networktable.c:179)
[2020-04-09 18:15:00.039 1159] Waiting for lock in parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.039 1159] Obtained lock for parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.039 1159] Removed lock in parse_arp_cache() (networktable.c:179)
[2020-04-09 18:15:00.040 1159] Waiting for lock in parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.040 1159] Obtained lock for parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.040 1159] Removed lock in parse_arp_cache() (networktable.c:179)
[2020-04-09 18:15:00.041 1159] Waiting for lock in parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.041 1159] Obtained lock for parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.041 1159] dbquery: UPDATE network SET lastQuery = MAX(lastQuery, 1586452840) WHERE id = 48;
[2020-04-09 18:15:00.041 1159] dbquery: UPDATE network SET numQueries = numQueries + 0 WHERE id = 48;
[2020-04-09 18:15:00.042 1159] Removed lock in parse_arp_cache() (networktable.c:179)
[2020-04-09 18:15:00.042 1159] Waiting for lock in parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.042 1159] Obtained lock for parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.042 1159] dbquery: UPDATE network SET lastQuery = MAX(lastQuery, 1586453502) WHERE id = 52;
[2020-04-09 18:15:00.043 1159] dbquery: UPDATE network SET numQueries = numQueries + 0 WHERE id = 52;
[2020-04-09 18:15:00.043 1159] Removed lock in parse_arp_cache() (networktable.c:179)
[2020-04-09 18:15:00.044 1159] Waiting for lock in parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.044 1159] Obtained lock for parse_arp_cache() (networktable.c:117)
[2020-04-09 18:15:00.044 1159] dbquery: UPDATE network SET lastQuery = MAX(lastQuery, 1586453533) WHERE id = 53;
[2020-04-09 18:15:00.044 1159] dbquery: UPDATE network SET numQueries = numQueries + 0 WHERE id = 53;
[2020-04-09 18:15:00.045 1159] Removed lock in parse_arp_cache() (networktable.c:179)
[2020-04-09 18:15:00.045 1159] dbquery: COMMIT
[2020-04-09 18:15:00.045 1159] ARP table processing (6 entries) took 10.8 ms
Apr 9 17:31:42 dnsmasq[18690]: reply keyvalueservice.fe.apple-dns.net is 17.248.184.203
Apr 9 17:31:42 dnsmasq[18690]: reply keyvalueservice.fe.apple-dns.net is 17.248.137.79
Apr 9 17:31:42 dnsmasq[18690]: reply keyvalueservice.fe.apple-dns.net is 17.248.137.109
Apr 9 17:32:13 dnsmasq[18690]: query[A] www.icloud.com from 10.9.8.1
Apr 9 17:32:13 dnsmasq[18690]: forwarded www.icloud.com to 1.0.0.1
Apr 9 17:32:13 dnsmasq[18690]: query[A] www.apple.com from 10.9.8.1
Apr 9 17:32:13 dnsmasq[18690]: cached www.apple.com is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: cached www.apple.com.edgekey.net is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: cached www.apple.com.edgekey.net.globalredir.akadns.net is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: forwarded www.apple.com to 1.0.0.1
Apr 9 17:32:13 dnsmasq[18690]: reply www.icloud.com is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: reply www-cdn.icloud.com.akadns.net is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: reply www.icloud.com.edgekey.net is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: reply e4478.a.akamaiedge.net is 104.91.5.92
Apr 9 17:32:13 dnsmasq[18690]: reply www.apple.com is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: reply www.apple.com.edgekey.net is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: reply www.apple.com.edgekey.net.globalredir.akadns.net is <CNAME>
Apr 9 17:32:13 dnsmasq[18690]: reply e6858.dsce9.akamaiedge.net is 104.83.149.8
Apr 9 17:32:50 dnsmasq[18690]: exiting on receipt of SIGTERM
Apr 9 17:33:24 dnsmasq[1159]: started, version pi-hole-2.80 cachesize 10000
Apr 9 17:33:24 dnsmasq[1159]: DNS service limited to local subnets
Apr 9 17:33:24 dnsmasq[1159]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify dumpfile
Apr 9 17:33:24 dnsmasq[1159]: using local addresses only for domain use-application-dns.net
Apr 9 17:33:24 dnsmasq[1159]: using nameserver 1.0.0.1#53
Apr 9 17:33:24 dnsmasq[1159]: using nameserver 1.1.1.1#53
Apr 9 17:33:24 dnsmasq[1159]: read /etc/hosts - 7 addresses
Apr 9 17:33:24 dnsmasq[1159]: read /etc/pihole/local.list - 2 addresses
Apr 9 17:33:24 dnsmasq[1159]: failed to load names from /etc/pihole/black.list: No such file or directory
Apr 9 17:33:25 dnsmasq[1159]: read /etc/pihole/gravity.list - 91372 addresses
Apr 9 17:33:25 dnsmasq[1159]: Ignoring query from non-local network
the new logs
[2020-04-09 18:21:00.443 10174] Removed lock in resolveForwardDestinations() (resolve.c:177)
[2020-04-09 18:21:00.653 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:00.653 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:00.654 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:00.658 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:00.658 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:00.660 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:00.661 10174] Waiting for lock in process_request() (request.c:50)
[2020-04-09 18:21:00.661 10174] Obtained lock for process_request() (request.c:50)
[2020-04-09 18:21:00.662 10174] Removed lock in process_request() (request.c:52)
[2020-04-09 18:21:00.662 10174] Waiting for lock in process_request() (request.c:50)
[2020-04-09 18:21:00.662 10174] Obtained lock for process_request() (request.c:50)
[2020-04-09 18:21:00.663 10174] Removed lock in process_request() (request.c:52)
[2020-04-09 18:21:02.685 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:02.685 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:02.686 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:03.712 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:03.712 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:03.713 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:04.744 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:04.744 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:04.746 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:06.776 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:06.776 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:06.778 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:08.769 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:08.769 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:08.770 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:09.778 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:09.778 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:09.778 10174] Removed lock in process_request() (request.c:31)
[2020-04-09 18:21:09.779 10174] Waiting for lock in process_request() (request.c:43)
[2020-04-09 18:21:09.779 10174] Obtained lock for process_request() (request.c:43)
[2020-04-09 18:21:09.780 10174] Removed lock in process_request() (request.c:45)
[2020-04-09 18:21:09.780 10174] Waiting for lock in process_request() (request.c:43)
[2020-04-09 18:21:09.780 10174] Obtained lock for process_request() (request.c:43)
[2020-04-09 18:21:09.780 10174] Removed lock in process_request() (request.c:45)
[2020-04-09 18:21:10.779 10174] Waiting for lock in process_request() (request.c:29)
[2020-04-09 18:21:10.779 10174] Obtained lock for process_request() (request.c:29)
[2020-04-09 18:21:10.781 10174] Removed lock in process_request() (request.c:31)
Apr 9 18:18:55 dnsmasq[1159]: exiting on receipt of SIGTERM
Apr 9 18:18:55 dnsmasq[9710]: started, version pi-hole-2.80 cachesize 10000
Apr 9 18:18:55 dnsmasq[9710]: DNS service limited to local subnets
Apr 9 18:18:55 dnsmasq[9710]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify dumpfile
Apr 9 18:18:55 dnsmasq[9710]: using local addresses only for domain use-application-dns.net
Apr 9 18:18:55 dnsmasq[9710]: using nameserver 1.0.0.1#53
Apr 9 18:18:55 dnsmasq[9710]: using nameserver 1.1.1.1#53
Apr 9 18:18:55 dnsmasq[9710]: read /etc/hosts - 7 addresses
Apr 9 18:18:55 dnsmasq[9710]: read /etc/pihole/local.list - 2 addresses
Apr 9 18:18:55 dnsmasq[9710]: failed to load names from /etc/pihole/black.list: No such file or directory
Apr 9 18:18:56 dnsmasq[9710]: read /etc/pihole/gravity.list - 91372 addresses
Apr 9 18:19:47 dnsmasq[9710]: exiting on receipt of SIGTERM
Apr 9 18:19:47 dnsmasq[10174]: started, version pi-hole-2.80 cachesize 10000
Apr 9 18:19:47 dnsmasq[10174]: DNS service limited to local subnets
Apr 9 18:19:47 dnsmasq[10174]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify dumpfile
Apr 9 18:19:47 dnsmasq[10174]: using local addresses only for domain use-application-dns.net
Apr 9 18:19:47 dnsmasq[10174]: using nameserver 1.0.0.1#53
Apr 9 18:19:47 dnsmasq[10174]: using nameserver 1.1.1.1#53
Apr 9 18:19:47 dnsmasq[10174]: read /etc/hosts - 7 addresses
Apr 9 18:19:47 dnsmasq[10174]: read /etc/pihole/local.list - 2 addresses
Apr 9 18:19:47 dnsmasq[10174]: failed to load names from /etc/pihole/black.list: No such file or directory
Apr 9 18:19:48 dnsmasq[10174]: read /etc/pihole/gravity.list - 91372 addresses
Apr 9 18:20:01 dnsmasq[10174]: query[A] www.duckdns.org from 10.9.8.5
Apr 9 18:20:01 dnsmasq[10174]: forwarded www.duckdns.org to 1.0.0.1
Apr 9 18:20:01 dnsmasq[10174]: forwarded www.duckdns.org to 1.1.1.1
Apr 9 18:20:01 dnsmasq[10174]: query[AAAA] www.duckdns.org from 10.9.8.5
Apr 9 18:20:01 dnsmasq[10174]: forwarded www.duckdns.org to 1.0.0.1
Apr 9 18:20:01 dnsmasq[10174]: forwarded www.duckdns.org to 1.1.1.1
Apr 9 18:20:01 dnsmasq[10174]: reply www.duckdns.org is <CNAME>
Apr 9 18:20:01 dnsmasq[10174]: reply duckdnsappelb-570522007.us-west-2.elb.amazonaws.com is 34.208.211.37
Apr 9 18:20:01 dnsmasq[10174]: reply duckdnsappelb-570522007.us-west-2.elb.amazonaws.com is 52.27.51.44
Apr 9 18:20:01 dnsmasq[10174]: reply www.duckdns.org is <CNAME>
Apr 9 18:20:01 dnsmasq[10174]: reply duckdnsappelb-570522007.us-west-2.elb.amazonaws.com is NODATA-IPv6
luca@orangepipcplus:~$
At what time did you access the web page? The logs do not really reveal this, i.e., the old logs go to 17:33 and 18:15, the new logs go from 18:21 and 18:18.
So if we assume that you accessed the web dashboard at 18:18, then we see some very strange things:
pihole-FTL is restarted - was that you triggering this?pihole-FTL.log snippet for this time is missing, making the analysis harderMore information needed.
Hi sorry for delay,
I'm trying to get the logs but now even navigate to web interface don't starts collecting the queries and the counters are all at 0.
If can be helpful I noticed a wrong pihole time, from the web and logs it show 9.32 but on the the system is 11.32 AM CEST
Yeah, this also really wasn't the trigger before, I guess. There is something else to it.
The web front end tries to detect the time zone of your client's browser to show everything in the correct timezone. @jfb recommended elsewhere to disable some tracking protection in your browser if I'm not mistaken.
This topic was automatically closed 21 days after the last reply. New replies are no longer allowed.