RUT951 FW 07.07.1 - Connectivity issues

Hi,

We were recently started using the FW 07.07.1 and it looks like it’s causing some connectivity issues. Some times and after the RUT951 device(s) are switched on, they struggle to provide internet (from the mobile interface) for the PC devices plugged into them.

I can ping from the router (e.g. ping 8.8.8.8 or ping -I qmimuxX 8.8.8.8) but this doesn’t work from the PC. ifconfig and ip r look ok, with the routes and the WAN_IP.

A power cycle usually resolves the issue or the gsmd restart, which makes me think whether there’s a race condition and something fails.

There are a few (Called out method not supported) errors, e.g. GSM error in "generic_disable_gea1_gea2_cb:121" (Called out method not supported), gsmd_method_id: "171" in the logs but I’m not sure if they’re related or not.

[Tue Jun 11 11:32:41] [gsm.modem0] Modem is already in CFUN: "2"(full) state
[Tue Jun 11 11:32:41] [gsm.modem0] Init: disable_gea
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_disable_gea1_gea2_cb:121" (Called out method not supported), gsmd_method_id: "171"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: ue usage
[Tue Jun 11 11:32:41] [gsm.modem0] Init: mbn_autosel
[Tue Jun 11 11:32:41] [gsm.modem0] Init: auto_timezone
[Tue Jun 11 11:32:41] [gsm.modem0] Init: mbn
[Tue Jun 11 11:32:41] [gsm.modem0] MBN: "ROW_Generic_3GPP", SELECTED: "1", ACTIVE: "1"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: usbnet
[Tue Jun 11 11:32:41] [gsm.modem0] Init: nat settings
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_nat_set_cb:331" (Called out method not supported), gsmd_method_id: "81"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: auth bit
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_set_auth_bit:361" (Called out method not supported), gsmd_method_id: "151"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: rat_priority
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_set_rat_priority:391" (Called out method not supported), gsmd_method_id: "167"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: mgcfg
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_mgcfg_cb:479" (Called out method not supported), gsmd_method_id: "105"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: mtu
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_set_mtu_info:422" (Called out method not supported), gsmd_method_id: "102"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: ipv6_ndp
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_set_ipv6_ndp:450" (Called out method not supported), gsmd_method_id: "174"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: msg fmt
[Tue Jun 11 11:32:41] [gsm.modem0] Init: urc port
[Tue Jun 11 11:32:41] [gsm.modem0] Init: signal query
[Tue Jun 11 11:32:41] [gsm.modem0] Init: sim state
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_sim_state_cfg_cb:604" (Called out method not supported)
[Tue Jun 11 11:32:41] [gsm.modem0] Init: sms mode
[Tue Jun 11 11:32:41] [gsm.modem0] Init: roaming_svc
[Tue Jun 11 11:32:41] [gsm.modem0] Init: m2m_func
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "generic_set_m2m_state:830" (Called out method not supported), gsmd_method_id: "96"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: urc_cause
[Tue Jun 11 11:32:41] [gsm.modem0] Init: modem_func
[Tue Jun 11 11:32:41] [gsm.modem0] Modem is in dynamic operation mode
[Tue Jun 11 11:32:41] [gsm.modem0] Init: sms_storage_check
[Tue Jun 11 11:32:41] [gsm.modem0] Init: set_urc_ind_cfg
[Tue Jun 11 11:32:41] [gsm.modem0] Modem is already in CFUN: "2"(full) state
[Tue Jun 11 11:32:41] [gsm.modem0] Init: functionality
[Tue Jun 11 11:32:41] [gsm.modem0] Modem is already in CFUN: "2"(full) state
[Tue Jun 11 11:32:41] [gsm.modem0] Init: net reg
[Tue Jun 11 11:32:41] [gsm.modem0] Init: net greg
[Tue Jun 11 11:32:41] [gsm.modem0] Init: net ereg
[Tue Jun 11 11:32:41] [gsm.modem0] Init: net c5greg
[Tue Jun 11 11:32:41] [gsm.modem0] GSM error in "mb_set_net_reg:731" (Called out method not supported), gsmd_method_id: "24"
[Tue Jun 11 11:32:41] [gsm.modem0] Init: clip mode
[Tue Jun 11 11:32:41] [gsm.modem0] Init: CRC mode
[Tue Jun 11 11:32:41] [gsm.modem0] Init: CNMI mode
[Tue Jun 11 11:32:41] [gsm.modem0] Scheduling init process 'CNMI mode' for "200ms"
[Tue Jun 11 11:32:41] [gsm.modem0] Modem is already in CFUN: "2"(full) state
[Tue Jun 11 11:32:42] [gsm.modem0] Init process was sheduled, last init entry executed 'CNMI mode'
[Tue Jun 11 11:32:42] [gsm.modem0] Init: net mode
[Tue Jun 11 11:32:42] [gsm.modem0] Will use "auto" service mode.
[Tue Jun 11 11:32:42] [gsm.modem0] Modem is in correct service mode "Auto"
[Tue Jun 11 11:32:42] [gsm.modem0] GSM error in "set_network_category:273" (Called out method not supported), gsmd_method_id: "116"
[Tue Jun 11 11:32:42] [gsm.modem0] Network category "m1_and_nb1" is not supported. Network category won't be changed
[Tue Jun 11 11:32:42] [gsm.modem0] Scheduling init process 'net mode' for "1500ms"
[Tue Jun 11 11:32:43] [gsm.modem0] Modem is already in CFUN: "2"(full) state
[Tue Jun 11 11:32:43] [gsm.modem0] Init process was sheduled, last init entry executed 'net mode'

Many thanks

After some digging, it seems the issue is related to the firewall as it works after restarting the service.

The RUT951 was disconnected from the mobile network and after a few secs/mins the connection was restored; I’m able to ping 8.8.8.8 from the router itself but not from the PC connected to the router (only the router’s IP can be pinged). Does the firewall conflict with the cconntrack flushing or could be a race condition?

Here’s the last few logs:

Mon Jun 17 12:41:20 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:41:20 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:41:21 2024 kern.info Mobile data disconnected (internal modem)
Mon Jun 17 12:41:25 2024 user.notice mwan3-hotplug[22949]: Execute ifup event on interface mob1s1a1 (wwan0)
Mon Jun 17 12:41:26 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names
Mon Jun 17 12:41:26 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:41:26 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:41:31 2024 kern.info Switched to backup WAN (mob1s1a1)
Mon Jun 17 12:41:32 2024 user.info mwan3track[5444]: Detect ifup event on interface mob1s1a1 (qmimux0)
Mon Jun 17 12:41:33 2024 user.notice mwan3track[5444]: Interface mob1s1a1 (qmimux0) is online
Mon Jun 17 12:41:38 2024 user.notice firewall: Reloading firewall due to ifup of mob1s1a1 (wwan0)
Mon Jun 17 12:41:43 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names
Mon Jun 17 12:41:43 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:41:43 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:41:46 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names
Mon Jun 17 12:41:46 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:41:46 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:41:48 2024 user.notice mwan3-hotplug[24124]: Execute ifup event on interface mob1s1a1 (qmimux0)
Mon Jun 17 12:41:52 2024 kern.info Switched to backup WAN (mob1s1a1)
Mon Jun 17 12:41:52 2024 user.info mwan3track[5444]: Detect ifup event on interface mob1s1a1 (qmimux0)
Mon Jun 17 12:41:52 2024 user.info mwan3track[5444]: Check (ping) failed for target "1.1.1.1" on interface mob1s1a1 (qmimux0). Current score: 2
Mon Jun 17 12:41:54 2024 user.notice firewall: Reloading firewall due to ifup of mob1s1a1_4 (qmimux0)
Mon Jun 17 12:41:54 2024 user.info mwan3track[5444]: Check (ping) failed for target "8.8.8.8" on interface mob1s1a1 (qmimux0). Current score: 2
Mon Jun 17 12:41:54 2024 user.notice mwan3track[5444]: Interface mob1s1a1 (qmimux0) is disconnecting
Mon Jun 17 12:42:00 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names
Mon Jun 17 12:42:00 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:42:00 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:42:01 2024 user.notice mwan3track[5444]: Interface mob1s1a1 (qmimux0) is offline
Mon Jun 17 12:42:04 2024 user.notice mwan3-hotplug[24910]: Execute disconnected event on interface mob1s1a1 (qmimux0)
Mon Jun 17 12:42:04 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names
Mon Jun 17 12:42:04 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:42:04 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:42:06 2024 kern.info Mobile data connected (internal modem)
Mon Jun 17 12:42:06 2024 kern.info Joined LTE network (internal modem)
Mon Jun 17 12:42:06 2024 kern.info Connected to vodafone UK KPN operator (internal modem)
Mon Jun 17 12:42:08 2024 kern.info WAN (mob1s1a1) is down, no more backups to switch
Mon Jun 17 12:42:08 2024 user.info mwan3-hotplug[24910]: Connection tracking flushed for interface 'mob1s1a1' on action 'disconnected'
Mon Jun 17 12:42:13 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names
Mon Jun 17 12:42:13 2024 daemon.info dnsmasq[3833]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Mon Jun 17 12:42:13 2024 daemon.info dnsmasq-dhcp[3833]: read /etc/ethers - 0 addresses
Mon Jun 17 12:42:14 2024 user.notice mwan3track[5444]: Interface mob1s1a1 (qmimux0) is online
Mon Jun 17 12:42:17 2024 daemon.info dnsmasq[3833]: read /etc/hosts - 12 names