Delay in sending WAN DDNS change notices
-
@stephenw10 the gateway/WAN was not down for 26 hours . Any outages are typically very short. I was on my network on June 3rd at 7:09am when I lost connectivity, but it was back within a minute or two. My DDNS provider did not get updated until 18 hours later and the messaging to me was also delayed by the same amount
Sorry, I am not really familiar with all the logs and thier purpose
Here is data from my system log
Jun 4 02:51:00 sshguard 93056 Now monitoring attacks.
Jun 4 02:51:00 sshguard 53357 Exiting on signal.
Jun 4 02:21:00 sshguard 53357 Now monitoring attacks.
Jun 4 02:21:00 sshguard 7477 Exiting on signal.
Jun 4 01:50:00 sshguard 7477 Now monitoring attacks.
Jun 4 01:50:00 sshguard 68319 Exiting on signal.
Jun 4 01:20:00 sshguard 68319 Now monitoring attacks.
Jun 4 01:20:00 sshguard 53579 Exiting on signal.
Jun 4 01:01:16 php-cgi 36618 notify_monitor.php: Message sent to <my email> OK
Jun 4 01:01:04 php-cgi 70826 rc.dyndns.update: phpDynDNS (my DDNS): (Success) IP Address Changed Successfully!
Jun 4 01:01:04 php-cgi 70826 rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_wannoip-free'my DDNS name'0.cache: xx.xx.131.159
Jun 4 00:49:00 sshguard 53579 Now monitoring attacks.
Jun 4 00:49:00 sshguard 18917 Exiting on signal.
Jun 4 00:19:00 sshguard 18917 Now monitoring attacks.
Jun 4 00:19:00 sshguard 85843 Exiting on signal.< removed 66 lines of the same as above & below >
Jun 3 07:50:00 sshguard 91527 Now monitoring attacks.
Jun 3 07:50:00 sshguard 86362 Exiting on signal.
Jun 3 07:21:00 sshguard 86362 Now monitoring attacks.
Jun 3 07:21:00 sshguard 47943 Exiting on signal.
Jun 3 07:15:05 php-fpm 1881 /index.php: User logged out for user <me on local connection> (Local Database)
Jun 3 07:15:00 sshguard 47943 Now monitoring attacks.
Jun 3 07:15:00 sshguard 48758 Exiting on signal.
Jun 3 07:10:35 ppp 60140 [wan] IPV6CP: LayerFinish
Jun 3 07:10:35 ppp 60140 [wan] IPV6CP: state change Req-Sent --> Stopped
Jun 3 07:10:35 ppp 60140 [wan] IPV6CP: parameter negotiation failed
Jun 3 07:10:33 ppp 60140 [wan] IPV6CP: SendConfigReq #70
Jun 3 07:10:31 ppp 60140 [wan] IPV6CP: SendConfigReq #69
Jun 3 07:10:29 ppp 60140 [wan] IPV6CP: SendConfigReq #68
Jun 3 07:10:27 ppp 60140 [wan] IPV6CP: SendConfigReq #67
Jun 3 07:10:27 php-fpm 1555 /rc.start_packages: Restarting/Starting all packages.
Jun 3 07:10:26 check_reload_status 1603 Reloading filter
Jun 3 07:10:26 check_reload_status 1603 Starting packages
Jun 3 07:10:26 php-fpm 24683 /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - xx.xx.149.254 -> xx.xx.131.159 - Restarting packages.
Jun 3 07:10:25 ppp 60140 [wan] IPV6CP: SendConfigReq #66
Jun 3 07:10:24 php-fpm 24683 /rc.newwanip: Creating rrd update script
Jun 3 07:10:24 php-fpm 24683 /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Jun 3 07:10:23 ppp 60140 [wan] IPV6CP: SendConfigReq #65
Jun 3 07:10:23 php-fpm 24683 /rc.newwanip: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
Jun 3 07:10:21 ppp 60140 [wan] IPV6CP: SendConfigReq #64
Jun 3 07:10:21 php-fpm 24683 /rc.newwanip: IP Address has changed, killing states on former IP Address xx.xx.149.254.
Jun 3 07:10:21 php-fpm 24683 /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
Jun 3 07:10:21 php-fpm 24683 /rc.newwanip: Default gateway setting Interface WAN_PPPOE Gateway as default.
Jun 3 07:10:21 php-fpm 24683 /rc.newwanip: Gateway, NONE AVAILABLE
Jun 3 07:10:19 ppp 60140 [wan] IPV6CP: SendConfigReq #63
Jun 3 07:10:17 ppp 60140 [wan] IPV6CP: SendConfigReq #62
Jun 3 07:10:16 php-fpm 24683 /rc.newwanip: rc.newwanip: on (IP address: xx.xx.131.159) (interface: WAN[wan]) (real interface: pppoe0).
Jun 3 07:10:16 php-fpm 24683 /rc.newwanip: rc.newwanip: Info: starting on pppoe0.
Jun 3 07:10:15 ppp 60140 [wan] IFACE: Add description "WAN"
Jun 3 07:10:15 ppp 60140 [wan] IFACE: Rename interface ng0 to pppoe0
Jun 3 07:10:15 ppp 60140 [wan] IFACE: Up event
Jun 3 07:10:15 check_reload_status 1603 rc.newwanip starting pppoe0
Jun 3 07:10:15 ppp 60140 [wan] xx.xx.131.159 -> 10.11.7.81
Jun 3 07:10:15 ppp 60140 [wan] IPCP: LayerUp
Jun 3 07:10:15 ppp 60140 [wan] IPCP: state change Ack-Sent --> Opened
Jun 3 07:10:15 ppp 60140 [wan] IPADDR xx.xx.131.159
Jun 3 07:10:15 ppp 60140 [wan] IPCP: rec'd Configure Ack #27 (Ack-Sent)
Jun 3 07:10:15 ppp 60140 [wan] IPADDR xx.xx.131.159
Jun 3 07:10:15 ppp 60140 [wan] IPCP: SendConfigReq #27
Jun 3 07:10:15 ppp 60140 [wan] xx.xx.131.159 is OK
Jun 3 07:10:15 ppp 60140 [wan] IPADDR xx.xx.131.159
Jun 3 07:10:15 ppp 60140 [wan] IPCP: rec'd Configure Nak #26 (Ack-Sent)
Jun 3 07:10:15 ppp 60140 [wan] IPADDR 0.0.0.0
Jun 3 07:10:15 ppp 60140 [wan] IPCP: SendConfigReq #26
Jun 3 07:10:15 ppp 60140 [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jun 3 07:10:15 ppp 60140 [wan] IPCP: rec'd Configure Reject #25 (Ack-Sent)
Jun 3 07:10:15 ppp 60140 [wan] IPCP: state change Req-Sent --> Ack-Sent
Jun 3 07:10:15 ppp 60140 [wan] IPADDR 10.11.7.81
Jun 3 07:10:15 ppp 60140 [wan] IPCP: SendConfigAck #214
Jun 3 07:10:15 ppp 60140 [wan] 10.11.7.81 is OK
Jun 3 07:10:15 ppp 60140 [wan] IPADDR 10.11.7.81
Jun 3 07:10:15 ppp 60140 [wan] IPCP: rec'd Configure Request #214 (Req-Sent)
Jun 3 07:10:15 ppp 60140 [wan] IPV6CP: SendConfigReq #61
Jun 3 07:10:15 ppp 60140 [wan] IPV6CP: state change Starting --> Req-Sent
Jun 3 07:10:15 ppp 60140 [wan] IPV6CP: Up event
Jun 3 07:10:15 ppp 60140 [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jun 3 07:10:15 ppp 60140 [wan] IPADDR 0.0.0.0
Jun 3 07:10:15 ppp 60140 [wan] IPCP: SendConfigReq #25
Jun 3 07:10:15 ppp 60140 [wan] IPCP: state change Starting --> Req-Sent
Jun 3 07:10:15 ppp 60140 [wan] IPCP: Up event
Jun 3 07:10:15 ppp 60140 [wan] IPV6CP: LayerStart
Jun 3 07:10:15 ppp 60140 [wan] IPV6CP: state change Initial --> Starting
Jun 3 07:10:15 ppp 60140 [wan] IPV6CP: Open event
Jun 3 07:10:15 ppp 60140 [wan] IPCP: LayerStart
Jun 3 07:10:15 ppp 60140 [wan] IPCP: state change Initial --> Starting
Jun 3 07:10:15 ppp 60140 [wan] IPCP: Open event
Jun 3 07:10:15 ppp 60140 [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jun 3 07:10:15 ppp 60140 [wan_link0] Link: Join bundle "wan"
Jun 3 07:10:15 ppp 60140 [wan_link0] Link: Matched action 'bundle "wan" ""'
Jun 3 07:10:15 ppp 60140 [wan_link0] LCP: authorization successful
Jun 3 07:10:15 ppp 60140 [wan_link0] MESG: Login ok
Jun 3 07:10:15 ppp 60140 [wan_link0] PAP: rec'd ACK #1 len: 13
Jun 3 07:10:15 ppp 60140 [wan_link0] LCP: LayerUp
Jun 3 07:10:15 ppp 60140 [wan_link0] PAP: sending REQUEST #1 len: 22
Jun 3 07:10:15 ppp 60140 [wan_link0] PAP: using authname "xxxxxxxx"
Jun 3 07:10:15 ppp 60140 [wan_link0] LCP: auth: peer wants PAP, I want nothing
Jun 3 07:10:15 ppp 60140 [wan_link0] LCP: state change Ack-Rcvd --> Opened
Jun 3 07:10:15 ppp 60140 [wan_link0] MAGICNUM 0x3c326777
Jun 3 07:10:15 ppp 60140 [wan_link0] AUTHPROTO PAP
Jun 3 07:10:15 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:15 ppp 60140 [wan_link0] LCP: SendConfigAck #243
Jun 3 07:10:15 ppp 60140 [wan_link0] MAGICNUM 0x3c326777
Jun 3 07:10:15 ppp 60140 [wan_link0] AUTHPROTO PAP
Jun 3 07:10:15 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:15 ppp 60140 [wan_link0] LCP: rec'd Configure Request #243 (Ack-Rcvd)
Jun 3 07:10:14 ppp 60140 [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd
Jun 3 07:10:14 ppp 60140 [wan_link0] MAGICNUM 0x0cefc404
Jun 3 07:10:14 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:14 ppp 60140 [wan_link0] LCP: rec'd Configure Ack #33 (Req-Sent)
Jun 3 07:10:14 ppp 60140 [wan_link0] MAGICNUM 0x0cefc404
Jun 3 07:10:14 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:14 ppp 60140 [wan_link0] LCP: SendConfigReq #33
Jun 3 07:10:14 ppp 60140 [wan_link0] LCP: state change Ack-Rcvd --> Req-Sent
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd
Jun 3 07:10:12 ppp 60140 [wan_link0] MAGICNUM 0x0cefc404
Jun 3 07:10:12 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: rec'd Configure Ack #32 (Req-Sent)
Jun 3 07:10:12 ppp 60140 [wan_link0] MAGICNUM 0x0cefc404
Jun 3 07:10:12 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: SendConfigReq #32
Jun 3 07:10:12 ppp 60140 [wan_link0] PROTOCOMP
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: rec'd Configure Reject #31 (Req-Sent)
Jun 3 07:10:12 ppp 60140 [wan_link0] MAGICNUM 0x0cefc404
Jun 3 07:10:12 ppp 60140 [wan_link0] MRU 1492
Jun 3 07:10:12 ppp 60140 [wan_link0] PROTOCOMP
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: SendConfigReq #31
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: state change Starting --> Req-Sent
Jun 3 07:10:12 ppp 60140 [wan_link0] LCP: Up event
Jun 3 07:10:12 ppp 60140 [wan_link0] Link: UP event
Jun 3 07:10:12 ppp 60140 [wan_link0] PPPoE: connection successful
Jun 3 07:10:12 ppp 60140 PPPoE: rec'd ACNAME "TOROON2938W"
Jun 3 07:10:10 ppp 60140 [wan_link0] PPPoE: Connecting to ''
Jun 3 07:10:10 ppp 60140 [wan_link0] Link: reconnection attempt 10
Jun 3 07:10:08 ppp 60140 [wan_link0] Link: reconnection attempt 10 in 2 seconds
Jun 3 07:10:08 ppp 60140 [wan_link0] LCP: Down event
Jun 3 07:10:08 ppp 60140 [wan_link0] Link: DOWN event
Jun 3 07:10:08 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
Jun 3 07:09:59 ppp 60140 [wan_link0] PPPoE: Connecting to ''
Jun 3 07:09:59 ppp 60140 [wan_link0] Link: reconnection attempt 9
Jun 3 07:09:58 ppp 60140 [wan_link0] Link: reconnection attempt 9 in 1 seconds
Jun 3 07:09:58 ppp 60140 [wan_link0] LCP: Down event
Jun 3 07:09:58 ppp 60140 [wan_link0] Link: DOWN event
Jun 3 07:09:58 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
Jun 3 07:09:55 php-fpm 1556 /index.php: The command '/usr/local/sbin/ping-auth -s > /etc/thoth/thothid 2>/dev/null' returned exit code '2', the output was '' -
Hmm, OK. I guess that was actually two different outages then. You can see dpinger is using a different process ID.
Nothing in the system log. That could be a scheduled update after the maximum renewal time. Yuop the default cron tab for that is:
1 1 * * * root /usr/bin/nice -n20 /etc/rc.dyndns.update
And that lines up with what's logged. So that then seems odd that it didn't trigger when the WAN initially reconnected.
How do you have the DynDNS configured?
Steve
-
@stephenw10 I presume you are referring to my DDNS configuration within pfSense. It seems straight forward. (see attached image)
The only slightly odd thing is my "Service Type" is set for "No-IP (free).
There are a number of options [No-IP, No-IP (v6), No-IP (free), No-IP (free-v6)]
I actually have a paid subscription but I presume there is no difference to pfSense, They merely list the different No-IP offerings but the config is the same.
-
Hmm, I believe the free option at one time had additional code to force updates because they would cancel the service if it didn't update frequently.
But that should also work with paid options. I have an instance of the free service and I still have to manually confirm it anyway.
I assume it does correctly update the entry at freedns?
And that WAN is correct interface here? It's the PPPoE connection?
-
@stephenw10 yes it's using a PPPoE connection. I'll change the Service Type to "No-IP" and see if that makes any difference. Nonetheless I guess we have chased this far enough? No "smoking gun". Now that I have this general background, I'll keep a closer eye for future IP changes. Thanks for your continued comments on this.
-
Mmm, I mean it looks like it's just not calling the update script when he PPPoE link reconnects for some reason. Usually the IP change when that relinks should trigger it.
-
@stephenw10 Well, it's happened again. My ISP made some change and I was assigned a new IP today at 2:27PM. pfSense displays the new IP. No-IP has not been updated (yet). I'm off to grab some logs....
-
@stephenw10 said in Delay in sending WAN DDNS change notices:
Mmm, I mean it looks like it's just not calling the update script when he PPPoE link reconnects for some reason. Usually the IP change when that relinks should trigger it.
How / where can I see if it is calling the update script?
-
@192-168-1-0 I note pfSense "Services > Dynamic DNS > Dynamic DNS Clients" had its Status indicated with an "X". The "Cached IP" still indicated the old IP
-
@192-168-1-0 And once again pfSense updated my DDNS provider at 1am. "Services > Dynamic DNS > Dynamic DNS Clients" status now indicates a green check mark. The "Cached IP" indicates the correct and current IP. There must be an area with pfSense that controls this.
-
For example I'd expect to see logged something like this: (logs reversed)
May 30 23:42:23 php-fpm 1140 /rc.dyndns.update: phpDynDNS (xxxxxx.hopto.org): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. May 30 23:42:23 php-fpm 1140 8.8.8.8|217.x.x.x|WAN_PPPOE|6.037ms|0.132ms|0.0%|online|none May 30 23:42:23 php-fpm 1140 /rc.dyndns.update: MONITOR: WAN_PPPOE is available now, adding to routing group LoadBalance May 30 23:42:23 php-fpm 42698 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_PPPOE. May 30 23:42:22 check_reload_status 3198 Reloading filter May 30 23:42:22 check_reload_status 3198 Restarting OpenVPN tunnels/interfaces May 30 23:42:22 check_reload_status 3198 Restarting IPsec tunnels May 30 23:42:22 check_reload_status 3198 updating dyndns WAN_PPPOE May 30 23:42:22 rc.gateway_alarm 37917 >>> Gateway alarm: WAN_PPPOE (Addr:8.8.8.8 Alarm:0 RTT:6.045ms RTTsd:.130ms Loss:0%)
Though in that case the IP did not change so no update was sent.
-
@stephenw10 Here is my log
loss of connectivity began at 14:09 on June 29
connectivity returned at 14:12 on June 29
my DDNS provider was updated at 01:01 on June 302024-06-30 1:57 sshguard 41684 Now monitoring attacks.
2024-06-30 1:57 sshguard 93560 Exiting on signal.
2024-06-30 1:26 sshguard 93560 Now monitoring attacks.
2024-06-30 1:26 sshguard 73565 Exiting on signal.
2024-06-30 1:01 php-cgi 50891 notify_monitor.php: Message sent to <my email> OK
2024-06-30 1:01 php-cgi 87382 rc.dyndns.update: phpDynDNS (my DDNS URL): (Success) IP Address Changed Successfully!
2024-06-30 1:01 php-cgi 87382 rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_wannoip'my DDNS URL'0.cache: xx.xx.xxx.xx
2024-06-30 0:55 sshguard 73565 Now monitoring attacks.
2024-06-30 0:55 sshguard 72849 Exiting on signal.
2024-06-30 0:24 sshguard 72849 Now monitoring attacks.
2024-06-30 0:24 sshguard 33689 Exiting on signal.
multiple duplicate lines removed
2024-06-29 14:47 sshguard 32617 Now monitoring attacks.
2024-06-29 14:47 sshguard 2636 Exiting on signal.
2024-06-29 14:18 sshguard 2636 Now monitoring attacks.
2024-06-29 14:18 sshguard 77831 Exiting on signal.
2024-06-29 14:13 ppp 60140 [wan] IPV6CP: LayerFinish
2024-06-29 14:13 ppp 60140 [wan] IPV6CP: state change Req-Sent --> Stopped
2024-06-29 14:13 ppp 60140 [wan] IPV6CP: parameter negotiation failed
2024-06-29 14:13 ppp 60140 [wan] IPV6CP: SendConfigReq #80
2024-06-29 14:13 ppp 60140 [wan] IPV6CP: SendConfigReq #79
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #78
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #77
2024-06-29 14:12 php-fpm 15502 /rc.start_packages: Restarting/Starting all packages.
2024-06-29 14:12 check_reload_status 1603 Reloading filter
2024-06-29 14:12 check_reload_status 1603 Starting packages
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - yy.yy.yyy.yyy -> xx.xx.xxx.xx - Restarting packages.
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #76
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Creating rrd update script
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #75
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #74
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: IP Address has changed, killing states on former IP Address yy.yy.yyy.yyy.
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Default gateway setting Interface WAN_PPPOE Gateway as default.
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Gateway, NONE AVAILABLE
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #73
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #72
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: rc.newwanip: on (IP address: xx.xx.xxx.xx) (interface: WAN[wan]) (real interface: pppoe0).
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: rc.newwanip: Info: starting on pppoe0.
2024-06-29 14:12 ppp 60140 [wan] IFACE: Add description "WAN"
2024-06-29 14:12 ppp 60140 [wan] IFACE: Rename interface ng0 to pppoe0
2024-06-29 14:12 ppp 60140 [wan] IFACE: Up event
2024-06-29 14:12 check_reload_status 1603 rc.newwanip starting pppoe0
2024-06-29 14:12 ppp 60140 [wan] xx.xx.xxx.xx -> 10.11.7.81
2024-06-29 14:12 ppp 60140 [wan] IPCP: LayerUp
2024-06-29 14:12 ppp 60140 [wan] IPCP: state change Ack-Sent --> Opened
2024-06-29 14:12 ppp 60140 [wan] IPADDR xx.xx.xxx.xx
2024-06-29 14:12 ppp 60140 [wan] IPCP: rec'd Configure Ack #31 (Ack-Sent)
2024-06-29 14:12 ppp 60140 [wan] IPADDR xx.xx.xxx.xx
2024-06-29 14:12 ppp 60140 [wan] IPCP: SendConfigReq #31
2024-06-29 14:12 ppp 60140 [wan] xx.xx.xxx.xx is OK
2024-06-29 14:12 ppp 60140 [wan] IPADDR xx.xx.xxx.xx
2024-06-29 14:12 ppp 60140 [wan] IPCP: rec'd Configure Nak #30 (Ack-Sent)
2024-06-29 14:12 ppp 60140 [wan] IPADDR 0.0.0.0
2024-06-29 14:12 ppp 60140 [wan] IPCP: SendConfigReq #30
2024-06-29 14:12 ppp 60140 [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
2024-06-29 14:12 ppp 60140 [wan] IPCP: rec'd Configure Reject #29 (Ack-Sent)
2024-06-29 14:12 ppp 60140 [wan] IPCP: state change Req-Sent --> Ack-Sent
2024-06-29 14:12 ppp 60140 [wan] IPADDR 10.11.7.81
2024-06-29 14:12 ppp 60140 [wan] IPCP: SendConfigAck #13
2024-06-29 14:12 ppp 60140 [wan] 10.11.7.81 is OK
2024-06-29 14:12 ppp 60140 [wan] IPADDR 10.11.7.81
2024-06-29 14:12 ppp 60140 [wan] IPCP: rec'd Configure Request #13 (Req-Sent)
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: SendConfigReq #71
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: state change Starting --> Req-Sent
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: Up event
2024-06-29 14:12 ppp 60140 [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
2024-06-29 14:12 ppp 60140 [wan] IPADDR 0.0.0.0
2024-06-29 14:12 ppp 60140 [wan] IPCP: SendConfigReq #29
2024-06-29 14:12 ppp 60140 [wan] IPCP: state change Starting --> Req-Sent
2024-06-29 14:12 ppp 60140 [wan] IPCP: Up event
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: LayerStart
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: state change Initial --> Starting
2024-06-29 14:12 ppp 60140 [wan] IPV6CP: Open event
2024-06-29 14:12 ppp 60140 [wan] IPCP: LayerStart
2024-06-29 14:12 ppp 60140 [wan] IPCP: state change Initial --> Starting
2024-06-29 14:12 ppp 60140 [wan] IPCP: Open event
2024-06-29 14:12 ppp 60140 [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
2024-06-29 14:12 ppp 60140 [wan_link0] Link: Join bundle "wan"
2024-06-29 14:12 ppp 60140 [wan_link0] Link: Matched action 'bundle "wan" ""'
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: authorization successful
2024-06-29 14:12 ppp 60140 [wan_link0] MESG: Login ok
2024-06-29 14:12 ppp 60140 [wan_link0] PAP: rec'd ACK #1 len: 13
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: LayerUp
2024-06-29 14:12 ppp 60140 [wan_link0] PAP: sending REQUEST #1 len: 22
2024-06-29 14:12 ppp 60140 [wan_link0] PAP: using authname "my user name"
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: auth: peer wants PAP, I want nothing
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: state change Ack-Sent --> Opened
2024-06-29 14:12 ppp 60140 [wan_link0] MAGICNUM 0x6f3e9b88
2024-06-29 14:12 ppp 60140 [wan_link0] MRU 1492
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: rec'd Configure Ack #37 (Ack-Sent)
2024-06-29 14:12 ppp 60140 [wan_link0] MAGICNUM 0x6f3e9b88
2024-06-29 14:12 ppp 60140 [wan_link0] MRU 1492
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: SendConfigReq #37
2024-06-29 14:12 ppp 60140 [wan_link0] PROTOCOMP
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: rec'd Configure Reject #36 (Ack-Sent)
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: state change Req-Sent --> Ack-Sent
2024-06-29 14:12 ppp 60140 [wan_link0] MAGICNUM 0x63e40dc4
2024-06-29 14:12 ppp 60140 [wan_link0] AUTHPROTO PAP
2024-06-29 14:12 ppp 60140 [wan_link0] MRU 1492
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: SendConfigAck #60
2024-06-29 14:12 ppp 60140 [wan_link0] MAGICNUM 0x63e40dc4
2024-06-29 14:12 ppp 60140 [wan_link0] AUTHPROTO PAP
2024-06-29 14:12 ppp 60140 [wan_link0] MRU 1492
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: rec'd Configure Request #60 (Req-Sent)
2024-06-29 14:12 ppp 60140 [wan_link0] MAGICNUM 0x6f3e9b88
2024-06-29 14:12 ppp 60140 [wan_link0] MRU 1492
2024-06-29 14:12 ppp 60140 [wan_link0] PROTOCOMP
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: SendConfigReq #36
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: state change Starting --> Req-Sent
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: Up event
2024-06-29 14:12 ppp 60140 [wan_link0] Link: UP event
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE: connection successful
2024-06-29 14:12 ppp 60140 PPPoE: rec'd ACNAME "TOROON2938W"
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 10
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 10 in 1 seconds
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:12 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 9
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 9 in 3 seconds
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:12 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 8
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 8 in 3 seconds
2024-06-29 14:12 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:12 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:12 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:12 ppp 60140 [wan_link0] Link: reconnection attempt 7
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 7 in 4 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:11 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 6
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 6 in 2 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:11 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 5
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 5 in 4 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:11 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 4
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 4 in 1 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:11 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:11 check_reload_status 1603 Reloading filter
2024-06-29 14:11 kernel e6000sw0port3: link state changed to UP
2024-06-29 14:11 check_reload_status 1603 Linkup starting $e6000sw0port3
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 3
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 3 in 2 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:11 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 2
2024-06-29 14:11 ppp 60140 [wan_link0] Link: reconnection attempt 2 in 3 seconds
2024-06-29 14:11 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:11 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:11 ppp 60140 [wan_link0] PPPoE connection timeout after 9 seconds
2024-06-29 14:10 ppp 60140 [wan_link0] PPPoE: Connecting to ''
2024-06-29 14:10 ppp 60140 [wan_link0] Link: reconnection attempt 1
2024-06-29 14:10 ppp 60140 [wan_link0] Link: reconnection attempt 1 in 3 seconds
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: LayerStart
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: state change Stopped --> Starting
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: Down event
2024-06-29 14:10 ppp 60140 [wan_link0] Link: DOWN event
2024-06-29 14:10 ppp 60140 [wan_link0] PPPoE: connection closed
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: LayerFinish
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: state change Stopping --> Stopped
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: SendTerminateReq #35
2024-06-29 14:10 check_reload_status 1603 Reloading filter
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: LayerDown
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: SendTerminateReq #34
2024-06-29 14:10 ppp 60140 [wan] Bundle: Last link has gone, no links for bw-manage defined
2024-06-29 14:10 ppp 60140 [wan] IPV6CP: state change Closed --> Initial
2024-06-29 14:10 ppp 60140 [wan] IPV6CP: Down event
2024-06-29 14:10 ppp 60140 [wan] IPCP: state change Closing --> Initial
2024-06-29 14:10 ppp 60140 [wan] Bundle: No NCPs left. Closing links...
2024-06-29 14:10 ppp 60140 [wan] IPCP: LayerFinish
2024-06-29 14:10 ppp 60140 [wan] IPCP: Down event
2024-06-29 14:10 ppp 60140 [wan] IPV6CP: state change Stopped --> Closed
2024-06-29 14:10 ppp 60140 [wan] IPV6CP: Close event
2024-06-29 14:10 ppp 60140 [wan] IFACE: Set description "WAN"
2024-06-29 14:10 ppp 60140 [wan] IFACE: Rename interface pppoe0 to pppoe0
2024-06-29 14:10 ppp 60140 [wan] IFACE: Down event
2024-06-29 14:10 ppp 60140 [wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
2024-06-29 14:10 check_reload_status 1603 Rewriting resolv.conf
2024-06-29 14:10 kernel e6000sw0port3: link state changed to DOWN
2024-06-29 14:10 check_reload_status 1603 Linkup starting $e6000sw0port3
2024-06-29 14:10 ppp 60140 [wan] IPCP: LayerDown
2024-06-29 14:10 ppp 60140 [wan] IPCP: SendTerminateReq #28
2024-06-29 14:10 ppp 60140 [wan] IPCP: state change Opened --> Closing
2024-06-29 14:10 ppp 60140 [wan] IPCP: Close event
2024-06-29 14:10 ppp 60140 [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
2024-06-29 14:10 ppp 60140 [wan_link0] Link: Leave bundle "wan"
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: state change Opened --> Stopping
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: peer not responding to echo requests
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: no reply to 5 echo request(s)
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: no reply to 4 echo request(s)
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: no reply to 3 echo request(s)
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: no reply to 2 echo request(s)
2024-06-29 14:10 ppp 60140 [wan_link0] LCP: no reply to 1 echo request(s)
2024-06-29 14:09 php-fpm 15502 /rc.dyndns.update: phpDynDNS (my DDNS URL): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-06-29 14:09 php-fpm 1556 /rc.openvpn: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
2024-06-29 14:09 php-fpm 1556 /rc.openvpn: Gateway, none 'available' for inet, use the first one configured. 'WAN_PPPOE'
2024-06-29 14:09 check_reload_status 1603 Reloading filter
2024-06-29 14:09 check_reload_status 1603 Restarting OpenVPN tunnels/interfaces
2024-06-29 14:09 check_reload_status 1603 Restarting IPsec tunnels
2024-06-29 14:09 check_reload_status 1603 updating dyndns WAN_PPPOE
2024-06-29 14:09 rc.gateway_alarm 30268 >>> Gateway alarm: WAN_PPPOE (Addr:10.11.7.81 Alarm:1 RTT:2.034ms RTTsd:.393ms Loss:22%)
2024-06-29 14:09 check_reload_status 1603 Reloading filter
2024-06-29 14:09 check_reload_status 1603 Linkup starting $e6000sw0port3
2024-06-29 14:09 kernel e6000sw0port3: link state changed to UP
2024-06-29 14:09 check_reload_status 1603 Reloading filter
2024-06-29 14:09 kernel e6000sw0port3: link state changed to DOWN
2024-06-29 14:09 check_reload_status 1603 Linkup starting $e6000sw0port3
2024-06-29 13:52 sshguard 77831 Now monitoring attacks.
2024-06-29 13:52 sshguard 57349 Exiting on signal.
2024-06-29 13:23 sshguard 57349 Now monitoring attacks.
2024-06-29 13:23 sshguard 25035 Exiting on signal.
multiple duplicate lines removed
2024-06-29 1:41 sshguard 54129 Now monitoring attacks.
2024-06-29 1:41 sshguard 14311 Exiting on signal.
2024-06-29 1:11 sshguard 14311 Now monitoring attacks.
2024-06-29 1:11 sshguard 22415 Exiting on signal.
2024-06-29 1:01 php-cgi 76964 rc.dyndns.update: phpDynDNS (my DDNS URL): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-06-29 0:41 sshguard 22415 Now monitoring attacks.
2024-06-29 0:41 sshguard 9336 Exiting on signal.
2024-06-29 0:12 sshguard 9336 Now monitoring attacks.
2024-06-29 0:12 sshguard 77943 Exiting on signal. -
@192-168-1-0 said in Delay in sending WAN DDNS change notices:
2024-06-29 14:12 php-fpm 1556 /rc.newwanip: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
OK that seems pretty much certainly the cause.
How is the system DNS setup? Using Unbound on localhost? Is that set to use both WANs?
-
@stephenw10 said in Delay in sending WAN DDNS change notices:
DNS setup? Using Unbound on localhost? I
I have attached images of what I believe are the areas you are referring to
-
Hmm, that should be OK. And I think I conflated some tickets there, you only have one WAN connection?
The WAN is up at that point so Unbound should be able to resolve it but for some reason is failing. Is there anything in the resolver log at that time?
As a test you could try adding dynupdate.no-ip.com as a host override so it will always resolve. That will at least prove that it updates correctly when that is resolvable. Or maybe that it still doesn't resolve if, for example, Unbound is not responding when that runs.
-
@stephenw10 yes only one WAN connection
here is the DNS Resolver log
Jun 30 02:18:27 unbound 60421 [60421:0] info: generate keytag query _ta-4f66. NULL IN
Jun 29 15:08:21 unbound 60421 [60421:0] info: generate keytag query _ta-4f66. NULL IN
Jun 29 14:55:43 unbound 60421 [60421:0] info: generate keytag query _ta-4f66. NULL IN
Jun 29 14:13:45 unbound 60421 [60421:1] info: generate keytag query _ta-4f66. NULL IN
Jun 29 14:12:46 unbound 60421 [60421:0] info: start of service (unbound 1.17.1).
Jun 29 14:12:45 unbound 60421 [60421:0] notice: init module 1: iterator
Jun 29 14:12:45 unbound 60421 [60421:0] notice: init module 0: validator
Jun 29 14:12:45 unbound 60421 [60421:0] notice: Restart of unbound 1.17.1.
Jun 29 14:12:45 unbound 60421 [60421:0] info: 64.000000 128.000000 4
Jun 29 14:12:45 unbound 60421 [60421:0] info: 16.000000 32.000000 1
Jun 29 14:12:45 unbound 60421 [60421:0] info: 8.000000 16.000000 2
Jun 29 14:12:45 unbound 60421 [60421:0] info: 4.000000 8.000000 4
Jun 29 14:12:45 unbound 60421 [60421:0] info: 2.000000 4.000000 2
Jun 29 14:12:45 unbound 60421 [60421:0] info: 1.000000 2.000000 26
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.524288 1.000000 195
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.262144 0.524288 933
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.131072 0.262144 5507
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.065536 0.131072 26293
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.032768 0.065536 17957
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.016384 0.032768 10678
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.008192 0.016384 10493
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.004096 0.008192 11141
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.002048 0.004096 3851
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.001024 0.002048 119
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000512 0.001024 35
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000256 0.000512 28
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000128 0.000256 12
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000064 0.000128 5
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000000 0.000001 2781
Jun 29 14:12:45 unbound 60421 [60421:0] info: lower(secs) upper(secs) recursions
Jun 29 14:12:45 unbound 60421 [60421:0] info: [25%]=0.0117401 median[50%]=0.043517 [75%]=0.0915835
Jun 29 14:12:45 unbound 60421 [60421:0] info: histogram of recursion processing times
Jun 29 14:12:45 unbound 60421 [60421:0] info: average recursion processing time 0.061340 sec
Jun 29 14:12:45 unbound 60421 [60421:0] info: server stats for thread 1: requestlist max 18 avg 0.301109 exceeded 0 jostled 0
Jun 29 14:12:45 unbound 60421 [60421:0] info: server stats for thread 1: 103719 queries, 13652 answers from cache, 90067 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Jun 29 14:12:45 unbound 60421 [60421:0] info: 16.000000 32.000000 13
Jun 29 14:12:45 unbound 60421 [60421:0] info: 8.000000 16.000000 5
Jun 29 14:12:45 unbound 60421 [60421:0] info: 4.000000 8.000000 1
Jun 29 14:12:45 unbound 60421 [60421:0] info: 2.000000 4.000000 13
Jun 29 14:12:45 unbound 60421 [60421:0] info: 1.000000 2.000000 41
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.524288 1.000000 275
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.262144 0.524288 1257
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.131072 0.262144 7251
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.065536 0.131072 32332
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.032768 0.065536 22461
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.016384 0.032768 14640
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.008192 0.016384 14006
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.004096 0.008192 14946
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.002048 0.004096 5488
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.001024 0.002048 155
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000512 0.001024 92
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000256 0.000512 40
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000128 0.000256 17
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000064 0.000128 9
Jun 29 14:12:45 unbound 60421 [60421:0] info: 0.000000 0.000001 3537
Jun 29 14:12:45 unbound 60421 [60421:0] info: lower(secs) upper(secs) recursions
Jun 29 14:12:45 unbound 60421 [60421:0] info: [25%]=0.011035 median[50%]=0.0405869 [75%]=0.0899473
Jun 29 14:12:45 unbound 60421 [60421:0] info: histogram of recursion processing times
Jun 29 14:12:45 unbound 60421 [60421:0] info: average recursion processing time 0.059597 sec
Jun 29 14:12:45 unbound 60421 [60421:0] info: server stats for thread 0: requestlist max 22 avg 0.480953 exceeded 0 jostled 0
Jun 29 14:12:45 unbound 60421 [60421:0] info: server stats for thread 0: 135269 queries, 18690 answers from cache, 116579 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Jun 29 14:12:45 unbound 60421 [60421:0] info: service stopped (unbound 1.17.1).
Jun 29 13:44:41 unbound 60421 [60421:0] info: generate keytag query _ta-4f66. NULL IN
Jun 29 13:12:55 unbound 60421 [60421:0] info: generate keytag query _ta-4f66. NULL IN
Jun 29 12:48:12 unbound 60421 [60421:1] info: generate keytag query _ta-4f66. NULL IN
Jun 29 12:48:12 unbound 60421 [60421:0] info: generate keytag query _ta-4f66. NULL IN -
Hmm, so I wonder if it tries to resolve in the 1s Unbound is restarting. You have system DNS set to only use Unbound locally. You could try setting it back to the defaults so it falls back to using 1.1.1.1 directly if Unbound isn't available. Otherwise testing a host override in Unbound would prove a general connectivity issue.
-
@stephenw10 I have set the DNS Resolution Behavior back to the default setting. We'll see what happens next time....
-
@192-168-1-0 one other question.... what process causes the DDNS update to be sent at 1am?
-
The dyndns update cronjob: