Hello, I´m trying to figure out why I lose connection with a frequency of about 2 days in my Arcadian AW1000.
When that happens, I need to restart the router and then everything works fine until the disconnection happens again.
Any advice will be appreciated.
root@OpenWrt:~# ubus call system board
{
"kernel": "6.6.44",
"hostname": "OpenWrt",
"system": "ARMv8 Processor rev 4",
"model": "Arcadyan AW1000",
"board_name": "arcadyan,aw1000",
"rootfs_type": "squashfs",
"release": {
"distribution": "OpenWrt",
"version": "SNAPSHOT",
"revision": "r27123-8cf9a932fa",
"target": "qualcommax/ipq807x",
"description": "OpenWrt SNAPSHOT r27123-8cf9a932fa"
}
}
root@OpenWrt:~# cat/etc/config/network
-ash: cat/etc/config/network: not found
root@OpenWrt:~# cat /etc/config/network
config interface 'loopback'
option device 'lo'
option proto 'static'
option ipaddr '127.0.0.1'
option netmask '255.0.0.0'
config globals 'globals'
option ula_prefix 'fd7e:130d:ed86::/48'
config device
option name 'br-lan'
option type 'bridge'
list ports 'lan1'
list ports 'lan2'
list ports 'lan3'
list ports 'lan4'
config interface 'lan'
option device 'br-lan'
option proto 'static'
option ipaddr ''
option netmask '255.255.255.0'
option ip6assign '60'
option gateway ''
option dns ''
config interface 'wan'
option device 'wan'
option proto 'dhcp'
config interface 'wan6'
option device 'wan'
option proto 'dhcpv6'
config interface 'wwan'
option proto 'mbim'
option device '/dev/cdc-wdm0'
option apn 'ac.vodafone.es'
option auth 'none'
option pdptype 'ipv4v6'
opcion dns '9.9.9.9 149.112.112.112'
config interface 'OpenVPN'
option proto 'none'
option device 'tun0'
option auto '0'
Hello,
I´m attaching the logs of the disconnection. It happened exactly 48h after last reset.
Some commentaries:
10:14 -> Reset interface wwan (mbim). Could see interface up but it didn´t connect.
10:19 -> Disconnected OpenVPN
10:23 -> Have internet
Thanks again for all the help. I'm currently testing without OpenVPN to see if that is the root cause of the disconnections, but any look at the logs would be appreciated.
Fri Aug 16 09:49:02 2024 daemon.warn odhcpd[2274]: No default route present, overriding ra_lifetime to 0!
Fri Aug 16 09:50:08 2024 daemon.notice openvpn(spain)[8727]: [madrid402] Inactivity timeout (--ping-restart), restarting
Fri Aug 16 09:50:08 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,ping-restart] received, process restarting
Fri Aug 16 09:50:09 2024 daemon.warn openvpn(spain)[8727]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Fri Aug 16 09:50:09 2024 daemon.notice openvpn(spain)[8727]: TCP/UDP: Preserving recently used remote address: [AF_INET]212.102.49.6:1197
Fri Aug 16 09:50:09 2024 daemon.notice openvpn(spain)[8727]: UDPv4 link local: (not bound)
Fri Aug 16 09:50:09 2024 daemon.notice openvpn(spain)[8727]: UDPv4 link remote: [AF_INET]212.102.49.6:1197
Fri Aug 16 09:51:09 2024 daemon.err openvpn(spain)[8727]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Fri Aug 16 09:51:09 2024 daemon.err openvpn(spain)[8727]: TLS Error: TLS handshake failed
Fri Aug 16 09:51:09 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,tls-error] received, process restarting
Fri Aug 16 09:51:10 2024 daemon.warn openvpn(spain)[8727]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Fri Aug 16 09:51:10 2024 daemon.notice openvpn(spain)[8727]: TCP/UDP: Preserving recently used remote address: [AF_INET]212.102.49.193:1197
Fri Aug 16 09:51:10 2024 daemon.notice openvpn(spain)[8727]: UDPv4 link local: (not bound)
Fri Aug 16 09:51:10 2024 daemon.notice openvpn(spain)[8727]: UDPv4 link remote: [AF_INET]212.102.49.193:1197
Fri Aug 16 09:52:10 2024 daemon.err openvpn(spain)[8727]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Fri Aug 16 09:52:10 2024 daemon.err openvpn(spain)[8727]: TLS Error: TLS handshake failed
Fri Aug 16 09:52:10 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,tls-error] received, process restarting
Fri Aug 16 09:52:11 2024 daemon.warn openvpn(spain)[8727]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Fri Aug 16 09:52:11 2024 daemon.notice openvpn(spain)[8727]: TCP/UDP: Preserving recently used remote address: [AF_INET]212.102.49.28:1197
Fri Aug 16 09:52:11 2024 daemon.notice openvpn(spain)[8727]: UDPv4 link local: (not bound)
Fri Aug 16 09:52:11 2024 daemon.notice openvpn(spain)[8727]: UDPv4 link remote: [AF_INET]212.102.49.28:1197
Fri Aug 16 09:52:45 2024 daemon.warn odhcpd[2274]: No default route present, overriding ra_lifetime to 0!
Fri Aug 16 09:53:12 2024 daemon.err openvpn(spain)[8727]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Fri Aug 16 09:53:12 2024 daemon.err openvpn(spain)[8727]: TLS Error: TLS handshake failed
Fri Aug 16 09:53:12 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,tls-error] received, process restarting
Fri Aug 16 09:53:13 2024 daemon.warn openvpn(spain)[8727]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Fri Aug 16 09:53:18 2024 daemon.err openvpn(spain)[8727]: RESOLVE: Cannot resolve host address: spain.privacy.network:1197 (Try again)
Fri Aug 16 09:53:23 2024 daemon.err openvpn(spain)[8727]: RESOLVE: Cannot resolve host address: spain.privacy.network:1197 (Try again)
Fri Aug 16 09:53:23 2024 daemon.warn openvpn(spain)[8727]: Could not determine IPv4/IPv6 protocol
Fri Aug 16 09:53:23 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,Could not determine IPv4/IPv6 protocol] received, process restarting
-------------------- Error message repeats -----------------------------------
-------------------- Reset interface wwan (mbim) -------------------------
Fri Aug 16 10:14:07 2024 daemon.warn openvpn(spain)[8727]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Fri Aug 16 10:14:12 2024 daemon.err openvpn(spain)[8727]: RESOLVE: Cannot resolve host address: spain.privacy.network:1197 (Try again)
Fri Aug 16 10:14:17 2024 daemon.err openvpn(spain)[8727]: RESOLVE: Cannot resolve host address: spain.privacy.network:1197 (Try again)
Fri Aug 16 10:14:17 2024 daemon.warn openvpn(spain)[8727]: Could not determine IPv4/IPv6 protocol
Fri Aug 16 10:14:17 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,Could not determine IPv4/IPv6 protocol] received, process restarting
Fri Aug 16 10:14:43 2024 daemon.notice netifd: Interface 'wwan_4' is now down
Fri Aug 16 10:14:43 2024 daemon.notice netifd: Interface 'wwan_4' is disabled
Fri Aug 16 10:14:43 2024 daemon.notice netifd: Interface 'wwan_4' has link connectivity loss
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using nameserver
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Fri Aug 16 10:14:43 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Fri Aug 16 10:14:43 2024 daemon.notice netifd: Network alias '' link is down
Fri Aug 16 10:14:43 2024 daemon.notice netifd: wwan (13906): mbim[13906] Stopping network
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13906): sessionid: 0
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13906): activationstate: 0003 - deactivated
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13906): voicecallstate: 0000 - none
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13906): nwerror: 0000 - unknown
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13906): iptype: 0000 - default
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13906): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wwan" } (Permission denied)
Fri Aug 16 10:14:44 2024 daemon.notice netifd: Interface 'wwan' is now down
Fri Aug 16 10:14:44 2024 daemon.notice netifd: Interface 'wwan' is setting up now
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Reading capabilities
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): devicetype: 0001 - embedded
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): cellularclass: 0001
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): voiceclass: 0001 - no-voice
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): simclass: 0002
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): dataclass: 8000003C
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): smscaps: 0003
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): controlcaps: 0001
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): maxsessions: 000F
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): deviceid: 869119050183688
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): firmwareinfo: RG500QEAAAR13A01M4G
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): hardwareinfo: RG500QEA_VH
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Checking pin
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): required pin: 3 - pin2
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): remaining attempts: 3
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Checking subscriber
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): readystate: 0001 - initialized
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): simiccid: 8934569822200115808F
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): subscriberid: 214019829541342
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Register with network
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): nwerror: 0000 - unknown
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): registerstate: 0003 - home
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): registermode: 0001 - automatic
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): availabledataclasses: 80000020 - (null)
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): currentcellularclass: 0001 - gsm
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): provider_id: 21401
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): provider_name: vodafone ES
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): roamingtext: (null)
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Registered in home mode
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Attach to network
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): nwerror: 0000 - unknown
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): packetservicestate: 0002 - attached
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): uplinkspeed: 1200000000
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): downlinkspeed: 3200000000
Fri Aug 16 10:14:44 2024 daemon.notice netifd: wwan (13920): mbim[13920] Connect to network
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): sessionid: 0
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): activationstate: 0001 - activated
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): voicecallstate: 0000 - none
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): nwerror: 0000 - unknown
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): iptype: 0001 - ipv4
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): mbim[13920] Connected
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): mbim[13920] Setting up wwan0
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): ipv4address:
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): ipv4gateway:
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): ipv4mtu: 1500
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): ipv4dnsserver: 212.166.210.1
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): ipv4dnsserver: 212.166.167.73
Fri Aug 16 10:14:45 2024 kern.info kernel: [174376.379130] 8021q: adding VLAN 0 to HW filter on device wwan0
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Interface 'wwan' is now up
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Network device 'wwan0' link is up
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Network alias 'wwan0' link is up
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver 9.9.9.9#53
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver 149.112.112.112#53
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Interface 'wwan_4' is enabled
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Interface 'wwan_4' is setting up now
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Interface 'wwan_4' is now up
Fri Aug 16 10:14:45 2024 daemon.notice netifd: Interface 'wwan_4' has link connectivity
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver 9.9.9.9#53
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver 149.112.112.112#53
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver 212.166.210.1#53
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using nameserver 212.166.167.73#53
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Fri Aug 16 10:14:45 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Fri Aug 16 10:14:45 2024 daemon.notice netifd: wwan (13920): Setting MTU of wwan0 to 1500
Fri Aug 16 10:14:45 2024 user.notice firewall: Reloading firewall due to ifup of wwan (wwan0)
Fri Aug 16 10:14:45 2024 user.notice firewall: Reloading firewall due to ifup of wwan_4 (wwan0)
Fri Aug 16 10:14:46 2024 daemon.warn odhcpd[2274]: No default route present, overriding ra_lifetime to 0!
-------------------- Disconnected OpenVPN ------------------------
-------------------- Got internet -----------------------------------------
Fri Aug 16 10:19:17 2024 daemon.warn openvpn(spain)[8727]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Fri Aug 16 10:19:22 2024 daemon.err openvpn(spain)[8727]: RESOLVE: Cannot resolve host address: spain.privacy.network:1197 (Try again)
Fri Aug 16 10:19:27 2024 daemon.err openvpn(spain)[8727]: RESOLVE: Cannot resolve host address: spain.privacy.network:1197 (Try again)
Fri Aug 16 10:19:27 2024 daemon.warn openvpn(spain)[8727]: Could not determine IPv4/IPv6 protocol
Fri Aug 16 10:19:27 2024 daemon.notice openvpn(spain)[8727]: SIGUSR1[soft,Could not determine IPv4/IPv6 protocol] received, process restarting
Fri Aug 16 10:19:49 2024 daemon.notice openvpn(spain)[8727]: /usr/libexec/openvpn-hotplug route-pre-down spain tun0 0 0 10.5.110.57 255.255.255.0 init
Fri Aug 16 10:19:49 2024 daemon.warn openvpn(spain)[8727]: sitnl_send: rtnl: generic error (-3): No such process
Fri Aug 16 10:19:49 2024 daemon.warn openvpn(spain)[8727]: ERROR: Linux route delete command failed
Fri Aug 16 10:19:49 2024 daemon.notice openvpn(spain)[8727]: net_addr_v4_del: 10.5.110.57 dev tun0
Fri Aug 16 10:19:49 2024 daemon.notice netifd: Network device 'tun0' link is down
Fri Aug 16 10:19:49 2024 daemon.notice netifd: Interface 'OpenVPN' has link connectivity loss
Fri Aug 16 10:19:50 2024 daemon.notice openvpn(spain)[8727]: /usr/libexec/openvpn-hotplug down spain tun0 0 0 10.5.110.57 255.255.255.0 init
Fri Aug 16 10:19:50 2024 daemon.notice openvpn(spain)[8727]: SIGTERM[hard,init_instance] received, process exiting
Fri Aug 16 10:23:22 2024 daemon.warn odhcpd[2274]: No default route present, overriding ra_lifetime to 0!
Hello again, after testing without OpenVPN it again disconnected 48 hours later.
In the logs I cannot see anything wrong (at 10:04 I restarted wwan and got internet again) before the disconnection.
