DNS-Resolver-Error after updating: There was a problem applying your settings. PHP error (2): fsockopen(): unable to connect to 127.0.0.1:4711 (Connection refused) in /var/www/html/admin/scripts/pi-hole/php/FTL.php:44

blacksun · July 9, 2022, 9:16am

Hello,

i am updating my rPi4 with raspian bullseye weekly.
one thing of the update-process is to execute
pihole -up

this is executed with user root manually

after doing this today, the DNS-Resolver do not start any more

Message when trying to restart via Webinterface:
There was a problem applying your settings.
Debugging information:
PHP error (2): fsockopen(): unable to connect to 127.0.0.1:4711 (Connection refused) in /var/www/html/admin/scripts/pi-hole/php/FTL.php:44

Debug Token:

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

What can I do?

Bucking_Horn · July 9, 2022, 8:50pm

Your debug log suggests your Pi-hole has been shut down around 2022-07-09 09:21 and wasn't restarted since:

*** [ DIAGNOSING ]: Pi-hole log
-rw-r----- 1 pihole pihole 16M Jul  9 09:21 /var/log/pihole/pihole.log

   -----tail of pihole.log------
   Jul  9 09:21:21 dnsmasq[1522]: exiting on receipt of SIGTERM

*** [ DIAGNOSING ]: contents of /var/log/pihole
-rw-r--r-- 1 pihole pihole 4.9K Jul  9 09:21 /var/log/pihole/FTL.log

   -----tail of FTL.log------
   [2022-07-09 09:21:21.106 1522M] Shutting down...
   [2022-07-09 09:21:21.418 1522M] Finished final database update (stored 76 queries)
   [2022-07-09 09:21:21.418 1522M] Waiting for threads to join
   [2022-07-09 09:21:21.419 1522M] Thread telnet-IPv4 (0) is idle, terminating it.
   [2022-07-09 09:21:21.419 1522M] Thread telnet-socket (2) is idle, terminating it.
   [2022-07-09 09:21:21.419 1522M] Thread database (3) is idle, terminating it.
   [2022-07-09 09:21:21.420 1522M] Thread housekeeper (4) is idle, terminating it.
   [2022-07-09 09:21:21.420 1522M] Thread DNS client (5) is idle, terminating it.
   [2022-07-09 09:21:21.420 1522M] All threads joined
   [2022-07-09 09:21:21.430 1522M] ########## FTL terminated after 4d 16h 20m 2s  (code 0)! ##########

Did you try to restart it yet, e.g. by running

sudo service pihole-FTL restart

blacksun · July 9, 2022, 9:30pm

yes, of course, i rebooted the whole machine, but no change

is it possible that it is a problem of wrong user-rights?
pihole uses the user pihole.
but I run the command pihole up with user root.

have you seen the
Failed to open log file. Check permissions!

Bucking_Horn · July 10, 2022, 6:11am

What's the output of the folllowing commands:

sudo service pihole-FTL restart

sudo systemctl status --full --no-pager pihole-FTL

blacksun · July 10, 2022, 8:39am

root@blackPI:~# service pihole-FTL restart
root@blackPI:~# sudo systemctl status --full --no-pager pihole-FTL
● pihole-FTL.service - LSB: pihole-FTL daemon
     Loaded: loaded (/etc/init.d/pihole-FTL; generated)
     Active: active (exited) since Sun 2022-07-10 10:37:23 CEST; 19s ago
       Docs: man:systemd-sysv-generator(8)
    Process: 10306 ExecStart=/etc/init.d/pihole-FTL start (code=exited, status=0/SUCCESS)
        CPU: 66ms

Jul 10 10:37:22 blackPI systemd[1]: Starting LSB: pihole-FTL daemon...
Jul 10 10:37:22 blackPI pihole-FTL[10306]: Not running
Jul 10 10:37:22 blackPI su[10334]: (to pihole) root on none
Jul 10 10:37:22 blackPI su[10334]: pam_unix(su:session): session opened for user pihole(uid=999) by (uid=0)
Jul 10 10:37:23 blackPI su[10334]: pam_unix(su:session): session closed for user pihole
Jul 10 10:37:23 blackPI systemd[1]: Started LSB: pihole-FTL daemon.
root@blackPI:~#

I also tried a repair-installation:
pihole -r
Nothing chanced
So I suppose, uninstall - reinstall wouldnt chance anything

No Firewall is installed
IPv6 is disabled

root@blackPI:~# netstat -nltup
Aktive Internetverbindungen (Nur Server)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name    
tcp        0      0 10.0.9.1:14434          0.0.0.0:*               LISTEN      840/qbittorrent-nox 
tcp        0      0 0.0.0.0:8888            0.0.0.0:*               LISTEN      1042/perl           
tcp        0      0 127.0.0.1:14434         0.0.0.0:*               LISTEN      840/qbittorrent-nox 
tcp        0      0 0.0.0.0:666             0.0.0.0:*               LISTEN      991/apache2         
tcp        0      0 0.0.0.0:667             0.0.0.0:*               LISTEN      991/apache2         
tcp        0      0 0.0.0.0:45678           0.0.0.0:*               LISTEN      991/apache2         
tcp        0      0 192.168.98.1:14434      0.0.0.0:*               LISTEN      840/qbittorrent-nox 
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      9755/lighttpd       
tcp        0      0 127.0.0.1:39677         0.0.0.0:*               LISTEN      3498/cockpit-bridge 
tcp        0      0 192.168.3.102:14434     0.0.0.0:*               LISTEN      840/qbittorrent-nox 
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      748/sshd: /usr/sbin 
tcp        0      0 0.0.0.0:2525            0.0.0.0:*               LISTEN      1834/master         
tcp        0      0 0.0.0.0:55554           0.0.0.0:*               LISTEN      809/openvpn         
tcp        0      0 0.0.0.0:55552           0.0.0.0:*               LISTEN      638/stunnel4        
tcp        0      0 127.0.0.1:3306          0.0.0.0:*               LISTEN      801/mysqld          
tcp        0      0 192.168.99.1:14434      0.0.0.0:*               LISTEN      840/qbittorrent-nox 
tcp        0      0 10.0.8.1:14434          0.0.0.0:*               LISTEN      840/qbittorrent-nox 
tcp        0      0 0.0.0.0:5900            0.0.0.0:*               LISTEN      743/vncserver-x11-c 
tcp6       0      0 :::9090                 :::*                    LISTEN      1/init              
tcp6       0      0 :::80                   :::*                    LISTEN      9755/lighttpd       
tcp6       0      0 :::22                   :::*                    LISTEN      748/sshd: /usr/sbin 
tcp6       0      0 :::2525                 :::*                    LISTEN      1834/master         
tcp6       0      0 :::7777                 :::*                    LISTEN      840/qbittorrent-nox 
tcp6       0      0 :::5900                 :::*                    LISTEN      743/vncserver-x11-c 
udp        0      0 0.0.0.0:55553           0.0.0.0:*                           811/openvpn         
udp        0      0 0.0.0.0:45536           0.0.0.0:*                           484/avahi-daemon: r 
udp        0      0 0.0.0.0:530             0.0.0.0:*                           29171/iodined       
udp        0      0 0.0.0.0:51820           0.0.0.0:*                           -                   
udp        0      0 0.0.0.0:5353            0.0.0.0:*                           484/avahi-daemon: r 
udp        0      0 0.0.0.0:68              0.0.0.0:*                           345/dhclient        
udp        0      0 192.168.99.1:14434      0.0.0.0:*                           840/qbittorrent-nox 
udp        0      0 192.168.98.1:14434      0.0.0.0:*                           840/qbittorrent-nox 
udp        0      0 10.0.9.1:14434          0.0.0.0:*                           840/qbittorrent-nox 
udp        0      0 10.0.8.1:14434          0.0.0.0:*                           840/qbittorrent-nox 
udp        0      0 192.168.3.102:14434     0.0.0.0:*                           840/qbittorrent-nox 
udp        0      0 127.0.0.1:14434         0.0.0.0:*                           840/qbittorrent-nox 
udp6       0      0 :::51820                :::*

before Update of pihole, I updated these raspian-packages via apt update and apt upgrade

Start-Date: 2022-07-09  09:12:32
Commandline: apt upgrade
Upgrade: firmware-brcm80211:armhf (1:20210315-3+rpt6, 1:20210315-3+rpt7), libavdevice58:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), ffmpeg:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), libpostproc55:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), libavcodec58:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), firmware-realtek:armhf (1:20210315-3+rpt6, 1:20210315-3+rpt7), firmware-libertas:armhf (1:20210315-3+rpt6, 1:20210315-3+rpt7), libavutil56:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), firmware-misc-nonfree:armhf (1:20210315-3+rpt6, 1:20210315-3+rpt7), libswscale5:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), libswresample3:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), libavformat58:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), libavresample4:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2), libavfilter7:armhf (7:4.3.4-0+deb11u1+rpt1, 7:4.3.4-0+deb11u1+rpt2)
End-Date: 2022-07-09  09:13:22

Is there anything which can caused the problem?

everything was ok, then
apt update and apt upgrade
pihole up
then the problem was occured

//EDIT:
new log from today, after a new apt update and apt upgrade and reboot
https://tricorder.pi-hole.net/mADg1Qm1/

//EDIT:
have you seen these things in debug-log:

 2022-07-09 09:45:31: mod_fastcgi.c.487) FastCGI-stderr:PHP Warning:  fopen(/var/log/pihole/pihole.log): failed to open stream: Permission denied in /var/www/html/admin/scripts/pi-hole/php/tailLog.php on line 21

   [2022-07-09 00:29:22.180 1522M] ERR: Port mismatch for 9.9.9.11: we derived 53, dnsmasq told us 48
   [2022-07-09 00:29:22.180 1522M] ERR: Port mismatch for 149.112.112.11: we derived 53, dnsmasq told us 48

   2022-07-09 09:21:23: configfile.c.1142) WARNING: unknown config-key: alias.url (ignored)

Bucking_Horn · July 10, 2022, 12:36pm

Yes, I've seen those.
The port mismatch is wrongly reported, but that has to be addressed by dnsmasq maintainers, and the alias warning can be ignored as well.
The stream open failure is an error reported by the web server and by itself wouldn't affect DNS resolution.

I was hoping my suggested commands would turn up tangible pointers to your issue, but they didn't come back with anything useful.

Please run the following syntax check on your dnsmasq configuration:

pihole-FTL --test

Let's also check your general system logs for errors:

dmesg --level emerg,alert,crit,err

And what's the output of:

ls -lah /var/log/pihole

blacksun · July 10, 2022, 1:48pm

I installed the update you released today

the results:

root@blackPI:~# pihole-FTL --test
dnsmasq: syntax check OK.
root@blackPI:~# dmesg --level emerg,alert,crit,err
[    2.456933] usbhid 1-1.1:1.0: couldn't find an input interrupt endpoint
[    4.173778] systemd[1]: network.target: Job networking-routes.service/start deleted to break ordering cycle starting with network.target/start
root@blackPI:~# ls -lah /var/log/pihole
insgesamt 59M
drw-rw----  2 pihole pihole 4,0K  9. Jul 09:21 .
drwxr-xr-x 15 root   root   4,0K 10. Jul 11:59 ..
-rw-r--r--  1 pihole pihole 4,9K  9. Jul 09:21 FTL.log
-rw-r--r--  1 pihole pihole  28K  9. Jul 00:00 FTL.log.1
-rw-r--r--  1 pihole pihole 2,3K  8. Jul 00:00 FTL.log.2.gz
-rw-r--r--  1 pihole pihole 2,6K  7. Jul 00:00 FTL.log.3.gz
-rw-r-----  1 root   pihole 418K 10. Jul 11:52 pihole_debug.log
-rw-r--r--  1 pihole pihole  25K 16. Jan 2020  pihole_debug.txt
-rw-r-----  1 pihole pihole  16M  9. Jul 09:21 pihole.log
-rw-r--r--  1 pihole pihole  37M  9. Jul 00:00 pihole.log.1
-rw-r--r--  1 pihole pihole 1,6M  8. Jul 00:00 pihole.log.2.gz
-rw-r--r--  1 pihole pihole 1,7M  7. Jul 00:00 pihole.log.3.gz
-rw-r--r--  1 pihole pihole 1,7M  6. Jul 00:00 pihole.log.4.gz
-rw-r--r--  1 pihole pihole 1,6M  5. Jul 00:00 pihole.log.5.gz
-rw-rw----  1 pihole pihole  30K 10. Jul 03:15 pihole_updateGravity.log
root@blackPI:~#

deHakkelaar · July 10, 2022, 4:43pm

pi@ph5b:~ $ apt-file search networking-routes.service
ifupdown-extra: /lib/systemd/system/networking-routes.service

pi@ph5b:~ $ apt show ifupdown-extra
[..]
Description: Network scripts for ifupdown
 This package provides a set of network testing scripts to be used together
 with the ifupdown package. These scripts can:
   - check the network cable before an interface is configured.
   - test if an assigned IPv4 or IPv6 address is already in use in the network.
   - test if default network gateways are reachable.
   - setup default static routes for interfaces.
 .
 Additionally network static routes can also be defined globally for the
 system when this is needed (e.g. for 'reject' rules) and will be
 added after network initialisation.
 .
 This package also provides 'network-test', a script to test the network
 configuration status by checking:
   - Status of available interface.
   - Availability of configured gateway routes.
   - If host resolution is working properly (DNS checks).
   - If network connectivity is working, including ICMP and web connections to
     remote web servers.

I wonder if this ifupdown-extra package is interfering with the workings of the default network manager called dhcpcd thats installed OOTB with Pi-OS/Raspbian:

pi@ph5b:~ $ apt policy ifupdown-extra
ifupdown-extra:
  Installed: (none)
[..]

pi@ph5b:~ $ apt policy dhcpcd5
dhcpcd5:
  Installed: 1:8.1.2-1+rpt5
[..]

What does below one show?

journalctl --full --no-pager -u networking-routes.service

blacksun · July 10, 2022, 5:15pm

the result:

root@blackPI:~# journalctl --full --no-pager -u networking-routes.service
-- Journal begins at Mon 2022-02-28 17:30:42 CET, ends at Sun 2022-07-10 19:14:06 CEST. --
Apr 03 19:39:35 blackPI systemd[1]: Starting Establish global networking routes for the system...
Apr 03 19:39:36 blackPI networking-routes[274]: Configuring network routes...done.
Apr 03 19:39:36 blackPI systemd[1]: Finished Establish global networking routes for the system.
Apr 07 09:12:56 blackPI systemd[1]: Stopping Establish global networking routes for the system...
Apr 07 09:12:57 blackPI networking-routes[23133]: Deconfiguring network routes...done.
Apr 07 09:12:57 blackPI systemd[1]: networking-routes.service: Succeeded.
Apr 07 09:12:57 blackPI systemd[1]: Stopped Establish global networking routes for the system.
-- Boot 1ac9dfe66b634bee804d5feaa97872a0 --
Apr 29 19:19:38 blackPI systemd[1]: Starting Establish global networking routes for the system...
Apr 29 19:19:38 blackPI networking-routes[304]: Configuring network routes...done.
Apr 29 19:19:38 blackPI systemd[1]: Finished Establish global networking routes for the system.
Mai 16 16:53:26 blackPI systemd[1]: Stopping Establish global networking routes for the system...
Mai 16 16:53:27 blackPI networking-routes[30965]: Deconfiguring network routes...done.
Mai 16 16:53:27 blackPI systemd[1]: networking-routes.service: Succeeded.
Mai 16 16:53:27 blackPI systemd[1]: Stopped Establish global networking routes for the system.
root@blackPI:~#

but I didnt change anything in the last months. I didnt neither install nor removed an package which has anything to do with network connectivity

deHakkelaar · July 10, 2022, 5:18pm

What if you disable that one temporarily with below:

sudo systemctl disable networking-routes.service

And reboot for testing.
Can enable again with:

sudo systemctl enable --now networking-routes.service

blacksun · July 10, 2022, 5:28pm

done
nothing changed

by the way, the service was enabled, but not running

//EDIT:
Do I think right:
pihole-part acts as "Server service" on port 4711, and FTL acts as client and want to connect to pihole-service with localhost:4711?
Because netstat do not show a service running on 4711, FTL is not the problem, but pihole?

deHakkelaar · July 10, 2022, 5:33pm

One more, what does below ones output?

nc -vz 127.0.0.1 4711

nc -vz 127.0.0.1 14434

ip -br a s lo

Any local firewall installed and active?

deHakkelaar · July 10, 2022, 5:40pm

The pihole-FTL binary/daemon should be listening on that port:

pi@ph5b:~ $ sudo netstat -nltup | grep 'Proto\|:4711 '
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 127.0.0.1:4711          0.0.0.0:*               LISTEN      32260/pihole-FTL
tcp6       0      0 ::1:4711                :::*                    LISTEN      32260/pihole-FTL

And the web GUI is querying this port.
But pihole-FTL can only bind to that 127.0.0.1 IP if nothing wrong with it or no firewall blocking.

blacksun · July 10, 2022, 5:44pm

root@blackPI:~# nc -vz 127.0.0.1 4711
nc: connect to 127.0.0.1 port 4711 (tcp) failed: Connection refused
root@blackPI:~# nc -vz 127.0.0.1 14434
Connection to 127.0.0.1 14434 port [tcp/*] succeeded!
root@blackPI:~# ip -br a s lo
lo               UNKNOWN        127.0.0.1/8 
root@blackPI:~#

see my posting above, no firewall
14434 is the server-port of my qBittorrent-Instance

by the way, see my EDIT above, it's not a network-issue, it's a problem of pihole, right?

deHakkelaar · July 10, 2022, 5:47pm

Not sure.
~~Do you know why the IPv6 address ::1 is lacking?~~

~~pi@ph5b:~ $ ip -br a s lo lo UNKNOWN 127.0.0.1/8 ::1/128~~

EDIT: Ow ps, I dont think its related.
Wait for a dev or mod for a possible answer.

EDIT2: Aha I see:

blacksun · July 12, 2022, 7:11am

@Bucking_Horn
do you have any update for me?
Is there anything that I can do?

Bucking_Horn · July 12, 2022, 8:25am

Those results didn't produce any hints.
Could you also provide

ls -lah /var/log/pihole*.log

From your latest debug log mADg1Qm1, pihole-FTL is reported as running:

*** [ DIAGNOSING ]: Pi-hole processes
[✓] lighttpd daemon is active
[✓] pihole-FTL daemon is active

But at the same time, it seems it failed to bind any of its ports, 53 and 4711, and possibly 67 and 547 if Pi-hole has been configured for DHCP/DHCPv6 (click for debug log details):

*** [ DIAGNOSING ]: Ports in use
    udp:192.168.3.102:5353 is in use by dotnet
    udp:0.0.0.0:5353 is in use by dotnet
    udp:0.0.0.0:5353 is in use by avahi-daemon
    udp:0.0.0.0:3478 is in use by dotnet
    udp:0.0.0.0:59312 is in use by avahi-daemon
    udp:0.0.0.0:68 is in use by dhclient
    udp:192.168.98.1:14434 is in use by qbittorrent-nox
    udp:10.0.9.1:14434 is in use by qbittorrent-nox
    udp:10.0.8.1:14434 is in use by qbittorrent-nox
    udp:192.168.99.1:14434 is in use by qbittorrent-nox
    udp:192.168.3.102:14434 is in use by qbittorrent-nox
    udp:127.0.0.1:14434 is in use by qbittorrent-nox
    udp:0.0.0.0:55553 is in use by openvpn
    udp:0.0.0.0:530 is in use by iodined
    udp:0.0.0.0:51820 is in use by <unknown>
    udp:*:51820 is in use by <unknown>
    tcp:0.0.0.0:22 is in use by sshd
    tcp:0.0.0.0:8888 is in use by rpimonitord
    tcp:0.0.0.0:8090 is in use by dotnet
    tcp:0.0.0.0:666 is in use by apache2
    tcp:0.0.0.0:667 is in use by apache2
    tcp:0.0.0.0:2525 is in use by master
    tcp:0.0.0.0:55552 is in use by stunnel4
    tcp:192.168.98.1%wg0:14434 is in use by qbittorrent-nox
    tcp:10.0.9.1%tun1:14434 is in use by qbittorrent-nox
    tcp:10.0.8.1%tun0:14434 is in use by qbittorrent-nox
    tcp:192.168.99.1%dns0:14434 is in use by qbittorrent-nox
    tcp:192.168.3.102%wlan0:14434 is in use by qbittorrent-nox
    tcp:127.0.0.1%lo:14434 is in use by qbittorrent-nox
    tcp:0.0.0.0:55554 is in use by openvpn
    tcp:127.0.0.1:3306 is in use by mysqld
    tcp:0.0.0.0:5900 is in use by vncserver-x11-c
    tcp:0.0.0.0:45678 is in use by apache2
[✓] tcp:0.0.0.0:80 is in use by lighttpd
    tcp:[::]:22 is in use by sshd
    tcp:[::]:2525 is in use by master
    tcp:*:7777 is in use by qbittorrent-nox
    tcp:*:9090 is in use by systemd
    tcp:[::]:5900 is in use by vncserver-x11-c
[✓] tcp:[::]:80 is in use by lighttpd

There may be a port conflict over 5353 (avahi and dotnet both claiming the offcial mDNS port), but that certainly is not related to Pi-hole.

More often than not, that would suggest a firewall on the machine hosting Pi-hole would be blocking Pi-hole's ports.

But it's strange that pihole-FTL would not even log its new startup attempts, as your log still shows it as having been terminated on 2022-07-09 as its last entry:

*** [ DIAGNOSING ]: contents of /var/log/pihole
-rw-r--r-- 1 pihole pihole 4.9K Jul  9 09:21 /var/log/pihole/FTL.log

   -----tail of FTL.log------
   [2022-07-09 09:21:21.106 1522M] Shutting down...
   (...)
   [2022-07-09 09:21:21.430 1522M] ########## FTL terminated after 4d 16h 20m 2s  (code 0)! ##########

deHakkelaar · July 12, 2022, 6:13pm

Below ones dump the rules in the nf_tables module:

sudo iptables -nL

sudo nft list tables

FYI:

pi@ph5b:~ $ lsmod
Module                  Size  Used by
nf_tables             200704  0
[..]

pi@ph5b:~ $ modinfo nf_tables
filename:       /lib/modules/5.10.92+/kernel/net/netfilter/nf_tables.ko
alias:          nfnetlink-subsys-10
author:         Patrick McHardy <kaber@trash.net>
license:        GPL
srcversion:     88909CB365A49A17A4E5873
depends:        nfnetlink
intree:         Y
name:           nf_tables
vermagic:       5.10.92+ mod_unload modversions ARMv6 p2v8

blacksun · July 13, 2022, 11:56am

root@blackPI:/var/log# ls -lah /var/log/pihole*.log
lrwxrwxrwx 1 pihole pihole 23  9. Jul 09:21 /var/log/pihole-FTL.log -> /var/log/pihole/FTL.log
lrwxrwxrwx 1 pihole pihole 26  9. Jul 09:21 /var/log/pihole.log -> /var/log/pihole/pihole.log
root@blackPI:/var/log#

nothing

blacksun · July 13, 2022, 2:49pm

because the problem occured with an update of pihole, is it possible to downgrade?

regard the problem, what can I do help you to find the problem?