Modem hanging up when sending SMS

Hi to all,
RUT200 updated to one of the latest firmwares (firmware updated to the latest available just few days ago.
I have two SIM from same operator: first SIM correctly works (I can send/receive SMS) while using second SIM I get modem hanging up when trying to send SMS.
SIM correctly work on smartphone.
How can I debug SMS?
Thanks.

Hello,

In the WebUI, navigate to System → Maintenance → Troubleshoot, and check the System logs after you’ve attempted to send an SMS message. These logs might help identify any errors causing the issue. If you need assistance analyzing the logs, please let me know.

Best Regards,

Tested several firmwares (about 5 before latest available), at the end I restored latest available (RUT2M_R_00.07.09).
This hapens on RUT200 with both modem firmware updated and modem firmware not updated.
I suppose something wrong with modem.

root@OZEM:~# date && gsmctl -S -s “33xxxxxxx Test RUT200” && date
Mon Sep 9 08:21:32 UTC 2024
[gsmctl_send_sms:22] error: ERROR: Request timed out
Mon Sep 9 08:24:12 UTC 2024
root@OZEM:~#

Here system log:

Mon Sep 9 08:20:00 2024 cron.err crond[3931]: USER root pid 14794 cmd /usr/sbin/ping_reboot.sh cfg01c21d
Mon Sep 9 08:20:01 2024 user.notice ping_reboot.sh: Ping successful.
Mon Sep 9 08:22:35 2024 daemon.notice netifd: mob1s1a1 (13911): Command failed: Request timed out
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.376512] usb 1-1: USB disconnect, device number 11
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.384115] cdc_ether 1-1:1.0 usb0: unregister ‘cdc_ether’ usb-101c0000.ehci-1, CDC Ethernet Device
Mon Sep 9 08:22:35 2024 daemon.notice netifd: Network device ‘usb0’ link is down
Mon Sep 9 08:22:35 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ has link connectivity loss
Mon Sep 9 08:22:35 2024 daemon.notice netifd: Interface ‘mob1s1a1_6’ has link connectivity loss
Mon Sep 9 08:22:35 2024 daemon.notice odhcp6c[13931]: carrier => 0 event on
Mon Sep 9 08:22:35 2024 daemon.err odhcp6c[13931]: Failed to send RS (Network unreachable)
Mon Sep 9 08:22:35 2024 daemon.notice odhcp6c[13931]: (re)starting transaction on usb0
Mon Sep 9 08:22:35 2024 daemon.info odhcp6c[13931]: Interface usb0 sending router solicitation message
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.445349] option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.453648] option 1-1:1.2: device disconnected
Mon Sep 9 08:22:35 2024 daemon.notice odhcp6c[13931]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Mon Sep 9 08:22:35 2024 daemon.err odhcp6c[13931]: Failed to send SOLICIT message to ff02::1:2 (Network unreachable)
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.565350] option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.573626] option 1-1:1.3: device disconnected
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.578975] option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Mon Sep 9 08:22:35 2024 kern.info kernel: [ 1939.587309] option 1-1:1.4: device disconnected
Mon Sep 9 08:22:36 2024 daemon.err odhcp6c[13931]: Failed to send SOLICIT message to ff02::1:2 (Network unreachable)
Mon Sep 9 08:22:38 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ is disabled
Mon Sep 9 08:22:38 2024 daemon.notice netifd: Interface ‘mob1s1a1_6’ is disabled
Mon Sep 9 08:22:38 2024 daemon.notice netifd: Interface ‘mob1s1a1_6’ is now down
Mon Sep 9 08:22:38 2024 daemon.warn dnsmasq[1534]: no servers found in /tmp/resolv.conf.d/resolv.conf.auto, will retry
Mon Sep 9 08:22:39 2024 daemon.notice netifd: mob1s1a1 (15032): Stopping network mob1s1a1
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: SIOCGIFINDEX: No such device
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: received SIGTERM
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: unicasting a release of 10.66.36.91 to 169.254.0.1
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: sending release
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: can’t bind to interface usb0: No such device
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: bindtodevice: No such device
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): udhcpc: entering released state
Mon Sep 9 08:22:40 2024 daemon.notice netifd: mob1s1a1_4 (13919): Command failed: Permission denied
Mon Sep 9 08:22:40 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ is now down
Mon Sep 9 08:22:41 2024 kern.info Mobile data disconnected (internal modem)
Mon Sep 9 08:22:42 2024 kern.info kernel: [ 1946.019718] usb 1-1: new high-speed USB device number 12 using ehci-platform
Mon Sep 9 08:22:42 2024 daemon.notice netifd: mob1s1a1 (15032): Command failed: Request timed out
Mon Sep 9 08:22:42 2024 daemon.notice netifd: mob1s1a1 (15032): Command failed: Not found
Mon Sep 9 08:22:42 2024 kern.info kernel: [ 1946.554922] usb 1-1: USB disconnect, device number 12
Mon Sep 9 08:22:43 2024 daemon.notice netifd: mob1s1a1 (15032): Command failed: Permission denied
Mon Sep 9 08:22:43 2024 daemon.notice netifd: Interface ‘mob1s1a1’ is now down
Mon Sep 9 08:22:48 2024 daemon.info dnsmasq[1534]: read /etc/hosts - 12 names
Mon Sep 9 08:22:48 2024 daemon.info dnsmasq[1534]: read /tmp/hosts/dhcp.cfg01411c - 0 names
Mon Sep 9 08:22:49 2024 kern.info Mobile data disconnected (internal modem)
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.234990] usb 1-1: new high-speed USB device number 13 using ehci-platform
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.442717] cdc_ether 1-1:1.0 usb0: register ‘cdc_ether’ at usb-101c0000.ehci-1, CDC Ethernet Device, 02:0c:29:a3:9b:6d
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.475734] option 1-1:1.2: GSM modem (1-port) converter detected
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.482339] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.515741] option 1-1:1.3: GSM modem (1-port) converter detected
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.522305] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.545767] option 1-1:1.4: GSM modem (1-port) converter detected
Mon Sep 9 08:22:50 2024 kern.info kernel: [ 1954.552992] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
Mon Sep 9 08:22:57 2024 daemon.info gsmd[1791]: [ubus_notify_event:299] error: [MODEM_UBUS] Failed to send ubus notify for 1-1 [2c7c:6005] modem!
Mon Sep 9 08:22:57 2024 daemon.info mobifd: [gsm.modem0] Starting modem settings init
Mon Sep 9 08:22:57 2024 daemon.err mobifd: [gsm.modem0] Failed to disable GEA1 and GEA2 algorithms
Mon Sep 9 08:23:00 2024 daemon.info mobifd: [gsm.modem0] SIM is ready
Mon Sep 9 08:23:02 2024 daemon.info mobifd: [gsm.modem0] Modem settings init completed
Mon Sep 9 08:23:02 2024 daemon.info mobifd: [gsm.modem0] Starting connection setup
Mon Sep 9 08:23:02 2024 daemon.info mobifd: [gsm.modem0] Skipping: mb_set_volte_value. Value may not be in effect
Mon Sep 9 08:23:02 2024 daemon.info mobifd: [gsm.modem0] Attempting to establish connection to operator with “15s” of timeout
Mon Sep 9 08:23:02 2024 daemon.info mobifd: [gsm.modem0] Connected to operator “I TIM”
Mon Sep 9 08:23:03 2024 daemon.info mobifd: [gsm.modem0] -CFUN- Functionality: “Full”
Mon Sep 9 08:23:03 2024 daemon.info mobifd: [gsm.modem0] -COPS- Mode: “Auto”, operator: “I TIM”
Mon Sep 9 08:23:03 2024 daemon.info mobifd: [gsm.modem0] -CREG- Mode: “Enabled (with location information)”, status: “Registered, home”, LAC: “15101”, cell ID: “179233056”, technology: “E-UTRAN”
Mon Sep 9 08:23:03 2024 daemon.info mobifd: [gsm.modem0] -CGREG- Mode: “Enabled (with location information)”, status: “Registered, home”, LAC: “15101”, cell ID: “179233056”, technology: “E-UTRAN”
Mon Sep 9 08:23:03 2024 daemon.info mobifd: [gsm.modem0] -CEREG- Mode: “Enabled (with location information)”, status: “Registered, home”, LAC: “”, cell ID: “179233056”, technology: “E-UTRAN”
Mon Sep 9 08:23:03 2024 daemon.info mobifd: [gsm.modem0] IP address on PDP context “1”: “10.66.221.142”
Mon Sep 9 08:23:03 2024 daemon.notice netifd: Interface ‘mob1s1a1’ is setting up now
Mon Sep 9 08:23:04 2024 daemon.notice netifd: mob1s1a1 (15716): wwan[15716] Using wwan usb device on bus 1-1
Mon Sep 9 08:23:04 2024 daemon.notice netifd: mob1s1a1 (15716): wwan[15716] Using proto:cdc_ether device:usb0 iface:usb0 desc:Quectel EC200A
Mon Sep 9 08:23:05 2024 daemon.notice netifd: mob1s1a1 (15716): Connection setup for mob1s1a1 starting!
Mon Sep 9 08:23:05 2024 daemon.notice netifd: mob1s1a1 (15716): Activating PDP CID1!
Mon Sep 9 08:23:05 2024 daemon.notice netifd: mob1s1a1 (15716): Starting setup data call!
Mon Sep 9 08:23:07 2024 daemon.notice netifd: mob1s1a1 (15716): Setting MTU: 1500 on usb0
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1’ is now up
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Network device ‘usb0’ link is up
Mon Sep 9 08:23:07 2024 daemon.notice netifd: mob1s1a1 (15716): Setting up usb0 V4 DCHP
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ is enabled
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ has link connectivity
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ is setting up now
Mon Sep 9 08:23:07 2024 daemon.notice netifd: mob1s1a1 (15716): Setting up usb0 V6 DHCP
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1_6’ is enabled
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1_6’ has link connectivity
Mon Sep 9 08:23:07 2024 daemon.notice netifd: Interface ‘mob1s1a1_6’ is setting up now
Mon Sep 9 08:23:08 2024 daemon.notice netifd: mob1s1a1_4 (15821): udhcpc: started, v1.34.1
Mon Sep 9 08:23:08 2024 daemon.notice netifd: mob1s1a1 (15813): Starting connection tracker for usb0!
Mon Sep 9 08:23:08 2024 daemon.err odhcp6c[15833]: Failed to send RS (Address not available)
Mon Sep 9 08:23:08 2024 daemon.notice odhcp6c[15833]: (re)starting transaction on usb0
Mon Sep 9 08:23:08 2024 daemon.info odhcp6c[15833]: Interface usb0 sending router solicitation message
Mon Sep 9 08:23:08 2024 daemon.notice netifd: mob1s1a1_4 (15821): udhcpc: broadcasting discover
Mon Sep 9 08:23:08 2024 daemon.notice netifd: mob1s1a1_4 (15821): udhcpc: broadcasting select for 10.66.221.142, server 169.254.0.1
Mon Sep 9 08:23:08 2024 daemon.notice netifd: mob1s1a1_4 (15821): udhcpc: lease of 10.66.221.142 obtained from 169.254.0.1, lease time 86400
Mon Sep 9 08:23:09 2024 daemon.notice odhcp6c[15833]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Mon Sep 9 08:23:09 2024 daemon.info mobifd: Auto APN is disabled for ‘mob1s1a1’. Skipping Ping To DNS functionality
Mon Sep 9 08:23:09 2024 daemon.notice netifd: Interface ‘mob1s1a1_4’ is now up
Mon Sep 9 08:23:09 2024 daemon.info dnsmasq[1534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Sep 9 08:23:09 2024 daemon.info dnsmasq[1534]: using nameserver 217.200.201.67#53
Mon Sep 9 08:23:09 2024 daemon.info dnsmasq[1534]: using nameserver 217.200.201.66#53
Mon Sep 9 08:23:09 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for test
Mon Sep 9 08:23:10 2024 daemon.info mobifd: Connection setup completed for ‘mob1s1a1’
Mon Sep 9 08:23:10 2024 daemon.info mobifd: Connection setup completed for modem: ‘gsm.modem0’
Mon Sep 9 08:23:10 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for onion
Mon Sep 9 08:23:10 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for localhost
Mon Sep 9 08:23:10 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for local
Mon Sep 9 08:23:10 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for invalid
Mon Sep 9 08:23:10 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for bind
Mon Sep 9 08:23:10 2024 daemon.info dnsmasq[1534]: using only locally-known addresses for lan
Mon Sep 9 08:23:10 2024 user.notice firewall: Reloading firewall due to ifup of mob1s1a1 (usb0)
Mon Sep 9 08:23:14 2024 daemon.info dnsmasq[1534]: read /etc/hosts - 12 names
Mon Sep 9 08:23:14 2024 daemon.info dnsmasq[1534]: read /tmp/hosts/dhcp.cfg01411c - 0 names
Mon Sep 9 08:23:15 2024 user.notice firewall: Reloading firewall due to ifup of mob1s1a1_4 (usb0)
Mon Sep 9 08:23:19 2024 daemon.info dnsmasq[1534]: read /etc/hosts - 12 names
Mon Sep 9 08:23:19 2024 daemon.info dnsmasq[1534]: read /tmp/hosts/dhcp.cfg01411c - 0 names
Mon Sep 9 08:23:20 2024 kern.info Mobile data connected (internal modem)
Mon Sep 9 08:23:20 2024 kern.info Joined LTE network (internal modem)
Mon Sep 9 08:23:20 2024 kern.info Connected to I TIM operator (internal modem)

Hello,

Could you please specify the module firmware version currently installed on your RUT200?

Best Regards,

  • Firmware version

RUT2M_R_00.07.09

  • Firmware build date

2024-08-29 09:38:31

  • Internal modem firmware version

EC200AEUHAR01A10M16_01.001.01.001

  • Kernel version

5.15.162

Thank you for the information. I recommend upgrading your internal modem’s firmware. I have sent you a form to fill out, and once completed, I will contact you privately to provide the file with the modem firmware. Please use ticket ID “7651”.

Best Regards