Question

Hello,

I am using the http api to sent an sms ;eg https://ip/cgi-bin/sms_send. Most of the times the API response with 200 OK but sometimes the API
response with 200 ERROR, the logread shows ". daemon.info gsmd[2016]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!"

Currently i see this behaviour on a rut950 and rut951

rut951:
[email protected]:/usr/sbin# mnf_info  -n
RUT95100XXXX
[email protected]:/usr/sbin# mnf_info  -H
0303

device_fw_version 'RUT9M_R_00.07.04'

What's causes this issue?

Kind regards.

Fri Mar 24 11:07:43 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:07:49 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:07:54 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:00 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:06 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:11 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:17 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:22 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:28 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:34 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:39 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:08:45 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:09:17 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:09:54 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:12:01 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:12:10 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:14:49 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:16:57 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:16:59 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:18:26 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:18:45 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:19:29 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:20:37 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:21:06 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:21:27 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:21:33 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:24:54 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:27:02 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:27:05 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:27:44 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:29:48 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:29:54 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:32:02 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:32:05 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:32:48 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:32:58 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:34:26 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:34:54 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:37:02 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:37:05 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:39:15 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:39:52 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:40:34 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:40:53 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:43:02 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:43:04 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:45:14 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:45:47 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:45:55 2023 kern.notice Authentication was successful from HTTPS 192.168.45.100

Fri Mar 24 11:45:55 2023 daemon.err uhttpd[2365]: vuci: accepted login for admin from 192.168.45.100

Fri Mar 24 11:47:24 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:47:35 2023 daemon.err uhttpd[2365]: Command failed: Request timed out

Fri Mar 24 11:48:32 2023 daemon.info gsmd[2057]: [check_req_timeout:104] error: [MODEM_MANAGER] Warning: request reached timeout (126s) on `1-1 [2c7c:0125]` modem!

Fri Mar 24 11:49:13 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:49:45 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:49:50 2023 daemon.err uhttpd[2365]: Command failed: Method not found

Fri Mar 24 11:49:51 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:49:56 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:49:59 2023 authpriv.info dropbear[15936]: Child connection from 192.168.45.100:39024

Fri Mar 24 11:50:02 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:50:08 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:50:13 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:50:19 2023 daemon.debug sms_send: Calling 'sms_send' handler

Fri Mar 24 11:52:21 2023 authpriv.notice dropbear[15936]: Password auth succeeded for 'root' from 192.168.45.100:39024

Fri Mar 24 11:52:21 2023 kern.notice Password auth succeeded for root from 192.168.45.100:39024

[email protected]:~# 

---

25695 root      1664 S    sleep 20

25710 root      2364 S    /www/cgi-bin/sms_send

25741 root      1664 R    ps w

25756 root      1704 R    /bin/sh -c . /lib/functions.sh . /etc/hotplug.d/gsm/2-fill-modem-info 

25762 root      1700 R    /bin/sh -c . /lib/functions.sh . /etc/hotplug.d/gsm/2-fill-modem-info 

25763 root      1704 R    /bin/sh -c . /lib/functions.sh . /etc/hotplug.d/gsm/2-fill-modem-info 

25764 root      1704 R    /bin/sh -c . /lib/functions.sh . /etc/hotplug.d/gsm/2-fill-modem-info 

25765 root      1700 R    /bin/sh -c . /lib/functions.sh . /etc/hotplug.d/gsm/2-fill-modem-info 

Answer 1

Hello,

I would like you to attach a troubleshoot file to your question. Please, replicate the issue by trying to send SMS using the HTTP API, then access router's WebUI, go to System -> Administration -> Troubleshoot section and download troubleshoot file from there. The logs in the file might provide more insight into the issue.

Attached files are private and visible only to Teltonika Moderators.

Best regards,

Comments

See attachment for the file

---

Hello,

The issue has been forwarded for further investigation. Once there are updates, I will inform you.

Best regards,

---

Hello,

There is an update from the developers, in regards to your issue.

In case SMS messages from the router are being sent back to same phone, which also receives the reply, then this is known issue. It is caused by single-threaded modem nature. meaning that it tries to read SMS while sending another. Some sort or race condition occurs, which results in the error you receive. This happens inside modem and we don't have much control over it, as its software is developed by Quectel.

A while ago this issue was encountered during testing, but was not replicated, despite trying different setups. It was concluded to be an operator's fault.

Lastly, it is also possible to experience modem timeouts, if a badly formatted PDU is sent. However, this does not apply to your case.

In conclusion, the issue is most likely caused by hardware limitations, and not much can be done to prevent it.

Best regards,

---

Goodmorning,

Thank you for the thorough answer! Too bad it's an issue which is out of the span of control of Teltonika :(

Are you aware of other Teltonika products, for example rut360, which don't have this issue??

Kind regards,

Peter Wolters

---

According to the developers, despite RUT360 having a different modem, also used in most RUTX series devices, probability of this issue occurring is similar on RUT360 as well. Additionally, the frequency of issue occurring might be influenced by operator as, during testing, it was noticed that this issue is more prevalent with come operators than others.

Best regards,

 

---

Alright, are you aware if there's a method to set a different response phonenumber in a sms?

---

Could you clarify?

As I understand, you are using Post/Get. The phone number to send SMS to is to modify the URL used:

• http://192.168.1.1/cgi-bin/sms_send?username=user1&password=user_pass&number=0037060000001&text=testmessage

Best regards,

---

If you send an email you can supply a reply to field. I was wondering if the sms protocol also support such kind of option.

You mentioned that the problem occurs in code written by Qectel, however the problem also occurs in RUT950 which have a Meiglink modem.

Can you please clarify why it also occurs in the Meiglink models?

[email protected]:~# gsmctl --info

{

"name": "Meiglink SLM750-VE",

"model": "SLM750-VE",

"manuf": "Meiglink",

"driver": "Meiglink AT",

"usb_id": "1-1",

"vid_pid": "05c6:f601",

"tty_port": "/dev/ttyUSB3",

"gps_port": "/dev/ttyUSB4",

"baudrate": 115200,

"aux_port": "/dev/modem0",

"builtin": true,

"primary": true,

"simcount": 2,

"is_busy": 0,

"pending": 0,

"state_id": 1,

"state": "Idle",

"last_active": "2023-04-03 12:58:36",

"band_list": [

"GSM_900",

"GSM_1800",

"WCDMA_850",

"WCDMA_900",

"WCDMA_2100",

"LTE_B1",

"LTE_B3",

"LTE_B5",

"LTE_B7",

"LTE_B8",

"LTE_B20",

"LTE_B40"

],

"cache": {

"firmware": "SLM750-V_4.57.20_EQ101",

"serial_num": "750VE14LYB053000040",

"imei": "868159052130429",

"pin_state": 1,

"pin_state_str": "OK",

"gsm_bands": 1049472,

"wcdma_bands": 562950024724480,

"lte_low_bands": 549756338389,

"lte_high_bands": 0,

"service_mode": 21,

"service_mode_str": "LTE",

"rssi_value": -68,

"rsrq_value": -8,

"rsrp_value": -100,

"sinr_value": 13.900000,

"net_mode": 1,

"imsi": "204086464503735",

"sms_mode": 1,

"sms_mode_str": "PDU Mode",

"network_state": 1

},

"cache_stats": {

"heap_usage": "907 B",

"item_count": 20

},

"comm_stats": {

"tty_tx": 915121,

"tty_rx": 4622320,

"tx_highest": 314,

"rx_highest": 599,

"aux_fd_num": 0,

"recv_pipe_fd": 8,

"send_pipe_fd": 9

},

"parser_stats": {

"c_grow_cnt": 1,

"c_len": 0,

"c_cap": 1024,

"u_grow_cnt": 1,

"u_len": 0,

"u_cap": 1024

},

"evtmgr_stats": {

"recv_pipe_fd": 10,

"send_pipe_fd": 11

}

}

Enabled band:     GSM_900

Enabled band:     GSM_1800

Enabled band:     WCDMA_850

Enabled band:     WCDMA_900

Enabled band:     WCDMA_2100

Enabled band:     LTE_B1

Enabled band:     LTE_B3

Enabled band:     LTE_B5

Enabled band:     LTE_B7

Enabled band:     LTE_B8

Enabled band:     LTE_B20

Enabled band:     LTE_B40

[email protected]:~# 

---

Hello,

Apparently, Meig modules are susceptible to this issue as well. Possible causes are already mentioned previously. RnD has no further insights at the moment, as the issue is being worked on, but has not been reliably replicated to determine actual root causes and develop preventative solutions.

Apologies for the inconveniences.

Best regards,