Hi Markus
thanks for having a look.
I have switched browsers (Firefox, Chrome) and the issue persists. The VM has been re-started, also the issue persists.
Again, the issue is: even though Nethsecurity makes the PPPOE connection, and WAN is up and running, the Web GUI reports that “Internet Connections Unknown” and any functionality dealing with the internet connection (reports, stats, status, update check, blocklist download, etc.) doesn’t work.
To the Logs:
This sticks out:
dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:28:53 castis dnsmasq[1]: FAILED to start up
procd: Instance dnsmasq::cfg01411c s in a crash loop 6 crashes, 0 seconds since last crash
Wow, so dnsmasq is broken because… there is a duplicate IP defined as both a DHCP static lease and as a separate DNS entry?! So NAT is broken and DNS is broken and everything? Because of a local DHCP static lease???
Here all the logs from bootup (skipping the normal kernel stuff, which I can also provide if they are useful):
Feb 16 01:28:53 ns_server kernel: [ 4.429341] xt_time: kernel timezone is -0000
Feb 16 01:28:53 ns_server kernel: [ 4.445231] PPP generic driver version 2.4.2
Feb 16 01:28:53 ns_server kernel: [ 4.446778] NET: Registered PF_PPPOX protocol family
Feb 16 01:28:53 ns_server kernel: [ 4.448473] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
Feb 16 01:28:53 ns_server kernel: [ 4.449347] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
Feb 16 01:28:53 ns_server kernel: [ 6.615549] 8021q: adding VLAN 0 to HW filter on device eth0
Feb 16 01:28:53 ns_server kernel: [ 6.616405] br-lan: port 1(eth0) entered blocking state
Feb 16 01:28:53 ns_server kernel: [ 6.616995] br-lan: port 1(eth0) entered disabled state
Feb 16 01:28:53 ns_server kernel: [ 6.617664] device eth0 entered promiscuous mode
Feb 16 01:28:53 ns_server kernel: [ 6.618471] br-lan: port 1(eth0) entered blocking state
Feb 16 01:28:53 ns_server kernel: [ 6.619112] br-lan: port 1(eth0) entered forwarding state
Feb 16 01:28:53 ns_server kernel: [ 6.621709] 8021q: adding VLAN 0 to HW filter on device eth1
Feb 16 01:28:53 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:28:53 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:28:53 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:28:53 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:28:54 ns_server netifyd[5549]: Netify Agent/4.4.3 (openwrt; x86_64; conntrack; netlink; dns-cache; plugins; regex)
Feb 16 01:28:54 ns_server netifyd[5549]: Unable to hash file: /etc/netify.d/netify-sink.conf: No such file or directory
Feb 16 01:28:54 ns_server netifyd[5549]: Legacy category format detected: /etc/netify.d/netify-categories.json
Feb 16 01:28:54 ns_server netifyd[5549]: Legacy category format detected: /etc/netify.d/netify-categories.json
Feb 16 01:28:54 ns_server netifyd[5549]: Error opening directory: /etc/netify.d/domains.d: No such file or directory
Feb 16 01:28:54 ns_server netifyd[5549]: np-nfa: Netify Agent Flow Actions Plugin, v1.0.13
Feb 16 01:28:54 ns_server netifyd[5549]: np-nfa: Copyright (C) 2022 eGloo Incorporated.
Feb 16 01:28:54 ns_server netifyd[5549]: np-nfa: flow action targets: ctlabel, log, nftset
Feb 16 01:28:54 ns_server kernel: [ 11.869836] device br-lan entered promiscuous mode
Feb 16 01:28:54 ns_server kernel: [ 11.870757] device eth1 entered promiscuous mode
Feb 16 01:28:54 ns_server netifyd[5549]: np-stats: Netify Agent Stats Plugin v1.0.17 (C) 2021 eGloo Incorporated.
Feb 16 01:28:56 ns_server dpireport[3750]: INFO: Connected to socket
Feb 16 01:28:56 ns_server netifyd[5549]: Unhandled signal: RT35
Feb 16 01:28:58 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:28:58 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:02 ns_server netifyd[5549]: nap-api-update: Error: 6
Feb 16 01:29:03 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:03 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:04 ns_server pppd[2833]: Timeout waiting for PADO packets
Feb 16 01:29:04 ns_server pppd[2833]: Unable to complete PPPoE Discovery
Feb 16 01:29:04 ns_server pppd[2833]: Exit.
Feb 16 01:29:04 ns_server netifd: Interface 'wan' is now down
Feb 16 01:29:04 ns_server netifd: Interface 'wan' is setting up now
Feb 16 01:29:04 ns_server pppd[5662]: Plugin pppoe.so loaded.
Feb 16 01:29:04 ns_server pppd[5662]: PPPoE plugin from pppd 2.4.9
Feb 16 01:29:04 ns_server pppd[5662]: pppd 2.4.9 started by root, uid 0
Feb 16 01:29:04 ns_server pppd[5662]: PPP session is 174
Feb 16 01:29:04 ns_server pppd[5662]: Connected to xx:xx:xx:xx:xx:xx via interface eth1
Feb 16 01:29:04 ns_server kernel: [ 22.199902] pppoe-wan: renamed from ppp0
Feb 16 01:29:04 ns_server pppd[5662]: Renamed interface ppp0 to pppoe-wan
Feb 16 01:29:04 ns_server pppd[5662]: Using interface pppoe-wan
Feb 16 01:29:04 ns_server pppd[5662]: Connect: pppoe-wan <--> eth1
Feb 16 01:29:06 ns_server nginx: ::1 - - [16/Feb/2025:01:29:06 +0100] "GET /api/v2/stats HTTP/1.1" 400 255 "-" "python-urllib3/2.0.4"
Feb 16 01:29:08 ns_server pppd[5662]: Remote message: SRU=XXXXXX#SRD=XXXXXX#
Feb 16 01:29:08 ns_server pppd[5662]: PAP authentication succeeded
Feb 16 01:29:08 ns_server pppd[5662]: peer from calling number XX:XX:XX:XX:XX:XX authorized
Feb 16 01:29:08 ns_server pppd[5662]: local IP address XX.XXX.XX.XXX
Feb 16 01:29:08 ns_server pppd[5662]: remote IP address XX.XXX.XXX.XXX
Feb 16 01:29:08 ns_server pppd[5662]: primary DNS address XXX.XXX.XXX.XXX
Feb 16 01:29:08 ns_server pppd[5662]: secondary DNS address XXX.XXX.XXX.XXX
Feb 16 01:29:08 ns_server pppd[5662]: local LL address XXXX::XXXX:XXXX:XXXX:XXXX
Feb 16 01:29:08 ns_server pppd[5662]: remote LL address XXXX::XXXX:XXXX:XXXX:XXXX
Feb 16 01:29:08 ns_server netifd: Network device 'pppoe-wan' link is up
Feb 16 01:29:08 ns_server netifd: Interface 'wan' is now up
Feb 16 01:29:08 ns_server netifd: Network alias 'pppoe-wan' link is up
Feb 16 01:29:08 ns_server netifd: Interface 'wan_6' is enabled
Feb 16 01:29:08 ns_server netifd: Interface 'wan_6' has link connectivity
Feb 16 01:29:08 ns_server netifd: Interface 'wan_6' is setting up now
Feb 16 01:29:08 ns_server qosify: start interface pppoe-wan
Feb 16 01:29:08 ns_server mwan3-hotplug[6032]: mwan3 hotplug on wan not called because interface disabled
Feb 16 01:29:08 ns_server firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Feb 16 01:29:08 ns_server firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Feb 16 01:29:08 ns_server ddns-scripts[6259]: myddns_ipv4: PID '6259' started at 2025-02-16 01:29
Feb 16 01:29:08 ns_server ddns-scripts[6259]: myddns_ipv4: Service section disabled! - TERMINATE
Feb 16 01:29:08 ns_server ddns-scripts[6259]: myddns_ipv4: PID '6259' exit WITH ERROR '1' at 2025-02-16 01:29
Feb 16 01:29:08 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:08 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:08 ns_server procd: Instance dnsmasq::cfg01411c s in a crash loop 6 crashes, 0 seconds since last crash
Feb 16 01:29:10 ns_server banIP-[4157]: start banIP processing (boot)
Feb 16 01:29:10 ns_server banIP-[4157]: add uplink 'XX.XXX.XX.XXX/32' to local allowlist
Feb 16 01:29:10 ns_server banIP-[4157]: add uplink 'XXXX::XXXX:XXXX:XXXX:XXX/128' to local allowlist
Feb 16 01:29:10 ns_server banIP-[4157]: initialize banIP nftables namespace
Feb 16 01:29:10 ns_server banIP-[4157]: start banIP download processes
Feb 16 01:29:23 ns_server login[1140]: root login on 'tty1'
Feb 16 01:29:23 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:23 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:28 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:28 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:33 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:33 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:38 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:38 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:43 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:43 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:44 ns_server adblock-4.1.5[2665]: dns backend 'dnsmasq' not running or executable
Feb 16 01:29:46 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:46 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:51 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:51 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:29:56 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:29:56 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:30:00 ns_server crond[2944]: USER root pid 7826 cmd /usr/bin/ns-objects-reload-dns
Feb 16 01:30:00 ns_server crond[2944]: USER root pid 7827 cmd sleep $(( RANDOM % 60 )); /usr/sbin/send-heartbeat
Feb 16 01:30:01 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:30:01 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:30:06 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:30:06 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:30:11 ns_server dnsmasq[1]: duplicate dhcp-host IP address 192.168.0.216 at line 58 of /var/etc/dnsmasq.conf.cfg01411c
Feb 16 01:30:11 ns_server dnsmasq[1]: FAILED to start up
Feb 16 01:30:11 ns_server procd: Instance dnsmasq::cfg01411c s in a crash loop 6 crashes, 0 seconds since last crash
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET / HTTP/1.1" 200 391 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /assets/index-BtOPPq6e.js HTTP/1.1" 200 1019369 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /assets/index-DxM9mes3.css HTTP/1.1" 200 86250 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /branding.js HTTP/1.1" 200 244 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /login_logo.svg HTTP/1.1" 200 9628 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /assets/StandaloneDashboardView-DTcv6zW7.js HTTP/1.1" 200 17678 "https://192.168.0.1/assets/index-BtOPPq6e.js" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /Poppins-Regular.ttf HTTP/1.1" 200 158240 "https://192.168.0.1/assets/index-DxM9mes3.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:28 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:28 +0100] "GET /favicon.ico HTTP/1.1" 200 4286 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:30:30 ns_server banIP-[4157]: download for feed 'allowlist' failed (rc: 6/log: curl: (6) Could not resolve host: bl.nethesis.it#012curl: (6) Could not resolve host: bl.nethesis.it#012curl: (6) Could not resolve host: bl.nethesis.it#012curl: (6) Could not resolve host: bl.nethesis.it#012curl: (6) Could not resolve host: bl.nethesis.it#012curl: (6) Could not resolve host: bl.nethesis.it)
Feb 16 01:30:30 ns_server banIP-[4157]: start banIP domain lookup
Feb 16 01:30:30 ns_server banIP-[4157]: domain lookup finished in 0m 0s (blocklist, 0 domains, 0 IPs)
Feb 16 01:30:30 ns_server banIP-[4157]: domain lookup finished in 0m 0s (allowlist, 0 domains, 0 IPs)
Feb 16 01:30:30 ns_server banIP-[4157]: start detached banIP log service (/usr/bin/tail)
Feb 16 01:30:35 ns_server nethsecurity-api[4514]: nethsecurity_api 2025/02/16 01:30:35 middleware.go:77: [INFO][AUTH] authentication success for user root from 192.168.0.11
Feb 16 01:30:35 ns_server nethsecurity-api[4514]: nethsecurity_api 2025/02/16 01:30:35 middleware.go:185: [INFO][AUTH] login response success for user root
Feb 16 01:30:35 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:30:35 +0100] "POST /api/login HTTP/1.1" 200 256 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:31:08 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:31:08 +0100] "POST /api/2fa/otp-verify HTTP/1.1" 200 237 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:31:08 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:31:08 +0100] "GET /logo_light.svg HTTP/1.1" 200 9679 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:31:08 ns_server nethsecurity-api[4514]: nethsecurity_api 2025/02/16 01:31:08 middleware.go:169: [INFO][AUTH] authorization success for user root. POST /api/ubus/call {"path":"uci","method":"changes","payload":{}}
Feb 16 01:31:08 ns_server nethsecurity-api[4514]: nethsecurity_api 2025/02/16 01:31:08 middleware.go:169: [INFO][AUTH] authorization success for user root. POST /api/ubus/call {"path":"system","method":"board","payload":{}}
Feb 16 01:31:08 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:31:08 +0100] "POST /api/ubus/call HTTP/1.1" 200 281 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"
Feb 16 01:31:08 ns_server nginx: 192.168.0.11 - - [16/Feb/2025:01:31:08 +0100] "POST /api/ubus/call HTTP/1.1" 200 88 "https://192.168.0.1/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36"