Random long times resolving

Please follow the below template, it will help us to help you!

Expected Behaviour:

Quick DNS resolution when surfing the web via browser

Actual Behaviour:

SOMETIMES, even rarely, browsers in the home stay for 10 maybe 15 seconds in the "resolving" state

Debug Token:

https://tricorder.pi-hole.net/dem9vh9yxo

Pihole is running on a Raspberry Pi 4 with 4GB RAM, attached via Cat6 Eth cable to ISP router (Fritzbox 7590). ADSL is a 200/30 Mbit FTTC working very well. Upstream DNS is Google's 8.8.8.8 as I measured to be consistently slightly faster than 1.1.1.1 or opendns.

Pihole usually works like a charm, filters about 12% of the IPs and all clients work very well with it. For reasons I do not understand SOMETIMES (like 3-4 times a day) the browsers stall in the "resolving" state for 10 maybe even 15 seconds and after that long wait usually resolve and the rest of the protocls load pages correctly.

Thank you VERY much for the wonderful software and for helping me find if I did some misconfiguration or explanation.

Do you experience this on several clients ?

Maybe you've created a DNS loop somewhere.
What upstream DSN server(s) are configured on Fritzbox ?
Usually these upstream DNS settings can be found in the Internet or WAN section of the router settings.

Do you experience "Under-voltage" ?

Can tail the logs live to see when goes south:

1 Like

Thank you very much for helping.

Yes this happens on my mac as well as my wife's mac and iphone.

Tailing the logs to catch the bug is very hard since this might happen only every few hours :frowning:

dmesg | grep -i voltage does not return anything.
filesystems are all quite empty

bob@rpibuster:~ $ free -h
              total        used        free      shared  buff/cache   available
Mem:          3.9Gi       763Mi       1.2Gi        18Mi       1.9Gi       3.0Gi
Swap:          99Mi          0B        99Mi
bob@rpibuster:~ $ uptime
 10:26:25 up 16:43,  1 user,  load average: 1.31, 2.12, 2.08
bob@rpibuster:~ $ timedatectl
               Local time: Fri 2020-05-01 10:27:35 CEST
           Universal time: Fri 2020-05-01 08:27:35 UTC
                 RTC time: n/a
                Time zone: Europe/Rome (CEST, +0200)
System clock synchronized: yes
              NTP service: inactive
          RTC in local TZ: no
bob@rpibuster:~ $ ip r | grep default
default via 192.168.1.254 dev eth0 proto dhcp metric 100
default via 192.168.1.254 dev eth0 src 192.168.1.18 metric 202

Load averages are a bit high for a Pi 4.
Below my dedicated Pi 1B idling:

pi@noads:~ $ uptime
 20:58:12 up 102 days, 20:27,  1 user,  load average: 0.43, 0.26, 0.22

High load could be an indicator of a DNS loop:

Have you configured "Conditional forwarding" in the Pi-hole settings and how is this configured ?
Do you run anything else on the Pi besides Pi-hole ?

Intermittent issues are always the hardest to troubleshoot.
I would still advice to check those logs when the issue occurs.
Keep an SSH session running or on console.
Or use the less command to browse those logs.

1 Like

Didnt noticed at first but you have two similar default routes configured somehow.
Whats output for below ?

sudo grep -v '^\s*#\|^\s*$' /etc/dhcpcd.conf

sudo grep -v '^\s*#\|^\s*$' -R /etc/network/interfaces*

Do you have another network manager running besides dhcpcd5 ?

sudo service network-manager status

sudo service connman status

1 Like

I am puzzled by the short uptime ... this Pi4 is always on (save for when electricity loss in the house) ... ideas on how to look for potential accidental reboots in the logs?

Conditional forwarding is disabled; Upstream DNS in pihole is only Google and IPV4; also have never forward non-FQDN and private IP ranges enabled; DNSSEC and Conditional forwarding are disabled;

Is /etc/resolv.conf reasonable?
bob@rpibuster:~ $ cat /etc/resolv.conf
nameserver 127.0.0.1
search fritz.box

Fritzbox gets its DNS server upstream delivered by the ISP (Fastweb Italy)
Choice is :"Use DNSv4 servers assigned by the internet service provider" (recommended)
and they are

  • Server DNS preferito: 85.18.200.200.
  • Server DNS alternativo: 89.97.140.140.

While doing a tail -f pihole.log not witnessed a slow resolution :frowning:

Looks like you dont have a loop.
If you know the Pi is up for 16 hours, check same logs as posted previously around that time.
EDIT: Ow sometimes the logs rotate after reboot so syslog becomes syslog.1 etc.
And logs whith extension .gz can be viewed with:

zcat <LOG_FILENAME.gz>

Or

zless <LOG_FILENAME.gz>

Looks OK.

1 Like

bob@rpibuster:~ $ sudo grep -v '^\s*#|^\s*$' /etc/dhcpcd.conf

[sudo] password di bob:
hostname
clientid
persistent
option rapid_commit
option domain_name_servers, domain_name, domain_search, host_name
option classless_static_routes
option interface_mtu
require dhcp_server_identifier
slaac private
interface eth0
        static ip_address=192.168.1.18/24
        static routers=192.168.1.254
        static domain_name_servers=127.0.0.1

bob@rpibuster:~ $ sudo grep -v '^\s*#|^\s*$' -R /etc/network/interfaces*
/etc/network/interfaces:source-directory /etc/network/interfaces.d

bob@rpibuster:~ $ sudo service network-manager status

● NetworkManager.service - Network Manager
   Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2020-04-30 17:17:05 CEST; 1 day 4h ago
     Docs: man:NetworkManager(8)
 Main PID: 396 (NetworkManager)
    Tasks: 4 (limit: 4915)
   Memory: 18.8M
   CGroup: /system.slice/NetworkManager.service
           ├─396 /usr/sbin/NetworkManager --no-daemon
           └─559 /sbin/dhclient -d -q -sf /usr/lib/NetworkManager/nm-dhcp-helper -pf /run/dhclient-eth0.pid -lf /var/lib/NetworkManager/dhclient-a62a

apr 30 17:45:23 rpibuster NetworkManager[396]: <info>  [1588261523.1737] device (veth4c086c1): state change: config -> ip-config (reason 'none', sys-
apr 30 17:45:23 rpibuster NetworkManager[396]: <info>  [1588261523.1773] dhcp4 (veth4c086c1): activation: beginning transaction (timeout in 45 second
apr 30 17:45:23 rpibuster NetworkManager[396]: <info>  [1588261523.1881] dhcp4 (veth4c086c1): dhclient started with pid 5512
apr 30 17:45:23 rpibuster NetworkManager[396]: <info>  [1588261523.1963] device (veth4c086c1): ipv6: duplicate address check failed for the fe80::2c8
apr 30 17:45:23 rpibuster dhclient[5512]: DHCPDISCOVER on veth4c086c1 to 255.255.255.255 port 67 interval 5
apr 30 17:45:24 rpibuster dhclient[5512]: receive_packet failed on veth4c086c1: Network is down
apr 30 17:45:24 rpibuster NetworkManager[396]: <info>  [1588261524.7237] device (veth4c086c1): state change: ip-config -> unmanaged (reason 'unmanage
apr 30 17:45:24 rpibuster NetworkManager[396]: <info>  [1588261524.7267] dhcp4 (veth4c086c1): canceled DHCP transaction, DHCP client pid 5512
apr 30 17:45:24 rpibuster NetworkManager[396]: <info>  [1588261524.7268] dhcp4 (veth4c086c1): state changed unknown -> done
apr 30 17:45:24 rpibuster NetworkManager[396]: <info>  [1588261524.7865] device (veth972f040): carrier: link connected
bob@rpibuster:~ $ sudo service connman status
Unit connman.service could not be found.

You have two network managers/manglers active that are fighting over who configures the network interfaces:

journalctl --no-pager -u dhcpcd | tail -20

journalctl --no-pager -u network-manager | tail -20

What OS/distro did you install ?

hostnamectl | tail -3

Did you install with a desktop ?

For diagnosing, you could disable/stop network-manager and let dhcpcd5 configure the interfaces:

sudo systemctl disable network-manager

sudo systemctl stop network-manager

sudo reboot

To flip back on again:

sudo systemctl enable network-manager

sudo systemctl start network-manager

1 Like

Thank you SO MUCH for helping.

Distribution is a Raspbian for an headless RPI4 hence minimal distro with no GUI.

bob@rpibuster:~ $ sudo journalctl --no-pager -u dhcpcd | tail -20
[sudo] password di bob:
mag 02 10:17:33 rpibuster dhcpcd[606]: vethb4fcf72: adding route to 169.254.0.0/16
mag 02 10:17:33 rpibuster dhcpcd[606]: if_route (ADD): Invalid argument
mag 02 10:17:33 rpibuster dhcpcd[606]: vethb4fcf72: pid 396 deleted IP address 169.254.222.97/16
mag 02 10:17:33 rpibuster dhcpcd[606]: vethb4fcf72: probing for an IPv4LL address
mag 02 10:17:37 rpibuster dhcpcd[606]: vethb4fcf72: using IPv4LL address 169.254.77.68
mag 02 10:17:37 rpibuster dhcpcd[606]: vethb4fcf72: adding route to 169.254.0.0/16
mag 02 10:18:18 rpibuster dhcpcd[606]: vethb4fcf72: pid 396 deleted route to 169.254.0.0/16
mag 02 10:18:18 rpibuster dhcpcd[606]: vethb4fcf72: adding route to 169.254.0.0/16
mag 02 10:18:18 rpibuster dhcpcd[606]: if_route (ADD): Invalid argument
mag 02 10:18:18 rpibuster dhcpcd[606]: vethb4fcf72: pid 396 deleted IP address 169.254.77.68/16
mag 02 10:18:18 rpibuster dhcpcd[606]: vethb4fcf72: probing for an IPv4LL address
mag 02 10:18:23 rpibuster dhcpcd[606]: vethb4fcf72: using IPv4LL address 169.254.196.180
mag 02 10:18:23 rpibuster dhcpcd[606]: vethb4fcf72: adding route to 169.254.0.0/16
mag 02 10:19:03 rpibuster dhcpcd[606]: vethb4fcf72: pid 396 deleted route to 169.254.0.0/16
mag 02 10:19:03 rpibuster dhcpcd[606]: vethb4fcf72: adding route to 169.254.0.0/16
mag 02 10:19:03 rpibuster dhcpcd[606]: vethb4fcf72: pid 396 deleted IP address 169.254.196.180/16
mag 02 10:19:03 rpibuster dhcpcd[606]: vethb4fcf72: deleting route to 169.254.0.0/16
mag 02 10:19:03 rpibuster dhcpcd[606]: vethb4fcf72: probing for an IPv4LL address
mag 02 10:19:08 rpibuster dhcpcd[606]: vethb4fcf72: using IPv4LL address 169.254.140.21
mag 02 10:19:08 rpibuster dhcpcd[606]: vethb4fcf72: adding route to 169.254.0.0/16

bob@rpibuster:~ $ sudo journalctl --no-pager -u network-manager | tail -20
-- Logs begin at Thu 2020-04-30 17:17:01 CEST, end at Sat 2020-05-02 10:19:52 CEST. --
-- No entries --

bob@rpibuster:~ $ hostnamectl | tail -3
Operating System: Raspbian GNU/Linux 10 (buster)
Kernel: Linux 4.19.97-v7l+
Architecture: arm

Disabled network manager, rebooted and so far system seems ok.

Suggestions for a next step?

Thank you very very much for your help my unknown virtual friend.

Peace and health onto you! :slight_smile:

1 Like

Next step, fingers crossed.
But I suspect those two network manglers running simultaneously was causing the issue.
One still configured to acquire IP details via DHCP and the other trying to keep a static IP.

Many thanks to you too and all others in medical care!

1 Like

This topic was automatically closed 21 days after the last reply. New replies are no longer allowed.