quectel-CM SIGTERM loop

IoT Modules LTE-A Module
1

Greetings Quectel experts!

I have a recently released consumer grade router based on the Quectel EG18, running a derivative of OpenWRT Chaos Calmer, r6043. FWIW, I am using it to connect to the Verizon LTE network in the US (which was a supported network at the time I purchased the router).

Most of the time the router works GREAT, the EG18 delivering much better download and upload speeds than anything I’ve had previously. But once or sometimes twice a day, something happens on the network that seems to put the router into a strange loop of disconnecting and reconnecting about every 11 seconds or so. Restarting the router (remove and reapply power) seems to solve the issue. None of my other 3 LTE data devices (phones) seem affected by the issue. Only the router.

When this condition is occurring, quectel-CM seems to be in a loop where it connects to the Verizon network, obtains an IP address and then, mysteriously, immediately disconnects and starts the whole process over again a few seconds later. I would have thought that if things got as far as obtaining an IP address, that the connection would have been considered “good”?

If it helps, here’s a snippet of the log from quectel-CM captured during one past incident. Note the “Received SIGTERM” that occurs right after the “lease of x.x.x.x obtained, lease time 7200”.

Can someone tell me what quectel-CM is doing here? I am at a loss to understand why a SIGTERM would be sent, given that the connection was just established - at least to the point of obtaining the DHCP lease.

[01-13_04:39:20:454] Sending discover…
[01-13_04:39:20:454] Sending select for 100.125.248.86…
[01-13_04:39:20:454] Lease of 100.125.248.86 obtained, lease time 7200
[01-13_04:39:20:454] Received SIGTERM
[01-13_04:39:20:454] Unicasting a release of 100.125.248.86 to 100.125.248.85 <== Why release what we just obtained??
[01-13_04:39:20:454] Sending release…
[01-13_04:39:20:454] Entering released state
[01-13_04:39:21:619] requestSetupDataCall WdsConnectionIPv4Handle: 0xe555a900
[01-13_04:39:21:875] change mtu 1500 -> 1428
[01-13_04:39:21:875] ifconfig wwan0 up
[01-13_04:39:21:897] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[01-13_04:39:22:015] [MW] current 8914800 no need set MTU, set to mannual 1500.
ioctl: Cannot assign requested address
[01-13_04:39:29:525] Not enable arlo . Not check arlo ip.
[01-13_04:39:29:526] LAN: 192.168.1.1/255.255.255.0
[01-13_04:39:29:526] WAN: 100.99.189.128/255.255.255.0
[01-13_04:39:29:526] WAN status: Link down
[01-13_04:39:29:526] WAN status: Link down
[01-13_04:39:29:526] WAN/LAN is NOT conflicting!
[01-13_04:39:29:654] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-13_04:39:29:683] Enter bound
[01-13_04:39:29:763] adding dns 198.224.166.135
[01-13_04:39:29:776] adding dns 198.224.167.135
ioctl: Cannot assign requested address
[01-13_04:39:29:800] Not enable arlo . Not check arlo ip.
[01-13_04:39:29:800] LAN: 192.168.1.1/255.255.255.0
[01-13_04:39:29:800] WAN: 100.99.189.128/255.255.255.0
[01-13_04:39:29:800] WAN status: Link down
[01-13_04:39:29:800] WAN status: Link down
[01-13_04:39:29:801] WAN/LAN is NOT conflicting!
[01-13_04:39:29:805] ipconflict run done
[01-13_04:39:29:815] deleting routers
[01-13_04:39:29:833] adding router 100.99.189.129
[01-13_04:39:30:297] Starting Firewall…
[01-13_04:39:30:297] Done!
[01-13_04:39:30:370] $Shutting down igmpproxy:
Sorry, rule does not exist.
Sorry, rule does not exist.
[01-13_04:39:30:436]

[01-13_04:39:30:478] $Shutting down igmpproxy:
Sorry, rule does not exist.
Sorry, rule does not exist.
[01-13_04:39:30:541]

[01-13_04:39:30:582] ip change for firewall restart
[01-13_04:39:30:588] Deleting static route … Done!
killall: ripd: no process killed
[01-13_04:39:30:622] Deleting static route … Done!
[01-13_04:39:30:622] Adding static route … Done!
/usr/share/udhcpc/default.script.wwan: line 1: sb_update_database: not found
[01-13_04:39:31:434] {“result”:0}
[01-13_04:39:35:955] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[01-13_04:39:35:986] ifconfig wwan0 down
[01-13_04:39:36:000] ifconfig wwan0 0.0.0.0
[01-13_04:39:36:106] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-13_04:39:36:146] udhcp client (v0.9.8) started
[01-13_04:39:36:146] Sending discover…
[01-13_04:39:36:146] Sending select for 100.99.189.128…
[01-13_04:39:36:146] Lease of 100.99.189.128 obtained, lease time 7200 <== new connection; new IP address… Process repeats from here.
[01-13_04:39:36:146] Received SIGTERM
[01-13_04:39:36:146] Unicasting a release of 100.99.189.128 to 100.99.189.129
[01-13_04:39:36:146] Sending release…

Any ideas?

TIA for any help!

2

Please you tell me some info
quectel-CM version?
The whole quectel-CM log？

Btw，it’s not recommended to change the MTU.

3

Another quectel-CM is running ？
Or uqmi is running in background？

4

Hi Bean. Thanks for the quick reply. Had to figure out how to get the router to turn on CM logging at startup and then wait for the conditions to happen again - usually occurs 0 - 2 times daily. Anyway, here’s the additional info:

quectel-CM version reported as: Quectel_QConnectManager_Linux_V1.5.2
Only one quectel-CM instance appears to be running (though there’s always a zombie child [sh] process with it?)
Don’t know about uqmi. But nothing shows up in ‘ps wl’
I don’t know that I can (easily) do anything with the MTU. It’s a stock router firmware from a reputable router manufacturer
Entire log is about 200KB… First time using these Quectel forums for me. So not sure if I can/should paste everything. But I’m including what I hope are relevant pieces along with periods when things seem to change along with some commentary. Let me know if you’re interested in looking for anything between the “segments”…

First, the startup:
[01-30_07:53:01:948] quectel-CM profile[3] = vzwinternet///0, pincode = (null)
[01-30_07:53:01:949] Find /sys/bus/usb/devices/2-1 idVendor=0x2c7c idProduct=0x512
[01-30_07:53:01:950] Auto find qmichannel = /dev/cdc-wdm0
[01-30_07:53:01:951] Auto find usbnet_adapter = wwan0
[01-30_07:53:01:951] qmap_mode = 1, muxid = 0x81, qmap_netcard = wwan0
[01-30_07:53:01:952] Modem works in QMI mode
[01-30_07:53:01:953] qmap_mode = 1, muxid = 0x81, qmap_netcard = wwan0
[01-30_07:53:02:041] cdc_wdm_fd = 8
[01-30_07:53:02:206] Get clientWDS = 19
[01-30_07:53:02:270] Get clientDMS = 1
[01-30_07:53:02:334] Get clientNAS = 5
[01-30_07:53:02:398] Get clientUIM = 3
[01-30_07:53:02:462] Get clientWDA = 1
[01-30_07:53:02:526] requestBaseBandVersion EG18NAPAR01A05M4G
[01-30_07:53:02:590] qmap_settings.rx_urb_size = 16384
[01-30_07:53:02:846] requestGetSIMStatus SIMStatus: SIM_READY
[01-30_07:53:02:846] requestSetProfile[3] vzwinternet///0
[01-30_07:53:02:974] requestGetProfile[3] vzwinternet///0
[01-30_07:53:03:038] requestRegistrationState2 MCC: 311, MNC: 480, PS: Attached, DataCap: LTE
[01-30_07:53:03:102] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[01-30_07:53:03:132] ifconfig wwan0 down
[01-30_07:53:03:143] ifconfig wwan0 0.0.0.0
[01-30_07:53:03:678] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[01-30_07:53:03:934] change mtu 1500 -> 1428
[01-30_07:53:03:934] ifconfig wwan0 up
[01-30_07:53:03:960] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[01-30_07:53:04:089] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-30_07:53:11:613] Not enable arlo . Not check arlo ip.
[01-30_07:53:11:613] LAN: 192.168.1.1/255.255.255.0
[01-30_07:53:11:613] WAN: 100.90.107.245/255.255.255.252
[01-30_07:53:11:613] WAN status: Link down
[01-30_07:53:11:613] WAN status: Link down
[01-30_07:53:11:614] WAN/LAN is NOT conflicting!
[01-30_07:53:11:725] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-30_07:53:11:750] Enter bound
[01-30_07:53:11:811] adding dns 198.224.166.135
[01-30_07:53:11:833] adding dns 198.224.167.135
[01-30_07:53:11:855] Not enable arlo . Not check arlo ip.
[01-30_07:53:11:855] LAN: 192.168.1.1/255.255.255.0
[01-30_07:53:11:856] WAN: 100.90.107.245/255.255.255.0
[01-30_07:53:11:856] WAN status: Link down
[01-30_07:53:11:856] WAN status: Link down
[01-30_07:53:11:856] WAN/LAN is NOT conflicting!
[01-30_07:53:11:860] ipconflict run done
[01-30_07:53:11:870] deleting routers
[01-30_07:53:11:879] adding router 100.90.107.246
[01-30_07:53:12:423] Starting Firewall…
[01-30_07:53:12:423] Done!
[01-30_07:53:12:535] $Shutting down igmpproxy:
[01-30_07:53:12:599]

[01-30_07:53:12:642] $Shutting down igmpproxy:
[01-30_07:53:12:705]

[01-30_07:53:12:744] ip change for firewall restart
[01-30_07:53:12:750] Deleting static route … Done!
[01-30_07:53:12:783] Deleting static route … Done!
[01-30_07:53:12:783] Adding static route … Done!
[01-30_07:53:14:052] {“result”:0}

Every so often after startup, there would be these very short periods of “Link down” status. These don’t materially impact overall perception of network availability though:

[01-30_09:38:11:923] Not enable arlo . Not check arlo ip.
[01-30_09:38:11:923] LAN: 192.168.1.1/255.255.255.0
[01-30_09:38:11:924] WAN: 100.90.107.245/255.255.255.252
[01-30_09:38:11:924] WAN status: Link down
[01-30_09:38:11:924] WAN status: Link down
[01-30_09:38:11:924] WAN/LAN is NOT conflicting!
[01-30_09:38:12:052] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-30_09:38:12:077] Enter renew
[01-30_09:38:12:138] adding dns 198.224.166.135
[01-30_09:38:12:150] adding dns 198.224.167.135
[01-30_09:38:12:169] Not enable arlo . Not check arlo ip.
[01-30_09:38:12:169] LAN: 192.168.1.1/255.255.255.0
[01-30_09:38:12:169] WAN: 100.90.107.245/255.255.255.0
[01-30_09:38:12:169] WAN status: Link down
[01-30_09:38:12:169] WAN status: Link down
[01-30_09:38:12:170] WAN/LAN is NOT conflicting!
[01-30_09:38:12:173] ipconflict run done
[01-30_09:38:12:182] deleting routers
[01-30_09:38:12:199] adding router 100.90.107.246
[01-30_09:38:12:347] Deleting static route … Done!
[01-30_09:38:12:381] Deleting static route … Done!
[01-30_09:38:12:381] Adding static route … Done!
[01-30_09:38:13:379] {“result”:0}

After a while, I get a rapid-fire string of these events, which start with launching udhcp client:

[01-31_10:08:05:705] udhcp client (v0.9.8) started
[01-31_10:08:05:705] Sending discover…
[01-31_10:08:05:705] Sending select for 100.90.107.245…
[01-31_10:08:05:705] Lease of 100.90.107.245 obtained, lease time 7200
[01-31_10:08:05:705] Sending renew…
[01-31_10:08:05:705] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:706] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Lease of 100.90.107.245 obtained, lease time 7200
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:707] Sending renew…
[01-31_10:08:05:708] Sending renew…
[01-31_10:08:05:708] Sending renew…
[01-31_10:08:05:708] Sending renew…
[01-31_10:08:05:708] Sending renew…
[01-31_10:08:05:708] Sending renew…
[01-31_10:08:05:708] Sending renew…
[01-31_10:08:05:708] Sending renew…

More of the previous “Not enabled arlo” groups. Then a few of these:

[01-31_15:08:14:400] requestRegistrationState2 MCC: 311, MNC: 480, PS: Attached, DataCap: LTE
[01-31_15:08:29:761] requestRegistrationState2 MCC: 311, MNC: 480, PS: Attached, DataCap: LTE
[01-31_15:08:45:024] requestRegistrationState2 MCC: 311, MNC: 480, PS: Attached, DataCap: LTE

A few more occurrences of the first two sequences… THEN it gets interesting, starting here:

[02-01_15:21:31:233] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:21:31:272] ifconfig wwan0 down
[02-01_15:21:31:309] ifconfig wwan0 0.0.0.0
[02-01_15:21:31:392] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:31:431]

[02-01_15:21:31:431] Sending renew…
[02-01_15:21:31:432] Lease of 100.90.107.245 obtained, lease time 7200
[02-01_15:21:31:432] Sending renew…
[02-01_15:21:31:432] Sending renew…
[02-01_15:21:31:432] Sending renew…
[02-01_15:21:31:432] Sending renew…
[02-01_15:21:31:432] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:433] Sending renew…
[02-01_15:21:31:434] Sending renew…
[02-01_15:21:31:434] Lease of 100.90.107.245 obtained, lease time 7200
[02-01_15:21:31:434] Sending renew…
[02-01_15:21:31:434] Received SIGTERM

This appears to be the point at which we lose the LTE connection (see requestQueryDataCall return status). BUT we are almost a millisecond later trying to renew the IP address lease?? How can that be?

This ends with the “Received SIGTERM” - from where I don’t know. But I’m guessing something in the CM didn’t like the situation and decided it was time to give up and start over. Now we have entered what I could best discern is some kind of fight between trying to get an IP address and establishing/re-establishing the LTE connection. This is where WAN connectivity is DOWN. We can stay in this state anywhere from minutes to hours if left unattended:

[02-01_15:21:31:434] Unicasting a release of 100.90.107.245 to 100.90.107.246
[02-01_15:21:31:434] Sending release…
[02-01_15:21:31:435] Entering released state
[02-01_15:21:32:609] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:21:32:865] change mtu 1500 -> 1428
[02-01_15:21:32:866] ifconfig wwan0 up
[02-01_15:21:32:899] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:21:33:078] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:40:535] Not enable arlo . Not check arlo ip.
[02-01_15:21:40:535] LAN: 192.168.1.1/255.255.255.0
[02-01_15:21:40:535] WAN: 100.115.84.56/255.255.255.240
[02-01_15:21:40:535] WAN status: Link down
[02-01_15:21:40:536] WAN status: Link down
[02-01_15:21:40:536] WAN/LAN is NOT conflicting!
[02-01_15:21:40:673] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:40:699] Enter bound
[02-01_15:21:40:772] adding dns 198.224.166.135
[02-01_15:21:40:785] adding dns 198.224.167.135
[02-01_15:21:40:809] Not enable arlo . Not check arlo ip.
[02-01_15:21:40:810] LAN: 192.168.1.1/255.255.255.0
[02-01_15:21:40:810] WAN: 100.115.84.56/255.255.255.0
[02-01_15:21:40:810] WAN status: Link down
[02-01_15:21:40:810] WAN status: Link down
[02-01_15:21:40:810] WAN/LAN is NOT conflicting!
[02-01_15:21:40:815] ipconflict run done
[02-01_15:21:40:826] deleting routers
[02-01_15:21:40:834] adding router 100.115.84.57
[02-01_15:21:41:518] Starting Firewall…
[02-01_15:21:41:518] Done!
[02-01_15:21:41:569] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:21:41:609] ifconfig wwan0 down
[02-01_15:21:41:622] ifconfig wwan0 0.0.0.0
[02-01_15:21:41:632] $Shutting down igmpproxy:
[02-01_15:21:41:699]

[02-01_15:21:41:740] $Shutting down igmpproxy:
[02-01_15:21:41:803]

[02-01_15:21:41:843] ip change for firewall restart
[02-01_15:21:41:849] Deleting static route … Done!
[02-01_15:21:41:884] Deleting static route … Done!
[02-01_15:21:41:884] Adding static route … Done!
[02-01_15:21:41:918] {“result”:-7}
[02-01_15:21:42:101] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:42:134] udhcp client (v0.9.8) started
[02-01_15:21:42:134] Sending discover…
[02-01_15:21:42:134] Sending select for 100.115.84.56…
[02-01_15:21:42:134] Lease of 100.115.84.56 obtained, lease time 7200
[02-01_15:21:42:134] Received SIGTERM
[02-01_15:21:42:134] Unicasting a release of 100.115.84.56 to 100.115.84.57
[02-01_15:21:42:134] Sending release…
[02-01_15:21:42:135] Entering released state
[02-01_15:21:42:945] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:21:43:201] change mtu 1500 -> 1428
[02-01_15:21:43:202] ifconfig wwan0 up
[02-01_15:21:43:223] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:21:43:339] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:50:791] Not enable arlo . Not check arlo ip.
[02-01_15:21:50:791] LAN: 192.168.1.1/255.255.255.0
[02-01_15:21:50:791] WAN: 100.119.30.213/255.255.255.252
[02-01_15:21:50:791] WAN status: Link down
[02-01_15:21:50:792] WAN status: Link down
[02-01_15:21:50:792] WAN/LAN is NOT conflicting!
[02-01_15:21:50:902] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:50:929] Enter bound
[02-01_15:21:51:019] adding dns 198.224.166.135
[02-01_15:21:51:034] adding dns 198.224.167.135
[02-01_15:21:51:059] Not enable arlo . Not check arlo ip.
[02-01_15:21:51:059] LAN: 192.168.1.1/255.255.255.0
[02-01_15:21:51:059] WAN: 100.119.30.213/255.255.255.0
[02-01_15:21:51:059] WAN status: Link down
[02-01_15:21:51:059] WAN status: Link down
[02-01_15:21:51:060] WAN/LAN is NOT conflicting!
[02-01_15:21:51:063] ipconflict run done
[02-01_15:21:51:073] deleting routers
[02-01_15:21:51:082] adding router 100.119.30.214
[02-01_15:21:51:590] Starting Firewall…
[02-01_15:21:51:590] Done!
[02-01_15:21:51:656] $Shutting down igmpproxy:
[02-01_15:21:51:723]

[02-01_15:21:51:765] $Shutting down igmpproxy:
[02-01_15:21:51:831]

[02-01_15:21:51:874] ip change for firewall restart
[02-01_15:21:51:880] Deleting static route … Done!
[02-01_15:21:51:914] Deleting static route … Done!
[02-01_15:21:51:914] Adding static route … Done!
[02-01_15:21:52:545] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:21:52:576] ifconfig wwan0 down
[02-01_15:21:52:594] ifconfig wwan0 0.0.0.0
[02-01_15:21:52:704] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:21:52:739] udhcp client (v0.9.8) started
[02-01_15:21:52:739] Sending discover…
[02-01_15:21:52:739] Sending select for 100.119.30.213…
[02-01_15:21:52:739] Lease of 100.119.30.213 obtained, lease time 7200
[02-01_15:21:52:740] Received SIGTERM
[02-01_15:21:52:740] Unicasting a release of 100.119.30.213 to 100.119.30.214
[02-01_15:21:52:740] Sending release…
[02-01_15:21:52:740] Entering released state
[02-01_15:21:53:953] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:21:54:209] change mtu 1500 -> 1428
[02-01_15:21:54:210] ifconfig wwan0 up
[02-01_15:21:54:244] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:21:54:384] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:01:941] Not enable arlo . Not check arlo ip.
[02-01_15:22:01:941] LAN: 192.168.1.1/255.255.255.0
[02-01_15:22:01:941] WAN: 100.74.183.85/255.255.255.252
[02-01_15:22:01:941] WAN status: Link down
[02-01_15:22:01:941] WAN status: Link down
[02-01_15:22:01:941] WAN/LAN is NOT conflicting!
[02-01_15:22:02:051] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:02:075] Enter bound
[02-01_15:22:02:142] adding dns 198.224.166.135
[02-01_15:22:02:154] adding dns 198.224.167.135
[02-01_15:22:02:173] Not enable arlo . Not check arlo ip.
[02-01_15:22:02:173] LAN: 192.168.1.1/255.255.255.0
[02-01_15:22:02:173] WAN: 100.74.183.85/255.255.255.0
[02-01_15:22:02:173] WAN status: Link down
[02-01_15:22:02:173] WAN status: Link down
[02-01_15:22:02:174] WAN/LAN is NOT conflicting!
[02-01_15:22:02:177] ipconflict run done
[02-01_15:22:02:186] deleting routers
[02-01_15:22:02:193] adding router 100.74.183.86
[02-01_15:22:02:636] Starting Firewall…
[02-01_15:22:02:636] Done!
[02-01_15:22:02:697] $Shutting down igmpproxy:
[02-01_15:22:02:761]

[02-01_15:22:02:804] $Shutting down igmpproxy:
[02-01_15:22:02:883]

[02-01_15:22:02:934] ip change for firewall restart
[02-01_15:22:02:940] Deleting static route … Done!
[02-01_15:22:02:986] Deleting static route … Done!
[02-01_15:22:02:986] Adding static route … Done!
[02-01_15:22:03:393] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:22:03:423] ifconfig wwan0 down
[02-01_15:22:03:440] ifconfig wwan0 0.0.0.0
[02-01_15:22:03:535] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:03:570] udhcp client (v0.9.8) started
[02-01_15:22:03:570] Sending discover…
[02-01_15:22:03:570] Sending select for 100.74.183.85…
[02-01_15:22:03:570] Lease of 100.74.183.85 obtained, lease time 7200
[02-01_15:22:03:571] Received SIGTERM
[02-01_15:22:03:571] Unicasting a release of 100.74.183.85 to 100.74.183.86
[02-01_15:22:03:571] Sending release…
[02-01_15:22:03:571] Entering released state
[02-01_15:22:04:705] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:22:04:961] change mtu 1500 -> 1428
[02-01_15:22:04:962] ifconfig wwan0 up
[02-01_15:22:04:984] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:22:05:107] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:12:581] Not enable arlo . Not check arlo ip.
[02-01_15:22:12:581] LAN: 192.168.1.1/255.255.255.0
[02-01_15:22:12:581] WAN: 100.110.146.220/255.255.255.248
[02-01_15:22:12:582] WAN status: Link down
[02-01_15:22:12:582] WAN status: Link down
[02-01_15:22:12:582] WAN/LAN is NOT conflicting!
[02-01_15:22:12:691] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:12:715] Enter bound
[02-01_15:22:12:780] adding dns 198.224.166.135
[02-01_15:22:12:792] adding dns 198.224.167.135
[02-01_15:22:12:811] Not enable arlo . Not check arlo ip.
[02-01_15:22:12:811] LAN: 192.168.1.1/255.255.255.0
[02-01_15:22:12:811] WAN: 100.110.146.220/255.255.255.0
[02-01_15:22:12:811] WAN status: Link down
[02-01_15:22:12:811] WAN status: Link down
[02-01_15:22:12:812] WAN/LAN is NOT conflicting!
[02-01_15:22:12:815] ipconflict run done
[02-01_15:22:12:824] deleting routers
[02-01_15:22:12:832] adding router 100.110.146.221
[02-01_15:22:13:332] Starting Firewall…
[02-01_15:22:13:332] Done!
[02-01_15:22:13:390] $Shutting down igmpproxy:
[02-01_15:22:13:457]

[02-01_15:22:13:502] $Shutting down igmpproxy:
[02-01_15:22:13:568]

[02-01_15:22:13:609] ip change for firewall restart
[02-01_15:22:13:615] Deleting static route … Done!
[02-01_15:22:13:650] Deleting static route … Done!
[02-01_15:22:13:651] Adding static route … Done!
[02-01_15:22:15:937] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:22:15:970] ifconfig wwan0 down
[02-01_15:22:15:986] ifconfig wwan0 0.0.0.0
[02-01_15:22:16:082] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:16:115] udhcp client (v0.9.8) started
[02-01_15:22:16:115] Sending discover…
[02-01_15:22:16:116] Sending select for 100.110.146.220…
[02-01_15:22:16:116] Lease of 100.110.146.220 obtained, lease time 7200
[02-01_15:22:16:116] Received SIGTERM
[02-01_15:22:16:116] Unicasting a release of 100.110.146.220 to 100.110.146.221
[02-01_15:22:16:116] Sending release…
[02-01_15:22:16:116] Entering released state
[02-01_15:22:17:345] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:22:17:601] change mtu 1500 -> 1428
[02-01_15:22:17:602] ifconfig wwan0 up
[02-01_15:22:17:624] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:22:17:742] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:25:181] Not enable arlo . Not check arlo ip.
[02-01_15:22:25:181] LAN: 192.168.1.1/255.255.255.0
[02-01_15:22:25:181] WAN: 100.110.18.86/255.255.255.252
[02-01_15:22:25:181] WAN status: Link down
[02-01_15:22:25:181] WAN status: Link down
[02-01_15:22:25:181] WAN/LAN is NOT conflicting!
[02-01_15:22:25:290] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:25:314] Enter bound
[02-01_15:22:25:380] adding dns 198.224.166.135
[02-01_15:22:25:392] adding dns 198.224.167.135
[02-01_15:22:25:411] Not enable arlo . Not check arlo ip.
[02-01_15:22:25:411] LAN: 192.168.1.1/255.255.255.0
[02-01_15:22:25:411] WAN: 100.110.18.86/255.255.255.0
[02-01_15:22:25:411] WAN status: Link down
[02-01_15:22:25:411] WAN status: Link down
[02-01_15:22:25:411] WAN/LAN is NOT conflicting!
[02-01_15:22:25:414] ipconflict run done
[02-01_15:22:25:423] deleting routers
[02-01_15:22:25:431] adding router 100.110.18.85
[02-01_15:22:25:915] Starting Firewall…
[02-01_15:22:25:916] Done!
[02-01_15:22:25:975] $Shutting down igmpproxy:
[02-01_15:22:26:040]

[02-01_15:22:26:085] $Shutting down igmpproxy:
[02-01_15:22:26:151]

[02-01_15:22:26:194] ip change for firewall restart
[02-01_15:22:26:200] Deleting static route … Done!
[02-01_15:22:26:234] Deleting static route … Done!
[02-01_15:22:26:234] Adding static route … Done!
[02-01_15:22:27:617] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:22:27:649] ifconfig wwan0 down
[02-01_15:22:27:669] ifconfig wwan0 0.0.0.0
[02-01_15:22:27:763] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:22:27:796] udhcp client (v0.9.8) started
[02-01_15:22:27:797] Sending discover…
[02-01_15:22:27:797] Sending select for 100.110.18.86…
[02-01_15:22:27:797] Lease of 100.110.18.86 obtained, lease time 7200
[02-01_15:22:27:797] Received SIGTERM
…

Eventually, things get into this state where it seems the tower may be telling me to go away for a while and don’t come back. Note the backoff algorithm here - 5, 10, 20, 40, 60, 60, 60, … seconds - I assume as not to spam the tower and risk getting blacklisted or something?

[02-01_15:36:21:377] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:36:21:407] ifconfig wwan0 down
[02-01_15:36:21:425] ifconfig wwan0 0.0.0.0
[02-01_15:36:21:524] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:36:21:562] udhcp client (v0.9.8) started
[02-01_15:36:21:562] Sending discover…
[02-01_15:36:21:562] Sending select for 100.92.128.109…
[02-01_15:36:21:562] Lease of 100.92.128.109 obtained, lease time 7200
[02-01_15:36:21:562] Received SIGTERM
[02-01_15:36:21:562] Unicasting a release of 100.92.128.109 to 100.92.128.110
[02-01_15:36:21:563] Sending release…
[02-01_15:36:21:563] Entering released state
[02-01_15:36:22:465] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:36:22:466] call_end_reason is 1
[02-01_15:36:22:466] call_end_reason_type is 2
[02-01_15:36:22:466] call_end_reason_verbose is 209
[02-01_15:36:22:466] try to requestSetupDataCall 5 second later
[02-01_15:36:27:489] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:36:27:489] call_end_reason is 1
[02-01_15:36:27:490] call_end_reason_type is 2
[02-01_15:36:27:490] call_end_reason_verbose is 209
[02-01_15:36:27:490] try to requestSetupDataCall 10 second later
[02-01_15:36:37:505] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:36:37:505] call_end_reason is 1
[02-01_15:36:37:506] call_end_reason_type is 2
[02-01_15:36:37:506] call_end_reason_verbose is 209
[02-01_15:36:37:506] try to requestSetupDataCall 20 second later
[02-01_15:36:57:569] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:36:57:569] call_end_reason is 1
[02-01_15:36:57:570] call_end_reason_type is 2
[02-01_15:36:57:570] call_end_reason_verbose is 209
[02-01_15:36:57:570] try to requestSetupDataCall 40 second later
[02-01_15:37:37:665] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:37:37:666] call_end_reason is 1
[02-01_15:37:37:666] call_end_reason_type is 2
[02-01_15:37:37:666] call_end_reason_verbose is 209
[02-01_15:37:37:666] try to requestSetupDataCall 60 second later
[02-01_15:38:37:793] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:38:37:793] call_end_reason is 1
[02-01_15:38:37:794] call_end_reason_type is 2
[02-01_15:38:37:794] call_end_reason_verbose is 209
[02-01_15:38:37:794] try to requestSetupDataCall 60 second later
[02-01_15:39:37:921] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:39:37:921] call_end_reason is 1
[02-01_15:39:37:922] call_end_reason_type is 2
[02-01_15:39:37:922] call_end_reason_verbose is 209
[02-01_15:39:37:922] try to requestSetupDataCall 60 second later
[02-01_15:40:38:049] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:40:38:049] call_end_reason is 1
[02-01_15:40:38:050] call_end_reason_type is 2
[02-01_15:40:38:050] call_end_reason_verbose is 209
[02-01_15:40:38:050] try to requestSetupDataCall 60 second later
[02-01_15:41:38:177] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:41:38:177] call_end_reason is 1
[02-01_15:41:38:178] call_end_reason_type is 2
[02-01_15:41:38:178] call_end_reason_verbose is 209
[02-01_15:41:38:178] try to requestSetupDataCall 60 second later
[02-01_15:42:38:305] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:42:38:305] call_end_reason is 1
[02-01_15:42:38:306] call_end_reason_type is 2
[02-01_15:42:38:306] call_end_reason_verbose is 209
[02-01_15:42:38:306] try to requestSetupDataCall 60 second later
[02-01_15:43:38:466] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:43:38:466] call_end_reason is 1
[02-01_15:43:38:466] call_end_reason_type is 2
[02-01_15:43:38:466] call_end_reason_verbose is 209
[02-01_15:43:38:466] try to requestSetupDataCall 60 second later
[02-01_15:44:38:593] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:44:38:594] call_end_reason is 1
[02-01_15:44:38:594] call_end_reason_type is 2
[02-01_15:44:38:594] call_end_reason_verbose is 209
[02-01_15:44:38:594] try to requestSetupDataCall 60 second later
[02-01_15:45:38:722] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:45:38:722] call_end_reason is 1
[02-01_15:45:38:722] call_end_reason_type is 2
[02-01_15:45:38:722] call_end_reason_verbose is 209
[02-01_15:45:38:722] try to requestSetupDataCall 60 second later
[02-01_15:46:38:881] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:46:38:881] call_end_reason is 1
[02-01_15:46:38:882] call_end_reason_type is 2
[02-01_15:46:38:882] call_end_reason_verbose is 209
[02-01_15:46:38:882] try to requestSetupDataCall 60 second later
[02-01_15:47:39:009] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:47:39:010] call_end_reason is 1
[02-01_15:47:39:010] call_end_reason_type is 2
[02-01_15:47:39:010] call_end_reason_verbose is 209
[02-01_15:47:39:010] try to requestSetupDataCall 60 second later
[02-01_15:48:39:137] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:48:39:138] call_end_reason is 1
[02-01_15:48:39:138] call_end_reason_type is 2
[02-01_15:48:39:138] call_end_reason_verbose is 209
[02-01_15:48:39:138] try to requestSetupDataCall 60 second later
[02-01_15:49:39:265] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:49:39:265] call_end_reason is 1
[02-01_15:49:39:266] call_end_reason_type is 2
[02-01_15:49:39:266] call_end_reason_verbose is 209
[02-01_15:49:39:266] try to requestSetupDataCall 60 second later
[02-01_15:50:39:393] requestSetupDataCall QMUXResult = 0x1, QMUXError = 0xe
[02-01_15:50:39:394] call_end_reason is 1
[02-01_15:50:39:394] call_end_reason_type is 2
[02-01_15:50:39:394] call_end_reason_verbose is 209
[02-01_15:50:39:394] try to requestSetupDataCall 60 second later
[02-01_15:51:39:969] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0

Eventually, though, things seem to recover (or I get sick of waiting and reboot the router) - at least for a short while:

[02-01_15:51:39:969] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:51:40:225] change mtu 1500 -> 1428
[02-01_15:51:40:226] ifconfig wwan0 up
[02-01_15:51:40:249] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:51:40:374] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:51:47:902] Not enable arlo . Not check arlo ip.
[02-01_15:51:47:902] LAN: 192.168.1.1/255.255.255.0
[02-01_15:51:47:902] WAN: 100.84.52.224/255.255.255.192
[02-01_15:51:47:902] WAN status: Link down
[02-01_15:51:47:902] WAN status: Link down
[02-01_15:51:47:902] WAN/LAN is NOT conflicting!
[02-01_15:51:48:024] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:51:48:053] Enter bound
[02-01_15:51:48:124] adding dns 198.224.166.135
[02-01_15:51:48:137] adding dns 198.224.167.135
[02-01_15:51:48:155] Not enable arlo . Not check arlo ip.
[02-01_15:51:48:155] LAN: 192.168.1.1/255.255.255.0
[02-01_15:51:48:155] WAN: 100.84.52.224/255.255.255.0
[02-01_15:51:48:155] WAN status: Link down
[02-01_15:51:48:155] WAN status: Link down
[02-01_15:51:48:155] WAN/LAN is NOT conflicting!
[02-01_15:51:48:159] ipconflict run done
[02-01_15:51:48:168] deleting routers
[02-01_15:51:48:176] adding router 100.84.52.225
[02-01_15:51:48:615] Starting Firewall…
[02-01_15:51:48:615] Done!
[02-01_15:51:48:673] $Shutting down igmpproxy:
[02-01_15:51:48:736]

[02-01_15:51:48:778] $Shutting down igmpproxy:
[02-01_15:51:48:841]

[02-01_15:51:48:881] ip change for firewall restart
[02-01_15:51:48:887] Deleting static route … Done!
[02-01_15:51:48:920] Deleting static route … Done!
[02-01_15:51:48:920] Adding static route … Done!
[02-01_15:51:49:942] {“result”:0}

And then back in the tank…

[02-01_15:56:34:113] requestQueryDataCall IPv4ConnectionStatus: DISCONNECTED
[02-01_15:56:34:154] ifconfig wwan0 down
[02-01_15:56:34:180] ifconfig wwan0 0.0.0.0
[02-01_15:56:34:305] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:56:34:345] udhcp client (v0.9.8) started
[02-01_15:56:34:345] Sending discover…
[02-01_15:56:34:346] Sending select for 100.84.52.224…
[02-01_15:56:34:346] Lease of 100.84.52.224 obtained, lease time 7200
[02-01_15:56:34:346] Received SIGTERM
[02-01_15:56:34:346] Unicasting a release of 100.84.52.224 to 100.84.52.225
[02-01_15:56:34:346] Sending release…
[02-01_15:56:34:346] Entering released state
[02-01_15:56:35:521] requestSetupDataCall WdsConnectionIPv4Handle: 0x01ef5ef0
[02-01_15:56:35:778] change mtu 1500 -> 1428
[02-01_15:56:35:778] ifconfig wwan0 up
[02-01_15:56:35:801] udhcpc -b -i wwan0 -h /tmp/dhcp_name.conf -r 0.0.0.0 -N 0.0.0.0
[02-01_15:56:35:918] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:56:43:422] Not enable arlo . Not check arlo ip.
[02-01_15:56:43:422] LAN: 192.168.1.1/255.255.255.0
[02-01_15:56:43:422] WAN: 100.87.140.10/255.255.255.252
[02-01_15:56:43:422] WAN status: Link down
[02-01_15:56:43:423] WAN status: Link down
[02-01_15:56:43:423] WAN/LAN is NOT conflicting!
[02-01_15:56:43:533] [MW] current 8914800 no need set MTU, set to mannual 1500.
[02-01_15:56:43:556] Enter bound
[02-01_15:56:43:620] adding dns 198.224.166.135
[02-01_15:56:43:631] adding dns 198.224.167.135
[02-01_15:56:43:650] Not enable arlo . Not check arlo ip.
[02-01_15:56:43:650] LAN: 192.168.1.1/255.255.255.0
[02-01_15:56:43:650] WAN: 100.87.140.10/255.255.255.0
[02-01_15:56:43:650] WAN status: Link down
[02-01_15:56:43:650] WAN status: Link down
[02-01_15:56:43:650] WAN/LAN is NOT conflicting!
[02-01_15:56:43:654] ipconflict run done
[02-01_15:56:43:663] deleting routers
[02-01_15:56:43:671] adding router 100.87.140.9
[02-01_15:56:44:108] Starting Firewall…
[02-01_15:56:44:109] Done!
[02-01_15:56:44:173] $Shutting down igmpproxy:
[02-01_15:56:44:249]

[02-01_15:56:44:301] $Shutting down igmpproxy:
[02-01_15:56:44:378]

[02-01_15:56:44:419] ip change for firewall restart
[02-01_15:56:44:424] Deleting static route … Done!
[02-01_15:56:44:459] Deleting static route … Done!
[02-01_15:56:44:460] Adding static route … Done!
[02-01_15:56:45:258] {“result”:0}

At this point I give up and reboot.

Hope that helps!

Thanks!
–David

5

If it failed to set up data call , the quectel-CM would set up data call once again.

main.c

image
image914×268 106 KB

You can modify the allow_time by yourself.

And

[01-30_07:53:04:089] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-30_07:53:11:613] Not enable arlo . Not check arlo ip.
[01-30_07:53:11:613] LAN: 192.168.1.1/255.255.255.0
[01-30_07:53:11:613] WAN: 100.90.107.245/255.255.255.252
[01-30_07:53:11:613] WAN status: Link down
[01-30_07:53:11:613] WAN status: Link down
[01-30_07:53:11:614] WAN/LAN is NOT conflicting!
[01-30_07:53:11:725] [MW] current 8914800 no need set MTU, set to mannual 1500.
[01-30_07:53:11:750] Enter bound

Quectel-CM would not output those logs. It is strange.

6

Hi Bean. Thanks again for your response.

Interesting… I wonder whether what I have here is a highly-customized version of quectel-CM? The invoking command line (which yielded the logs) was:

quectel-CM -n 3 -s vzwinternet -a 0 -4 -f /tmp/qcm_logfile

This is the only process that’s writing the log file…

Is there an official (Quectel-maintained) open version of quectel-CM somewhere available for browsing? I found several repos on GitHub that seem to be taken from snapshots of various ages. Or is it proprietary (closed-source)?

Certainly some of the logs such as the “try to requestSetupDataCall …” trace are coming from quectel-CM itself (from the code you reference above). But I’m guessing other logs (like the “Not enable arlo” one) are probably coming from some customization of it that was done by the router manufacturer…

I’m just the end user unfortunately. I have no idea what (if anything) the router manufacturer did with the code they used in its implementation. Though being as the router is based on OpenWrt, I’m not beyond deriving and running my own CM build if that’s what it takes to get this issue solved. Apparently I’m running an unsupported configuration by trying to use it with Verizon anyway…

Thanks though for your help!!

7

I’ve sent you my skypeID and the lasted quectel-CM. Notice the message.