8298 questions

9759 answers

15542 comments

13863 members

+1 vote
771 views 3 comments
by

Hi!

I have a RUT955 (FW ver.: RUT9XX_R_00.06.05.) and I am using mobile connection for WAN.

As the router does not support the 700MHz LTE Frequency at my current country I am limited to 3G WCDMA connection.

Now the problem is, that the 3G connection is being dropped every 5 minutes and I think it is the RUT955 dropping the conneciton and reconnecting.

In the log I see "user.notice /sbin/reregister.sh: Forcing LTE mode" but that option is disabled in the GUI:

root@Teltonika-RUT955:~# cat /etc/config/reregister

config reregister 'reregister'
        option enabled '0'
        option force_reregister '0'
        option interval '3600'
root@Teltonika-RUT955:~#

As a workaround I wanted to place a "exit 0" at the top of /sbin/reregister.sh, but it seems the router is executing another version of that file?!

Does anybody have an Idea if that might be a firmware bug and/or can help me to make my workaround work?

And what about those "Permission denied" messages? They also might expose some (maybe unrelated) problem.

Here is the log:

[connection is active]
Sun Feb  2 11:04:16 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:04:16 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,5' (11)
Sun Feb  2 11:04:21 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:04:21 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",61,-63,-1' (24)
Sun Feb  2 11:04:21 2020 local1.info gsmd[2811]: gsmd send: 'AT+CREG?' (9)
Sun Feb  2 11:04:21 2020 local1.info gsmd[2811]: gsmd get: '+CREG: 2,5,"2712","051202D",2' (29)
Sun Feb  2 11:04:21 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:04:21 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,5' (11)
Sun Feb  2 11:05:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:05:14 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",55,-57,-2' (24)
Sun Feb  2 11:05:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+CREG?' (9)
Sun Feb  2 11:05:14 2020 local1.info gsmd[2811]: gsmd get: '+CREG: 2,5,"2712","051202D",2' (29)
Sun Feb  2 11:05:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:05:14 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,5' (11)
Sun Feb  2 11:06:48 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:06:48 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",61,-64,-1' (24)
Sun Feb  2 11:06:48 2020 local1.info gsmd[2811]: gsmd send: 'AT+CREG?' (9)
Sun Feb  2 11:06:48 2020 local1.info gsmd[2811]: gsmd get: '+CREG: 2,5,"2712","051202D",2' (29)
Sun Feb  2 11:06:48 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:06:48 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,5' (11)
Sun Feb  2 11:07:04 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:04 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",61,-62,-1' (24)
Sun Feb  2 11:07:04 2020 user.notice /sbin/reregister.sh: Forcing LTE mode
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp_4 (23175): udhcpc: received SIGTERM
Sun Feb  2 11:07:04 2020 daemon.notice netifd: Interface 'ppp_4' is now down
Sun Feb  2 11:07:04 2020 daemon.notice netifd: Network alias '' link is down
Sun Feb  2 11:07:04 2020 daemon.notice netifd: Interface 'ppp_4' has link connectivity loss
Sun Feb  2 11:07:04 2020 daemon.notice netifd: Interface 'ppp_4' is disabled
Sun Feb  2 11:07:04 2020 daemon.warn dnsmasq[21873]: no servers found in /tmp/resolv.conf.auto, will retry
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (29582): teardown: ppp
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (29582): Command failed: Permission denied
Sun Feb  2 11:07:04 2020 local1.info hotplug-gsmstate[29661]: envACT: ifdown
Sun Feb  2 11:07:04 2020 local1.info hotplug-gsmstate[29661]: envINT: ppp
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (21507): Command failed: Permission denied
Sun Feb  2 11:07:04 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:04 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",61,-62,-1' (24)
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (21507): [02-02_11:07:04:433] requestDeactivateDefaultPDP err = 0
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (21507): [02-02_11:07:04:433] /lib/netifd/mobile.script down wwan0 ppp
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (21507): [02-02_11:07:04:692] QmiWwanThread exit
Sun Feb  2 11:07:04 2020 daemon.notice netifd: ppp (21507): [02-02_11:07:04:693] main exit
Sun Feb  2 11:07:04 2020 daemon.notice netifd: Interface 'ppp' is now down
Sun Feb  2 11:07:04 2020 user.info Messaged[29708]: Start from new event "Mobile Data" "Mobile data disconnected"
Sun Feb  2 11:07:04 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:04 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",61,-62,-1' (24)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",69,-70,-2' (24)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd send: 'AT+CREG?' (9)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd get: '+CREG: 2,5,"2712","051202D",2' (29)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,5' (11)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:07 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",69,-70,-2' (24)
Sun Feb  2 11:07:08 2020 user.info Messaged[30358]: Start from new event "Network Type" "Joined 3G WCDMA"
Sun Feb  2 11:07:09 2020 daemon.err insmod: module is already loaded - xt_multiport
Sun Feb  2 11:07:09 2020 daemon.err insmod: module is already loaded - xt_connmark
Sun Feb  2 11:07:09 2020 daemon.err insmod: module is already loaded - xt_length
Sun Feb  2 11:07:09 2020 local1.info gsmd[2811]: gsmd send: 'AT+CPIN?' (9)
Sun Feb  2 11:07:09 2020 local1.info gsmd[2811]: gsmd get: '+CPIN: READY' (12)
Sun Feb  2 11:07:09 2020 local1.info gsmd[2811]: gsmd send: 'AT+CIMI' (8)
Sun Feb  2 11:07:09 2020 local1.info gsmd[2811]: gsmd get: '340200104502576' (15)
Sun Feb  2 11:07:09 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGMR' (8)
Sun Feb  2 11:07:09 2020 local1.info gsmd[2811]: gsmd get: 'EC25EFAR03A08M4G' (16)
Sun Feb  2 11:07:10 2020 local1.notice fwblock[30767]: Started fwblock
Sun Feb  2 11:07:10 2020 local1.notice fwblock[30767]: Applying SSH blocks
Sun Feb  2 11:07:10 2020 local1.notice fwblock[30767]: Applying WebUI blocks
Sun Feb  2 11:07:12 2020 daemon.info dnsmasq[21873]: exiting on receipt of SIGTERM
Sun Feb  2 11:07:12 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:12 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "WCDMA",69,-65,-2' (24)
Sun Feb  2 11:07:12 2020 daemon.notice netifd: Interface 'ppp' is setting up now
Sun Feb  2 11:07:12 2020 daemon.notice netifd: ppp (30978): setup: ppp
Sun Feb  2 11:07:12 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCFG="roamservice",2,1' (26)
Sun Feb  2 11:07:12 2020 local1.info gsmd[2811]: gsmd get: 'OK' (2)
Sun Feb  2 11:07:12 2020 daemon.notice netifd: ppp (30978): OK
Sun Feb  2 11:07:13 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGDCONT=2' (13)
Sun Feb  2 11:07:13 2020 local1.info gsmd[2811]: gsmd get: 'OK' (2)
Sun Feb  2 11:07:13 2020 daemon.notice netifd: ppp (30978): OK
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGDCONT=3' (13)
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd get: 'OK' (2)
Sun Feb  2 11:07:14 2020 daemon.notice netifd: ppp (30978): OK
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGDCONT=4' (13)
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd get: 'OK' (2)
Sun Feb  2 11:07:14 2020 daemon.notice netifd: ppp (30978): OK
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGMR' (8)
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd get: 'EC25EFAR03A08M4G' (16)
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd send: 'AT+QICSGP=1,1,"web.digicelfr.com","","",0' (42)
Sun Feb  2 11:07:14 2020 local1.info gsmd[2811]: gsmd get: 'OK' (2)
Sun Feb  2 11:07:14 2020 daemon.notice netifd: ppp (30978): OK
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "NOSERVICE"' (18)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "NOSERVICE"' (18)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+CREG?' (9)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+CREG: 2,2' (10)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,2' (11)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+CREG?' (9)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+CREG: 2,2' (10)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+CGREG?' (10)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+CGREG: 0,2' (11)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+QCSQ' (8)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+QCSQ: "NOSERVICE"' (18)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd send: 'AT+COPS?' (9)
Sun Feb  2 11:07:17 2020 local1.info gsmd[2811]: gsmd get: '+COPS: 0' (8)
by
Update:

looking at the process table I noticed that "reregister.sh" is running for more than some seconds so I can assume it was at the point where "sleep" is called for $INTERVAL seconds.

There was only a "sleep 300" running at this time which fits perfectly because connection is dropped every 5 minutes.

This is strange though: INTERVAL is determined by the script by running "uci get reregister.reregister.interval", but when I run this in my root shell I get "3600" and that is the amount of seconds that I set in the webinterface because I was guessing before that the default setting of 300 here might be the culprit somehow.

Now the interesting part: I killed reregister.sh and since then the connection is stable.

So these permission denied messages may be the root cause of that problem. I guess that reregister is about to being disabled but failing some how making it getting started.

But why? And why does it have the default of 300 for INTERVAL and not what is in uci?

Any Idea somebody?
by

Update 2:

I created a workaround if this problem occurs: In the firewall custom rules you can enter shell commands and they get executed when the firewall is reloaded, which is the case when mobile connection is established.

Here you can enter this command to kill reregister.sh:

pgrep -f reregister.sh | xargs -r kill

(I tested this command within a root shell but not yet in the custom firewall rules. Why? Read on...)

However:

After rebooting the router it now all works as expected! And this although I did several reboots within the last few weeks and the behavior persistet.

Though I played with some settings and I think one combination of these is triggering the wrong behavior. But now - everthign working without disconnects - I have:

  • Use IPv4 only (in Mobile Configuration)
  • QMI (Connection type in Mobile Configuration)
  • enabled "Use DNS servers advertised by peer" WAN Common Configuration (Before I had disabled this option and added 8.8.8.8)

My guess is that the last of these three is triggering it, but I did not test it. I will write another update when I know more.

by
Would be interest to hear if you get an answer to this one.

1 Answer

0 votes
by

Hi,

In several weeks new FW version will be released with changes to operctl service which is responsible for registering to the network operator.

If there will be no delays FW ver.: RUT9XX_R_00.06.06 will be downloadable from wiki on 21st of February.