TP-Link MR6400 v5, Problem to reconnect when ISP reseting 4G

Hi,
im on Openwrt 21.02.3 and have setup my 4G Connection with uqmi Version uqmi_2022-05-16-0.5_mipsel_24kc.ipk from mrhaav .
The Problem i have is after my ISP is reseting the connection when ~24h have passed, the connection is not getting restored. There is some time uqmi tries to reconnect but it ends with REGISTRATION_FAILED and i have to restart the interface 4G for it to work again.

Log looks like this for interface 4G

Mon Jun 27 20:04:43 2022 daemon.notice netifd: Interface '4G' has lost the connection
Mon Jun 27 20:04:43 2022 daemon.notice netifd: 4G (12932): Stopping network 4G
Mon Jun 27 20:04:44 2022 daemon.notice netifd: 4G (12932): Command failed: Permission denied
Mon Jun 27 20:04:44 2022 daemon.notice netifd: Interface '4G' is now down
Mon Jun 27 20:04:44 2022 daemon.notice netifd: Interface '4G' is setting up now
Mon Jun 27 20:04:45 2022 daemon.notice netifd: 4G (13073): PINcode disabled
Mon Jun 27 20:04:46 2022 daemon.notice netifd: 4G (13073): Data format set to raw-ip
Mon Jun 27 20:04:46 2022 daemon.notice netifd: 4G (13073): Default profile number: 1
Mon Jun 27 20:04:46 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:04:49 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:04:52 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:04:56 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:04:59 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:02 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:05 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:08 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:11 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:14 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:17 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:20 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:24 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:27 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:30 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:33 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:36 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:39 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:42 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:45 2022 daemon.notice netifd: 4G (13073): searching on 26203
Mon Jun 27 20:05:46 2022 daemon.notice netifd: 4G (13073): Unable to register to ▒4▒▒~▒▒e7 on LTE
Mon Jun 27 20:05:46 2022 daemon.notice netifd: 4G (13073): Check subscription or APN settings
Mon Jun 27 20:05:46 2022 daemon.notice netifd: 4G (13322): Stopping network 4G
Mon Jun 27 20:05:46 2022 daemon.notice netifd: 4G (13322): Command failed: Permission denied
Mon Jun 27 20:05:46 2022 daemon.notice netifd: Interface '4G' is now down

and uqmi daemon

Mon Jun 27 20:04:43 2022 user.notice uqmi_d: Modem disconnected.
Mon Jun 27 20:04:43 2022 user.notice uqmi_d: Unable to re-connect. Interface restarted.

i tried to do a ifup in crontab but it seems that my isp is not reseting for exactly 24h, sometimes it happens earlier and sometimes later, so its not helping much.
Maybe someone can help me here, im out of ideas.

Hi
Can you paste syslog with the setup of your LTE modem after a power reset?
Can you paste your LTE configuaration, uci show network.4G?

thank you mrhaav for quick response.

my LTE config looks like this

root@OpenWrt:~# uci show network.4G
network.4G=interface
network.4G.proto='qmi'
network.4G.device='/dev/cdc-wdm0'
network.4G.apn='netpublic'
network.4G.pdptype='ipv4'
network.4G.default_profile='1'
network.4G.auth='none'
network.4G.pincode='7437'

for a Power reset i have to go to the remote location where the Router is, i need a few hours to do that.
I manage the Router with Wireguard from my home or workplace. I post you the syslog asap.

Last night the reset happen again and for some mysterious reason that time it could reconnect after a few seconds.

Wed Jun 29 00:44:59 2022 daemon.notice netifd: Interface '4G' has lost the connection
Wed Jun 29 00:45:00 2022 daemon.notice netifd: 4G (24337): Stopping network 4G
Wed Jun 29 00:45:01 2022 daemon.notice netifd: 4G (24337): Command failed: Permission denied
Wed Jun 29 00:45:01 2022 daemon.notice netifd: Interface '4G' is now down
Wed Jun 29 00:45:01 2022 daemon.notice netifd: Interface '4G' is setting up now
Wed Jun 29 00:45:02 2022 daemon.notice netifd: 4G (24477): PINcode disabled
Wed Jun 29 00:45:02 2022 daemon.notice netifd: 4G (24477): Data format set to raw-ip
Wed Jun 29 00:45:02 2022 daemon.notice netifd: 4G (24477): Default profile number: 1
Wed Jun 29 00:45:03 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:06 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:09 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:12 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:15 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:18 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:21 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:25 2022 daemon.notice netifd: 4G (24477):  searching on 26203
Wed Jun 29 00:45:28 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:31 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:34 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:37 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:40 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:43 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:46 2022 daemon.notice netifd: 4G (24477):  searching on 26202
Wed Jun 29 00:45:49 2022 daemon.notice netifd: 4G (24477):  registered on 26203
Wed Jun 29 00:45:49 2022 daemon.notice netifd: 4G (24477): Registered to Willkommen on LTE
Wed Jun 29 00:45:51 2022 daemon.notice netifd: 4G (24477): Default profile connected with ipv4
Wed Jun 29 00:45:51 2022 daemon.notice netifd: 4G (24477): Setting up wwan0

Your configuration looks OK.
But, how is the LTE coverage?
There is a limit in the qmi-script after 1min of search for network. The script will check for registration every 3rd second, 20 times. If the registration is unsuccessful the script will exit.
That happened at 27/6 20:05.

The reception is good, i tested it with a Phone and it was around 80% Signal strength. The Antenna from the Router is mounted outside the house, there are 2 celltowers in ~1,5km Range.

MR6400 Signal

root@OpenWrt:~# ./status.sh
{
        "type": "lte",
        "rssi": -37,
        "rsrq": -13,
        "rsrp": -67,
        "snr": 1.600000

i was able to do a syslog and a power reset

Tue Jun 28 05:23:47 2022 kern.info kernel: [   14.333626] qmi_wwan 1-1:1.4: cdc-wdm0: USB WDM device
Tue Jun 28 05:23:47 2022 kern.info kernel: [   14.406336] qmi_wwan 1-1:1.4 wwan0: register 'qmi_wwan' at usb-101c0000.ehci-1, WWAN/QMI device, d6:14:be:61:ce:eb
Tue Jun 28 05:23:47 2022 kern.info kernel: [   14.417220] usbcore: registered new interface driver qmi_wwan
Tue Jun 28 05:24:02 2022 daemon.notice netifd: Interface '4G' is setting up now
Tue Jun 28 05:24:04 2022 daemon.notice netifd: 4G (1848): PINcode disabled
Tue Jun 28 05:24:04 2022 daemon.notice netifd: 4G (1848): Data format set to raw-ip
Tue Jun 28 05:24:05 2022 daemon.notice netifd: 4G (1848): Default profile number: 1
Tue Jun 28 05:24:05 2022 daemon.notice netifd: 4G (1848): Airplane mode off
Tue Jun 28 05:24:07 2022 daemon.notice netifd: 4G (1848):  registered on 26203
Tue Jun 28 05:24:10 2022 daemon.notice netifd: 4G (1848): Registered to Willkommen on LTE
Tue Jun 28 05:24:11 2022 daemon.notice netifd: 4G (1848): Default profile connected with ipv4
Tue Jun 28 05:24:11 2022 daemon.notice netifd: 4G (1848): Setting up wwan0
Tue Jun 28 05:24:11 2022 daemon.notice netifd: Interface '4G' is now up
Tue Jun 28 05:24:11 2022 daemon.notice netifd: Network device 'wwan0' link is up

i tried to pick all up whats related to the modem. I dont know why the time and date are incorrect, it changes at the end of the log to the right ones.

As i understand the modem is searching for a network and does not found one after the reset.
But if i do a ifup after the failed registration it just connects in 1 try, like this

Wed Jun 29 17:52:55 2022 daemon.notice netifd: 4G (6081): Stopping network 4G
Wed Jun 29 17:52:56 2022 daemon.notice netifd: 4G (6081): Command failed: Permission denied
Wed Jun 29 17:52:56 2022 daemon.notice netifd: Interface '4G' is now down
Wed Jun 29 17:52:56 2022 daemon.notice netifd: Interface '4G' is setting up now
Wed Jun 29 17:52:57 2022 daemon.notice netifd: 4G (6211): PINcode disabled
Wed Jun 29 17:52:57 2022 daemon.notice netifd: 4G (6211): Data format set to raw-ip
Wed Jun 29 17:52:57 2022 daemon.notice netifd: 4G (6211): Default profile number: 1
Wed Jun 29 17:52:58 2022 daemon.notice netifd: 4G (6211):  registered on 26203
Wed Jun 29 17:52:58 2022 daemon.notice netifd: 4G (6211): Registered to Willkommen on LTE
Wed Jun 29 17:52:59 2022 daemon.notice netifd: 4G (6211): Default profile connected with ipv4
Wed Jun 29 17:52:59 2022 daemon.notice netifd: 4G (6211): Setting up wwan0
Wed Jun 29 17:52:59 2022 daemon.notice netifd: Interface '4G' is now up
Wed Jun 29 17:52:59 2022 user.notice firewall: Reloading firewall due to ifup of 4G (wwan0)
Wed Jun 29 17:53:01 2022 user.notice firewall: Reloading firewall due to ifupdate of 4G (wwan0)

maybe it needs a few seconds waiting time ?

Maybe the reception is too good :wink:
Both your syslogs looks OK. When the daemon can´t re-connect the session it will send ifup.

Are you running any other scripts with uqmi commands?

Not that i know of, i had qmi-utils installed for a while until i removed it because i noticed here somewhere it is not needed with uqmi.

And your right, my snr rating does not really fit to the other readings. When i run speedtest-cli i get ~10mbit down and ~10mbit uplink speed with that values. Sometimes the snr is in negative range and i still have a connection.

I mean scripts like your status.sh.
The LTE modem in the TP-Link router can not handle parallel uqmi commands in a good way.

Thats the only one and its not scheduled, i made it for quick get signal strength. Its just that one command.

I have no good ideas.
Can you try to use the original antennas to the router?
Is the uqmi daemon always failing to re-connect? Can you paste all info from syslog regarding uqmi_d?

I will try the original Antennas when i am there next time.

For the last 2 times the ISP reset reconnect did work, it is not allways failing. :smiley:
It took 47s the last time today to reach the network.

Thu Jun 30 16:22:01 2022 daemon.notice netifd: Interface '4G' has lost the connection
Thu Jun 30 16:22:02 2022 daemon.notice netifd: 4G (19173): Stopping network 4G
Thu Jun 30 16:22:03 2022 daemon.notice netifd: 4G (19173): Command failed: Permission denied
Thu Jun 30 16:22:03 2022 daemon.notice netifd: Interface '4G' is now down
Thu Jun 30 16:22:03 2022 daemon.notice netifd: Interface '4G' is setting up now
Thu Jun 30 16:22:04 2022 daemon.notice netifd: 4G (19311): PINcode disabled
Thu Jun 30 16:22:04 2022 daemon.notice netifd: 4G (19311): Data format set to raw-ip
Thu Jun 30 16:22:04 2022 daemon.notice netifd: 4G (19311): Default profile number: 1
Thu Jun 30 16:22:05 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:08 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:11 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:14 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:17 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:20 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:24 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:27 2022 daemon.notice netifd: 4G (19311):  searching on 26203
Thu Jun 30 16:22:30 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:33 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:36 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:39 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:42 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:45 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:49 2022 daemon.notice netifd: 4G (19311):  searching on 26202
Thu Jun 30 16:22:52 2022 daemon.notice netifd: 4G (19311):  registered on 26203
Thu Jun 30 16:22:52 2022 daemon.notice netifd: 4G (19311): Registered to Willkommen on LTE
Thu Jun 30 16:22:53 2022 daemon.notice netifd: 4G (19311): Default profile connected with ipv4
Thu Jun 30 16:22:53 2022 daemon.notice netifd: 4G (19311): Setting up wwan0

uqmi_d did restart the interface, the restart at 03:00 is scheduled by a cronjob.

root@OpenWrt:~# logread -e uqmi_d
Tue Jun 28 05:24:13 2022 user.notice uqmi_d: Daemon started
Wed Jun 29 17:52:55 2022 user.notice uqmi_d: Daemon stopped, interface down
Wed Jun 29 17:53:00 2022 user.notice uqmi_d: Daemon started
Thu Jun 30 03:00:01 2022 user.notice uqmi_d: Daemon stopped, interface down
Thu Jun 30 03:00:06 2022 user.notice uqmi_d: Daemon started
Thu Jun 30 16:22:01 2022 user.notice uqmi_d: IPv4 disconnected
Thu Jun 30 16:22:02 2022 user.notice uqmi_d: Unable to re-connect IPv4 -  Interface restarted
Thu Jun 30 16:22:54 2022 user.notice uqmi_d: Daemon started

There is a QMI Parameter which can delay the interaction with the modem, is there any possiblity that i can add this in your script on my setup? Maybe the reset from my ISP in my region needs a little time to let the client reconnect, i dont know.

It should not be needed to reset the interface, just re-connect the session.
Can you add one thing in the uqmi daemon script, /usr/bin/uqmi_d.sh?
Add "$pdh_4" so it will printed to the syslog, in the logger command

# IPv4
		if [ "$ipv4connected" = '"Out of call"' ]
		then
			uqmi -s -d $device --set-client-id wds,"$cid_4" \
				--release-client-id wds

			cid_4=$(uqmi -s -d $device --get-client-id wds)
			uqmi -s -d "$device" --set-client-id wds,"$cid_4" --set-ip-family ipv4
			pdh_4=$(uqmi -s -d $device --set-client-id wds,"$cid_4" \
				--start-network \
				--profile $default_profile)
			if ! [ "$pdh_4" -eq "$pdh_4" ] 2> /dev/null
			then
				logger -t uqmi_d 'Unable to re-connect IPv4 - Interface restarted '$pdh_4 
				ifup $interface
				/etc/init.d/uqmi_d stop
			else
				logger -t uqmi_d IPv4 re-connected
			fi
		fi

Ok, i added it. Btw, thanks for your patience with me.

No problem.
I forgot to mention, you need to restart your interface. Make sure that the daemon is started as well.

I did that and both are running fine. I´ll post the syslog for the next reset when it happens.

1 Like

after reset it did again reconnect , but it took almost a minute.

Fri Jul  1 03:00:01 2022 user.notice uqmi_d: Daemon stopped, interface down
Fri Jul  1 03:00:06 2022 user.notice uqmi_d: Daemon started
Fri Jul  1 16:22:01 2022 user.notice uqmi_d: IPv4 disconnected
Fri Jul  1 16:22:02 2022 user.notice uqmi_d: Unable to re-connect IPv4 - Interface restarted "Call failed"
Fri Jul  1 16:23:00 2022 user.notice uqmi_d: Daemon started

and now it says "Call failed"

It looks like your LTE modem is totaly dis-connected from the network. I don't understand why your ISP would like to do that. Normally the ISP is dis-connecting your data session and then it is just to re-connect it. Not restart the interface.
Is it a coincident that it happened at 16:22 again?
Maybe a long shot, but could it be some isseu with your power supply or some electrical machine, in your house, that could interfere with your router and cause the LTE modem restart?

I think that´s when i performed the power reset last Tuesday. Then every ~24h ISP is doing that reset thing again, its the same thing for my DSL line, but i don´t notice it there.
The openwrt itself is running since Tuesday, so the power supply seems stable.
For interference i cant think of any device, there is a raspberry Pi in the basement that´s all.

I found a software package , will give this a try.

Did your DSL modem a reset at the same time as your LTE modem?
My thought was if you have any "heavy" electrical equipment like air conditioner or hot water tank that could cause some kind of power spikes when it is turned on or off.