I know this is going to sound strange, but every so often, once every 6-72 hours, my RT-AX56U (386.1_2) thinks it is disconnected from the internet. However I can do the following:
I can resolve the issue by selecting "Internet Connection" restart in scMerlin and the system works again within a second. Any ideas on how to diagnose or resolve this issue?
Connection monitor:
Syslog section that covers this time. You can see the speedtest working. You can also see when the restart is initiated. It takes a second to get the internet working.
The essence of the /jffs/scripts/wan-event script
- If I was already connected to a service, such as a Microsoft Teams meeting - this continues without interruption.
- I can connect to the cable modem (on the WAN side of the router) and confirm all connectivity tests work from this device to the internet. Not only does it think it is connected, but if I plug another router into this device (it has 4 ports) then this is able to connect to the internet, DNS etc without issue.
- The automated Speedtest (spdMerlin addon) runs without reporting an issue.
- The Connection Monitor (connmon addon) fails - it pings bbc.co.uk which has not been down during the outage hours.
- Browsing to internet sites fails, even if they were previously browsed, so DNS should be cached.
- New devices onto the wifi / lan connect to router but cannot access sites beyond the router (except the cable modem).
I can resolve the issue by selecting "Internet Connection" restart in scMerlin and the system works again within a second. Any ideas on how to diagnose or resolve this issue?
Connection monitor:
Syslog section that covers this time. You can see the speedtest working. You can also see when the restart is initiated. It takes a second to get the internet working.
Code:
Feb 21 21:42:25 spdMerlin: Speedtest results - Download: 455.79 Mbps (data used: 804.3 MB) - Upload: 35.34 Mbps (data used: 16.4 MB)
Feb 21 21:42:25 spdMerlin: Connection quality - Latency: 13.71 ms (8.31 ms jitter) - Packet Loss: 0.0%
Feb 21 21:55:41 wlceventd: wlceventd_proc_event(469): eth6: Deauth_ind 34:82:C5:A8:DE:27, status: 0, reason: Deauthenticated because sending station is leaving (or has left) IBSS or ESS (3)
Feb 21 21:55:41 wlceventd: wlceventd_proc_event(469): eth6: Deauth_ind 34:82:C5:A8:DE:27, status: 0, reason: Class 3 frame received from nonassociated station (7)
Feb 21 21:55:42 wlceventd: wlceventd_proc_event(505): eth6: Auth 34:82:C5:A8:DE:27, status: Successful (0)
Feb 21 21:55:42 wlceventd: wlceventd_proc_event(534): eth6: Assoc 34:82:C5:A8:DE:27, status: Successful (0)
Feb 21 21:55:42 kernel: 34:82:C5:A8:DE:27 not mesh client, can't update it's ip
Feb 21 22:12:01 spdMerlin: Starting speedtest using Zzoomm (Henley-on-Thames, United Kingdom) for WAN interface
Feb 21 22:12:24 spdMerlin: Speedtest results - Download: 437.93 Mbps (data used: 642.5 MB) - Upload: 35.29 Mbps (data used: 15.9 MB)
Feb 21 22:12:24 spdMerlin: Connection quality - Latency: 14.66 ms (2.69 ms jitter) - Packet Loss: 0.0%
Feb 21 22:16:28 kernel: 18:74:2E:F4:83:55 not mesh client, can't update it's ip
Feb 21 22:27:31 kernel: 74:B5:87:8A:6B:47 not mesh client, can't update it's ip
Feb 21 22:28:44 kernel: A8:DB:03:11:4A:AF not mesh client, can't update it's ip
Feb 21 22:39:39 kernel: 74:B5:87:8A:6B:47 not mesh client, can't update it's ip
Feb 21 22:40:01 kernel: 74:B5:87:8A:6B:47 not mesh client, can't update it's ip
Feb 21 22:42:01 spdMerlin: Starting speedtest using Zzoomm (Henley-on-Thames, United Kingdom) for WAN interface
Feb 21 22:42:25 spdMerlin: Speedtest results - Download: 458.14 Mbps (data used: 778.9 MB) - Upload: 35.66 Mbps (data used: 16.1 MB)
Feb 21 22:42:25 spdMerlin: Connection quality - Latency: 13.06 ms (0.58 ms jitter) - Packet Loss: 0.0%
Feb 21 22:43:38 wlceventd: wlceventd_proc_event(469): eth6: Deauth_ind 34:82:C5:A8:DE:27, status: 0, reason: Deauthenticated because sending station is leaving (or has left) IBSS or ESS (3)
Feb 21 22:51:13 kernel: 74:B5:87:8A:6B:47 not mesh client, can't update it's ip
Feb 21 23:04:40 wlceventd: wlceventd_proc_event(486): eth6: Disassoc 30:AB:6A:BB:77:83, status: 0, reason: Disassociated because sending station is leaving (or has left) BSS (8)
Feb 21 23:04:40 wlceventd: wlceventd_proc_event(486): eth6: Disassoc 30:AB:6A:BB:77:83, status: 0, reason: Disassociated because sending station is leaving (or has left) BSS (8)
Feb 21 23:06:12 miniupnpd[3477]: shutting down MiniUPnPd
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:12 (wan-event): 25619 Script not defined for wan-event: wan0-stopping
Feb 21 23:06:12 (wan-event): 25635 Script not defined for wan-event: wan0-stopped
Feb 21 23:06:12 (wan-event): 25655 Script not defined for wan-event: wan1-stopping
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:12 (wan-event): 25662 Script not defined for wan-event: wan1-stopped
Feb 21 23:06:12 wsdd2[3475]: error: wsdd-mcast-v4: wsd_send_soap_msg: send
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:12 (wan-event): 25677 Script not defined for wan-event: wan0-init
Feb 21 23:06:12 (wan-event): 25694 Script not defined for wan-event: wan0-connecting
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:12 wsdd2[3475]: error: wsdd-mcast-v4: wsd_send_soap_msg: send
Feb 21 23:06:12 (wan-event): 25710 Script not defined for wan-event: wan0-connected
Feb 21 23:06:12 kernel: 30:AB:6A:BB:77:83 not mesh client, can't update it's ip
Feb 21 23:06:14 miniupnpd[25848]: HTTP listening on port 55187
Feb 21 23:06:14 miniupnpd[25848]: Listening for NAT-PMP/PCP traffic on port 5351
Feb 21 23:06:19 wlceventd: wlceventd_proc_event(505): eth6: Auth 30:AB:6A:BB:77:83, status: Successful (0)
Feb 21 23:06:20 wlceventd: wlceventd_proc_event(534): eth6: Assoc 30:AB:6A:BB:77:83, status: Successful (0)
Feb 21 23:06:22 kernel: HTB: quantum of class 10001 is big. Consider r2q change.
Feb 21 23:06:22 kernel: HTB: quantum of class 10002 is big. Consider r2q change.
Feb 21 23:06:23 kernel: HTB: quantum of class 10060 is big. Consider r2q change.
Feb 21 23:06:25 kernel: HTB: quantum of class 20001 is big. Consider r2q change.
Feb 21 23:06:25 kernel: HTB: quantum of class 20002 is big. Consider r2q change.
Feb 21 23:06:25 kernel: HTB: quantum of class 20060 is big. Consider r2q change.
Feb 21 23:06:27 kernel: Archer TCP Pure ACK Enabled
Feb 21 23:06:27 wsdd2[3475]: Terminated received.
Feb 21 23:06:28 miniupnpd[26166]: MiniUPnPd is already running. EXITING
Feb 21 23:06:56 kernel: Archer TCP Pure ACK Enabled
Feb 21 23:07:02 kernel: HTB: quantum of class 10001 is big. Consider r2q change.
Feb 21 23:07:02 kernel: HTB: quantum of class 10002 is big. Consider r2q change.
Feb 21 23:07:03 kernel: HTB: quantum of class 10060 is big. Consider r2q change.
Feb 21 23:07:04 kernel: HTB: quantum of class 20001 is big. Consider r2q change.
Feb 21 23:07:05 kernel: HTB: quantum of class 20002 is big. Consider r2q change.
Feb 21 23:07:05 kernel: HTB: quantum of class 20060 is big. Consider r2q change.
Feb 21 23:12:01 spdMerlin: Starting speedtest using Zzoomm (Henley-on-Thames, United Kingdom) for WAN interface
Feb 21 23:12:31 spdMerlin: Speedtest results - Download: 437.16 Mbps (data used: 777.3 MB) - Upload: 35.11 Mbps (data used: 37.4 MB)
Feb 21 23:12:31 spdMerlin: Connection quality - Latency: 14.08 ms (2.55 ms jitter) - Packet Loss: 0.0%
Feb 21 23:42:01 spdMerlin: Starting speedtest using Zzoomm (Henley-on-Thames, United Kingdom) for WAN interface
Feb 21 23:42:04 miniupnpd[25848]: upnp_event_process_notify: connect(192.168.0.60:2869): Connection timed out
Feb 21 23:42:04 miniupnpd[25848]: upnp_event_process_notify: connect(192.168.0.60:2869): Connection timed out
Feb 21 23:42:04 miniupnpd[25848]: upnpevents_processfds: 0xd27068, remove subscriber uuid:32c6d2fa-d3c3-4be1-933f-1e97e86f246e after an ERROR cb: http://192.168.0.60:2869/upnp/eventing/hrsqjbuhil
Feb 21 23:42:04 miniupnpd[25848]: upnp_event_process_notify: connect(192.168.0.60:2869): Connection timed out
Feb 21 23:42:04 miniupnpd[25848]: upnpevents_processfds: 0xd20870, remove subscriber uuid:7963689d-69b6-4946-a2c0-fef9aabb1c1d after an ERROR cb: http://192.168.0.60:2869/upnp/eventing/zpovpdukdd
Feb 21 23:42:25 spdMerlin: Speedtest results - Download: 474.11 Mbps (data used: 825.8 MB) - Upload: 35.55 Mbps (data used: 16.0 MB)
Feb 21 23:42:25 spdMerlin: Connection quality - Latency: 14.06 ms (0.29 ms jitter) - Packet Loss: 0.0%
Feb 22 00:05:21 wlceventd: wlceventd_proc_event(505): eth6: Auth F8:59:71:FF:ED:26, status: Successful (0)
The essence of the /jffs/scripts/wan-event script
Code:
#!/bin/sh
Say(){
echo -e $$ $@ | logger -st "($(basename $0))"
}
SayT(){
echo -e $$ $@ | logger -t "($(basename $0))"
}
scr_name="$(basename $0)"
WAN_IF=$1
WAN_STATE=$2
# Call appropriate script based on script_type
SERVICE_SCRIPT_NAME="wan${WAN_IF}-$WAN_STATE"
SERVICE_SCRIPT_LOG="/tmp/WAN${WAN_IF}_state"
# Execute and log script state
if [[ -f "/jffs/scripts/$SERVICE_SCRIPT_NAME" ]] ; then
Say " Script executing.. for wan-event: "$SERVICE_SCRIPT_NAME
echo "$SERVICE_SCRIPT_NAME" > $SERVICE_SCRIPT_LOG
sh /jffs/scripts/$SERVICE_SCRIPT_NAME $*
else
Say " Script not defined for wan-event: "$SERVICE_SCRIPT_NAME
fi