Mbed-os: u-blox SARA-R142M unable to connect using LTE Cat M1
Description of defect
I'm using a u-blox SARA-R412M module and was unable to get a connection to a LTE Cat M1 network. We have our own APN, which I've configured using CellularContext::set_credentials before starting the connection.
There appear to be two issues, which might be related so I'm listing both here. If they're not related, please let me know and I can split this into two separate issues.
- I had to manually do the AT command
CGDCONTin to be able to send data. - I had to add
CellularNetwork::C_REGto thereg_params._typecheck inCellularStateMachine::cellular_event_changedin order to get a registration to the network.
I've attached a couple of logs that are, hopefully, explaining this behaviour. In the logs and diff I've redacted the custom APN with XXX as well as the IP's.
| log | CGDCONT set | C_REG added |
| --- | ------------- | ------------- |
| 0569.log | yes | yes |
| 0570.log | no | yes |
| 0571.log | yes | no |
Logs 569 and 571 are using the following patch in order to manually add the AT command CGDCONT, to fix 1.
diff --git a/features/cellular/framework/AT/AT_CellularNetwork.cpp b/features/cellular/framework/AT/AT_CellularNetwork.cpp
index 4e35dcb4..24910a61 100644
--- a/features/cellular/framework/AT/AT_CellularNetwork.cpp
+++ b/features/cellular/framework/AT/AT_CellularNetwork.cpp
@@ -182,6 +182,11 @@ void AT_CellularNetwork::attach(Callback<void(nsapi_event_t, intptr_t)> status_c
nsapi_error_t AT_CellularNetwork::set_registration_urc(RegistrationType type, bool urc_on)
{
+ tr_info("WTG set_registration_urc");
+ _at.cmd_start("AT+CGDCONT=1,\"IP\",\"XXX.com\"");
+ _at.cmd_stop_read_resp();
+
int index = (int)type;
MBED_ASSERT(index >= 0 && index < C_MAX);
@@ -223,7 +228,7 @@ nsapi_error_t AT_CellularNetwork::set_registration(const char *plmn)
if (_op_act != RAT_UNKNOWN) {
return _at.at_cmd_discard("+COPS", "=1,2,", "%s%d", plmn, _op_act);
} else {
- return _at.at_cmd_discard("+COPS", "=1,2", "%s", plmn);
+ return _at.at_cmd_discard("+COPS", "=1,2,", "%s", plmn);
}
}
}
Logs 569 and 570 are using the following patch in order to enable the CREG registration, to fix 2.
diff --git a/features/cellular/framework/device/CellularStateMachine.cpp b/features/cellular/framework/device/CellularStateMachine.cpp
index 08b77977..633a5b20 100644
--- a/features/cellular/framework/device/CellularStateMachine.cpp
+++ b/features/cellular/framework/device/CellularStateMachine.cpp
@@ -708,8 +708,12 @@ void CellularStateMachine::cellular_event_changed(nsapi_event_t ev, intptr_t ptr
// expect packet data so only these states are valid
CellularNetwork::registration_params_t reg_params;
nsapi_error_t err = _network.get_registration_params(reg_params);
+ tr_info("TEST: err %d, type %d", err, reg_params._type);
- if (err == NSAPI_ERROR_OK && (reg_params._type == CellularNetwork::C_EREG || reg_params._type == CellularNetwork::C_GREG)) {
+ if (err == NSAPI_ERROR_OK && (reg_params._type == CellularNetwork::C_EREG
+ || reg_params._type == CellularNetwork::C_GREG
+ || reg_params._type == CellularNetwork::C_REG
+ )) {
if ((data->status_data == CellularNetwork::RegisteredHomeNetwork ||
data->status_data == CellularNetwork::RegisteredRoaming) && data->error == NSAPI_ERROR_OK) {
_queue.cancel(_event_id);
Target(s) affected by this defect ?
All targets using the u-blox SARA-R412M (and perhaps other u-blox modules as well, especially the R4x series).
Toolchain(s) (name and version) displaying this defect ?
GCC_ARM
What version of Mbed-os are you using (tag or sha) ?
5.15.0
I didn't see significant changes in cellular in the release notes up to 5.15.3 except #12088 , which I manually patched in my 5.15.0 code.
What version(s) of tools are you using. List all that apply (E.g. mbed-cli)
$ mbed --version
1.10.0
$ arm-none-eabi-gcc --version
arm-none-eabi-gcc (GNU Tools for Arm Embedded Processors 9-2019-q4-major) 9.2.1 20191025 (release) [ARM/arm-9-branch revision 277599]
How is this defect reproduced ?
- Do a cellular connection with the u-blox SARA-R412M and connect to a LTE Cat M1 network with a custom APN.
- Have APN configured using
CellularContext::set_credentialsand disable APN lookup.
jdbruijn
All 15 comments
@jdbruijn Thanks for the good logs.
Can you try if #13013 fixes the CREG problem. I can't reproduce this here, but according to the logs, CGREG/CEREG registration status was dismissed when received after CREG.
CGDCONT failure seems DNS related... Could you check with echo send/recv to see PDN is OK before DNS query?
AriParkkila
on 25 May 2020
🚀1
Can you try if #13013 fixes the CREG problem. I can't reproduce this here, but according to the logs, CGREG/CEREG registration status was dismissed when received after CREG.
Yes, I'll try this today and post back results.
CGDCONT failure seems DNS related... Could you check with echo send/recv to see PDN is OK before DNS query?
I'm taking you mean to test this without the CGDCONT change I've made, so creating a socket (UDP) and sending a message to an IP, thus omitting the DNS query. Is that correct? If so, I'll check that too!
jdbruijn
on 25 May 2020
👍1
Can you try if #13013 fixes the CREG problem. I can't reproduce this here, but according to the logs, CGREG/CEREG registration status was dismissed when received after CREG.
I've just tested with #13013 and that working just fine, without my patch for CREG obvs! Thanks for that patch! I'll manually apply that patch in my older OS version until I update to a newer release.
@AriParkkila If you're interested in the logs I can add those as well. Just let me know!
I'll check the DNS issue later today!
jdbruijn
on 25 May 2020
👍1
@AriParkkila It took a bit longer, but I've just tested echo without the CGDCONT change. Unfortunately, it didn't send the message although the device UDP socket thinks it has.
Here is my test code, and at our server I have netcat running (nc -lu 1234). I've again redacted the IP and port obvs.
UDPSocket socket(network_connection.Interface());
SocketAddress addr("x.x.x.x", 1234);
char out_buffer[] = "time\n";
nsapi_size_or_error_t e = socket.sendto(addr, out_buffer, sizeof(out_buffer));
printf("Test message sent (%d)\n\n\n", e);
Output without CGDCONT
This is the output without the CGDCONT (only the last section). Note that this the send returned 6, the size of the massage, but I didn't receive the message at the server.
[2020-05-26 15:29:43.073875] [INFO][CELL]: Found PDP context 1
[2020-05-26 15:29:43.077911] [INFO][CELL]: CellularContext PPP connect
[2020-05-26 15:29:43.081815] [INFO][CELL]: AT TX ( 9): ATD*99***
[2020-05-26 15:29:43.084871] [INFO][CELL]: AT TX ( 1): 1
[2020-05-26 15:29:43.089938] [INFO][CELL]: AT TX ( 1): #
[2020-05-26 15:29:43.091776] [INFO][CELL]: AT TX ( 1): <cr>
[2020-05-26 15:29:43.101924] [INFO][CELL]: AT RX (10): <cr><ln>CONNECT
[2020-05-26 15:29:43.106925] [DBG ][CELL]: ppp_status_cb: event 0, ptr 3
[2020-05-26 15:29:43.110966] [DBG ][CELL]: callback: 0, ptr: 3
[2020-05-26 15:29:43.120450] [DBG ][CELL]: process_oob, filehandle is not usable, return...
[2020-05-26 15:29:49.729811] [DBG ][CELL]: ppp_status_cb: event 0, ptr 1
[2020-05-26 15:29:49.733903] [DBG ][CELL]: callback: 0, ptr: 1
[2020-05-26 15:29:49.737813] Connection status: 3, cellular status: 38
[2020-05-26 15:29:49.811918] Global IP received but waiting for local IP (30816 ms)
[2020-05-26 15:29:49.914868] Connected as X.X.X.X in 30920 ms
[2020-05-26 15:29:49.918824] [INFO][CELL]: CellularContext set blocking 1
[2020-05-26 15:29:49.920659] Connected to network!
[2020-05-26 15:29:49.921730] RSSI: -51
[2020-05-26 15:29:49.923761] Test message sent (6)
[2020-05-26 15:29:49.923807]
[2020-05-26 15:29:49.923821]
[2020-05-26 15:31:29.487936] NSAPI address error! -3009
[2020-05-26 15:31:29.490894] Resolved IP address of platform ''
[2020-05-26 15:31:29.495957] [INFO][TLSW]: Starting TLS handshake with (null)
[2020-05-26 15:31:29.500989] [DBG ][TLSW]: mbedtls_ssl_setup()
[2020-05-26 15:31:29.506009] [ERR ][TLSW]: Socket send error -3006
[2020-05-26 15:31:29.517784] [ERR ][TLSW]: mbedtls_ssl_handshake() failed: -0x0bbe (-3006): UNKNOWN ERROR CODE (0B80) : ENTROPY - No more sources can be added
[2020-05-26 15:31:29.521902] Error: dtls.connect() returned -3011
Output with CGDCONT
This is the output with the CGDCONT (only the last section). Note that this the send returned 6, again the size of the massage, and the message is received at the server.
[2020-05-26 15:28:21.469884] [INFO][CELL]: Found PDP context 1
[2020-05-26 15:28:21.474850] [INFO][CELL]: CellularContext PPP connect
[2020-05-26 15:28:21.478773] [INFO][CELL]: AT TX ( 9): ATD*99***
[2020-05-26 15:28:21.481818] [INFO][CELL]: AT TX ( 1): 1
[2020-05-26 15:28:21.485430] [INFO][CELL]: AT TX ( 1): #
[2020-05-26 15:28:21.488856] [INFO][CELL]: AT TX ( 1): <cr>
[2020-05-26 15:28:21.498049] [INFO][CELL]: AT RX ( 9): <cr><ln>CONNECT
[2020-05-26 15:28:21.505107] [DBG ][CELL]: ppp_status_cb: event 0, ptr 3
[2020-05-26 15:28:21.507034] [DBG ][CELL]: callback: 0, ptr: 3
[2020-05-26 15:28:21.514065] [DBG ][CELL]: process_oob, filehandle is not usable, return...
[2020-05-26 15:28:22.530705] [DBG ][CELL]: ppp_status_cb: event 0, ptr 1
[2020-05-26 15:28:22.534809] [DBG ][CELL]: callback: 0, ptr: 1
[2020-05-26 15:28:22.538777] Connection status: 3, cellular status: 38
[2020-05-26 15:28:22.613879] Global IP received but waiting for local IP (31715 ms)
[2020-05-26 15:28:22.715857] Connected as x.x.x.x in 31819 ms
[2020-05-26 15:28:22.719847] [INFO][CELL]: CellularContext set blocking 1
[2020-05-26 15:28:22.721860] Connected to network!
[2020-05-26 15:28:22.722862] RSSI: -51
[2020-05-26 15:28:22.725878] Test message sent (6)
[2020-05-26 15:28:22.725928]
[2020-05-26 15:28:22.725941]
[2020-05-26 15:28:23.050074] Resolved IP address of platform 'x.x.x.x'
[2020-05-26 15:28:23.055019] [INFO][TLSW]: Starting TLS handshake with (null)
[2020-05-26 15:28:23.059866] [DBG ][TLSW]: mbedtls_ssl_setup()
[2020-05-26 15:28:25.607752] [INFO][TLSW]: TLS connection to (null) established
[2020-05-26 15:28:25.612156] [DBG ][TLSW]: Server certificate:
...
[2020-05-26 15:28:25.658797] [INFO][TLSW]: Certificate verification passed
[2020-05-26 15:28:25.661861] DTLS Open finished, Connected now!
@jdbruijn Thanks for testing. Obviously, the modem should not tell it sent something it didn't... @ARMmbed/team-ublox could know more about that?
AriParkkila
on 27 May 2020
@AriParkkila Any update on the outstanding issue as described in https://github.com/ARMmbed/mbed-os/issues/13000#issuecomment-634033722?
jdbruijn
on 3 Jun 2020
it didn't send the message although the device UDP socket thinks it has
@jdbruijn @ARMmbed/team-ublox can probably answer what might wrong on the modem side.
Culprit could be something like a conflict between the default initial context and your PDN, so you could still check AT+CGDCONT? that APN of PDP with ID 1 is correct (in the logs X/XXX.com) before network is attached +CGATT: 1.
AriParkkila
on 4 Jun 2020
👍1
Culprit could be something like a conflict between the default initial context and your PDN, so you could still check
AT+CGDCONT?that APN of PDP with ID 1 is correct (in the logs X/XXX.com) before network is attached+CGATT: 1.
Thanks for the suggestion. I've tried this by adding the AT+CGDCONT? to the beginning of AT_CellularNetwork::get_signal_quality since I noticed that the signal quality is read before +CGATT: 1 in the logs.
The default for the module is all zeroes (u-blox AT manual) so looks something like below, but not all is read due to AT buffer size.
During the first two thirds or so of the logs, the response of AT+CGDCONT? is the default. After network registration, but before +CGATT: 1, the response shows the correct APN (redacted of course) and its assigned IP (see 2nd part of the log below).
So it seems I do see the correct APN before network is attached. If there is any more I could test please let me know!
[2020-06-04 09:16:31.418314] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:31.423924] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:31.428149] [ERR ][CELL]: AT overflow
...
[2020-06-04 09:16:39.287177] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 09:16:39.295146] [INFO][CELL]: AT RX (32): m","1.2.3.4",0,0,0,0<cr><ln><cr><ln>OK<cr>
[2020-06-04 09:16:39.298115] [INFO][CELL]: AT RX ( 1): <ln>
@AriParkkila I've noted that the default is an IPV4V6 address and the configured/received address is IPV4, so could that have anything to do with this issue? Do I need change the default to all zeroes, but with IPV4?
Full log
[2020-06-04 09:16:08.513350] [INFO][CELL]: CellularContext set blocking 0
[2020-06-04 09:16:08.528134] [INFO][CELL]: CellularContext set blocking 0
[2020-06-04 09:16:08.529230] [INFO][CELL]: CellularContext connect: CellularContext connect
[2020-06-04 09:16:08.539153]
[2020-06-04 09:16:08.542301] Connection status: 2, cellular status: 0
[2020-06-04 09:16:08.542301] [DBG ][CELL]: callback: 4106, err: 0, data: 4096
[2020-06-04 09:16:08.561442] Unknown cellular status
[2020-06-04 09:16:08.569459] Connection status: 2, cellular status: 0
[2020-06-04 09:16:08.579424] [INFO][CELL]: Start connecting (timeout 1000 ms)
[2020-06-04 09:16:08.582425] [INFO][CELL]: AT TX ( 2): AT
[2020-06-04 09:16:08.591487] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:09.584441] [DBG ][CELL]: AT error -3012
[2020-06-04 09:16:09.588261] [INFO][CELL]: AT TX ( 2): AT
[2020-06-04 09:16:09.591439] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:10.589238] [DBG ][CELL]: AT error -3012
[2020-06-04 09:16:10.592189] [DBG ][CELL]: Init => Power
[2020-06-04 09:16:10.597199] [DBG ][CELL]: callback: 4106, err: 0, data: 4096
[2020-06-04 09:16:10.599171] Unknown cellular status
[2020-06-04 09:16:10.603248] Connection status: 2, cellular status: 0
[2020-06-04 09:16:10.608188] [INFO][CELL]: Modem power ON (timeout 1000 ms)
[2020-06-04 09:16:10.631269] [DBG ][CELL]: Power => Device ready
[2020-06-04 09:16:10.637227] [DBG ][CELL]: callback: 4106, err: 0, data: 4096
[2020-06-04 09:16:10.639202] Unknown cellular status
[2020-06-04 09:16:10.642200] Connection status: 2, cellular status: 0
[2020-06-04 09:16:10.648213] [DBG ][CELL]: Device was not ready, calling soft_power_on()
[2020-06-04 09:16:10.850281] [DBG ][CELL]: AT flush
[2020-06-04 09:16:10.854231] [INFO][CELL]: AT RX ( 1): <00>
[2020-06-04 09:16:10.858249] [INFO][CELL]: AT TX ( 4): ATE0
[2020-06-04 09:16:10.861248] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:11.858572] [DBG ][CELL]: AT error -3012
[2020-06-04 09:16:11.863334] [DBG ][CELL]: Wait 100ms to init modem
[2020-06-04 09:16:11.965625] [DBG ][CELL]: AT flush
[2020-06-04 09:16:11.968502] [INFO][CELL]: AT TX ( 4): ATE0
[2020-06-04 09:16:11.973879] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:12.970577] [DBG ][CELL]: AT error -3012
[2020-06-04 09:16:12.973282] [DBG ][CELL]: Wait 100ms to init modem
[2020-06-04 09:16:13.075361] [DBG ][CELL]: AT flush
[2020-06-04 09:16:13.079551] [INFO][CELL]: AT TX ( 4): ATE0
[2020-06-04 09:16:13.083446] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:14.080638] [DBG ][CELL]: AT error -3012
[2020-06-04 09:16:14.084574] [DBG ][CELL]: Wait 100ms to init modem
[2020-06-04 09:16:14.188310] [DBG ][CELL]: Device ready: retry 0/10
[2020-06-04 09:16:14.196315] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4096, retrycount: 0
[2020-06-04 09:16:14.198711] Unknown cellular status
[2020-06-04 09:16:14.202802] Connection status: 2, cellular status: 0
[2020-06-04 09:16:14.206338] [INFO][CELL]: Continue after 1 seconds
[2020-06-04 09:16:15.212548] [DBG ][CELL]: callback: 4106, err: 0, data: 4096
[2020-06-04 09:16:15.214573] Unknown cellular status
[2020-06-04 09:16:15.217525] Connection status: 2, cellular status: 0
[2020-06-04 09:16:15.224499] [DBG ][CELL]: Device was not ready, calling soft_power_on()
[2020-06-04 09:16:15.429611] [WARN][CELL]: URC already added with prefix: +CGEV: NW DEACT
[2020-06-04 09:16:15.435675] [WARN][CELL]: URC already added with prefix: +CGEV: ME DEACT
[2020-06-04 09:16:15.441395] [WARN][CELL]: URC already added with prefix: +CGEV: NW PDN D
[2020-06-04 09:16:15.447305] [WARN][CELL]: URC already added with prefix: +CGEV: ME PDN D
[2020-06-04 09:16:15.450381] [DBG ][CELL]: AT flush
[2020-06-04 09:16:15.454342] [INFO][CELL]: AT TX ( 4): ATE0
[2020-06-04 09:16:15.457351] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.463330] [INFO][CELL]: AT RX (11): ATE0<cr><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.467371] [INFO][CELL]: AT TX ( 9): AT+CMEE=1
[2020-06-04 09:16:15.472982] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.475335] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.479343] [INFO][CELL]: AT TX ( 9): AT+CFUN=1
[2020-06-04 09:16:15.483518] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.487350] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.491368] [INFO][CELL]: Modem ready
[2020-06-04 09:16:15.496338] [DBG ][CELL]: callback: 4096, err: 0, data: 4096
[2020-06-04 09:16:15.499385] Connection status: 2, cellular status: 1
[2020-06-04 09:16:15.504333] [DBG ][CELL]: Device ready => SIM pin
[2020-06-04 09:16:15.509305] [DBG ][CELL]: callback: 4106, err: 0, data: 4097
[2020-06-04 09:16:15.512344] Unknown cellular status
[2020-06-04 09:16:15.515371] Connection status: 2, cellular status: 1
[2020-06-04 09:16:15.519418] [INFO][CELL]: Setup SIM (timeout 1000 ms)
[2020-06-04 09:16:15.522326] [DBG ][CELL]: AT flush
[2020-06-04 09:16:15.526301] [INFO][CELL]: AT TX ( 8): AT+CPIN?
[2020-06-04 09:16:15.529307] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.537441] [INFO][CELL]: AT RX (22): <cr><ln>+CPIN: READY<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.540417] [INFO][CELL]: SIM is ready
[2020-06-04 09:16:15.545416] [DBG ][CELL]: callback: 4097, err: 0, data: 0
[2020-06-04 09:16:15.548862] Connection status: 2, cellular status: 2
[2020-06-04 09:16:15.553441] [DBG ][CELL]: Automatic network registration
[2020-06-04 09:16:15.557485] [INFO][CELL]: AT TX ( 8): AT+COPS?
[2020-06-04 09:16:15.561372] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.565346] [INFO][CELL]: AT RX ( 6): <cr><ln>+COP
[2020-06-04 09:16:15.571379] [INFO][CELL]: AT RX (12): S: 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.576313] [DBG ][CELL]: STM: set_registration: 0, plmn: NULL
[2020-06-04 09:16:15.580342] [INFO][CELL]: AT TX ( 9): AT+CGREG=
[2020-06-04 09:16:15.583424] [INFO][CELL]: AT TX ( 1): 2
[2020-06-04 09:16:15.587351] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.592353] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.596355] [INFO][CELL]: AT TX ( 8): AT+CREG=
[2020-06-04 09:16:15.599330] [INFO][CELL]: AT TX ( 1): 2
[2020-06-04 09:16:15.602331] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.607357] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.611333] [INFO][CELL]: AT TX ( 9): AT+CGACT?
[2020-06-04 09:16:15.615336] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.621347] [INFO][CELL]: AT RX (12): <cr><ln>+CGACT: 1,
[2020-06-04 09:16:15.626308] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.630302] [INFO][CELL]: AT TX ( 9): AT+CGATT?
[2020-06-04 09:16:15.634354] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.638338] [INFO][CELL]: AT RX (11): <cr><ln>+CGATT: 0
[2020-06-04 09:16:15.644339] [INFO][CELL]: AT RX ( 8): <cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.648303] [INFO][CELL]: AT TX (10): AT+CGEREP=
[2020-06-04 09:16:15.651393] [INFO][CELL]: AT TX ( 1): 1
[2020-06-04 09:16:15.655398] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.660332] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.664311] [DBG ][CELL]: SIM pin => Signal quality
[2020-06-04 09:16:15.669404] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:15.672460] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.676349] [INFO][CELL]: AT RX ( 2): <cr><ln>
[2020-06-04 09:16:15.682407] [INFO][CELL]: AT RX (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:15.685336] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:15.691402] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:15.697337] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:15.700438] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:15.706315] [INFO][CELL]: AT ERR (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:15.712353] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.716322] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:15.719387] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.724383] [INFO][CELL]: AT RX (14): <cr><ln>+CSQ: 99,99<cr>
[2020-06-04 09:16:15.729333] [INFO][CELL]: AT RX ( 7): <ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.734402] [DBG ][CELL]: callback: 4104, err: 0, data: -1
[2020-06-04 09:16:15.738358] Connection status: 2, cellular status: 2
[2020-06-04 09:16:15.743344] [DBG ][CELL]: Signal quality => Registering network
[2020-06-04 09:16:15.748792] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:15.751746] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.756356] [INFO][CELL]: AT RX ( 8): <cr><ln>+CGDCO
[2020-06-04 09:16:15.762344] [INFO][CELL]: AT RX (26): NT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:15.765368] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:15.771500] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:15.777316] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:15.781354] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:15.786329] [INFO][CELL]: AT ERR (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:15.792340] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:15.796361] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:15.799323] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.805373] [INFO][CELL]: AT RX (17): <cr><ln>+CSQ: 99,99<cr><ln><cr><ln>
[2020-06-04 09:16:15.809355] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 09:16:15.814325] [DBG ][CELL]: callback: 4104, err: 0, data: -1
[2020-06-04 09:16:15.818335] Connection status: 2, cellular status: 2
[2020-06-04 09:16:15.821303] [INFO][CELL]: RSSI unknown
[2020-06-04 09:16:15.826335] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:15.829345] Unknown cellular status
[2020-06-04 09:16:15.832342] Connection status: 2, cellular status: 2
[2020-06-04 09:16:15.836323] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 09:16:15.840352] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.846314] [INFO][CELL]: AT RX (18): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>O
[2020-06-04 09:16:15.853421] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 09:16:15.857325] [INFO][CELL]: AT RX ( 3): K<cr><ln>
[2020-06-04 09:16:15.863313] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 09:16:15.868348] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:15.870336] Unknown cellular status
[2020-06-04 09:16:15.874307] Connection status: 2, cellular status: 2
[2020-06-04 09:16:15.879388] [DBG ][CELL]: Automatic network registration
[2020-06-04 09:16:15.883368] [INFO][CELL]: AT TX ( 8): AT+COPS?
[2020-06-04 09:16:15.886386] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:15.893363] [INFO][CELL]: AT RX (17): <cr><ln>+COPS: 0<cr><ln><cr><ln>OK<cr>
[2020-06-04 09:16:15.896358] [INFO][CELL]: AT RX ( 1): <ln>
[2020-06-04 09:16:15.901407] [DBG ][CELL]: Registering network: retry 0/10
[2020-06-04 09:16:15.909317] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 0
[2020-06-04 09:16:15.911315] Unknown cellular status
[2020-06-04 09:16:15.915343] Connection status: 2, cellular status: 2
[2020-06-04 09:16:15.919327] [INFO][CELL]: Continue after 1 seconds
[2020-06-04 09:16:16.924636] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:16.928675] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:16.934513] [INFO][CELL]: AT RX ( 8): <cr><ln>+CGDCO
[2020-06-04 09:16:16.939576] [INFO][CELL]: AT RX (26): NT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:16.942432] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:16.948419] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:16.954387] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:16.957404] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:16.964354] [INFO][CELL]: AT ERR (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:16.969902] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:16.973461] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:16.976397] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:16.982396] [INFO][CELL]: AT RX (14): <cr><ln>+CSQ: 99,99<cr>
[2020-06-04 09:16:16.987411] [INFO][CELL]: AT RX ( 7): <ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:16.992393] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 09:16:16.996475] Connection status: 2, cellular status: 2
[2020-06-04 09:16:16.999397] [INFO][CELL]: RSSI unknown
[2020-06-04 09:16:17.004549] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:17.006411] Unknown cellular status
[2020-06-04 09:16:17.010494] Connection status: 2, cellular status: 2
[2020-06-04 09:16:17.014403] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 09:16:17.017500] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:17.022381] [INFO][CELL]: AT RX (13): <cr><ln>+CGREG: 2,4
[2020-06-04 09:16:17.028411] [INFO][CELL]: AT RX ( 8): <cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:17.035477] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 09:16:17.040416] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 09:16:17.045397] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:17.048375] Unknown cellular status
[2020-06-04 09:16:17.051463] Connection status: 2, cellular status: 2
[2020-06-04 09:16:17.056398] [DBG ][CELL]: Registering network: retry 1/10
[2020-06-04 09:16:17.064395] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 1
[2020-06-04 09:16:17.066395] Unknown cellular status
[2020-06-04 09:16:17.070447] Connection status: 2, cellular status: 2
[2020-06-04 09:16:17.074367] [INFO][CELL]: Continue after 2 seconds
[2020-06-04 09:16:19.080734] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:19.084548] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:19.088741] [INFO][CELL]: AT RX ( 2): <cr><ln>
[2020-06-04 09:16:19.094708] [INFO][CELL]: AT RX (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:19.097534] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:19.104110] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:19.110725] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:19.112433] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:19.119608] [INFO][CELL]: AT ERR (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:19.124499] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:19.128460] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:19.131480] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:19.136842] [INFO][CELL]: AT RX (11): <cr><ln>+CSQ: 99,
[2020-06-04 09:16:19.142421] [INFO][CELL]: AT RX (10): 99<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:19.147452] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 09:16:19.150419] Connection status: 2, cellular status: 2
[2020-06-04 09:16:19.154548] [INFO][CELL]: RSSI unknown
[2020-06-04 09:16:19.159434] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:19.161449] Unknown cellular status
[2020-06-04 09:16:19.164446] Connection status: 2, cellular status: 2
[2020-06-04 09:16:19.169474] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 09:16:19.172435] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:19.178476] [INFO][CELL]: AT RX (17): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>
[2020-06-04 09:16:19.186827] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 09:16:19.190594] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 09:16:19.195451] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 09:16:19.200450] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:19.203485] Unknown cellular status
[2020-06-04 09:16:19.206445] Connection status: 2, cellular status: 2
[2020-06-04 09:16:19.211431] [DBG ][CELL]: Registering network: retry 2/10
[2020-06-04 09:16:19.219523] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 2
[2020-06-04 09:16:19.221533] Unknown cellular status
[2020-06-04 09:16:19.225454] Connection status: 2, cellular status: 2
[2020-06-04 09:16:19.230467] [INFO][CELL]: Continue after 4 seconds
[2020-06-04 09:16:23.236608] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:23.240771] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:23.245589] [INFO][CELL]: AT RX (17): <cr><ln>+CGDCONT: 1,"IP
[2020-06-04 09:16:23.250804] [INFO][CELL]: AT RX (17): V4V6","","0.0.0.0
[2020-06-04 09:16:23.253661] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:23.259752] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:23.265632] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:23.268585] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:23.274664] [INFO][CELL]: AT ERR (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:23.280589] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:23.283571] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:23.287627] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:23.292612] [INFO][CELL]: AT RX (14): <cr><ln>+CSQ: 99,99<cr>
[2020-06-04 09:16:23.297536] [INFO][CELL]: AT RX ( 7): <ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:23.302529] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 09:16:23.306920] Connection status: 2, cellular status: 2
[2020-06-04 09:16:23.309601] [INFO][CELL]: RSSI unknown
[2020-06-04 09:16:23.314753] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:23.317598] Unknown cellular status
[2020-06-04 09:16:23.320658] Connection status: 2, cellular status: 2
[2020-06-04 09:16:23.324587] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 09:16:23.328540] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:23.335556] [INFO][CELL]: AT RX (20): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>OK<cr>
[2020-06-04 09:16:23.342549] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 09:16:23.345607] [INFO][CELL]: AT RX ( 1): <ln>
[2020-06-04 09:16:23.351558] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 09:16:23.356545] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:23.358619] Unknown cellular status
[2020-06-04 09:16:23.362574] Connection status: 2, cellular status: 2
[2020-06-04 09:16:23.367572] [DBG ][CELL]: Registering network: retry 3/10
[2020-06-04 09:16:23.375557] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 3
[2020-06-04 09:16:23.377616] Unknown cellular status
[2020-06-04 09:16:23.381533] Connection status: 2, cellular status: 2
[2020-06-04 09:16:23.385597] [INFO][CELL]: Continue after 8 seconds
[2020-06-04 09:16:31.397044] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:31.399015] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:31.403314] [INFO][CELL]: AT RX ( 3): <cr><ln>+
[2020-06-04 09:16:31.409617] [INFO][CELL]: AT RX (31): CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:31.412165] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:31.418314] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IPV4V6","","0.0.0.0
[2020-06-04 09:16:31.423924] [INFO][CELL]: AT RX (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:31.428149] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:31.433902] [INFO][CELL]: AT ERR (32): .0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,
[2020-06-04 09:16:31.440794] [INFO][CELL]: AT RX ( 9): 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:31.442953] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:31.446907] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:31.450861] [INFO][CELL]: AT RX (10): <cr><ln>+CSQ: 99
[2020-06-04 09:16:31.457864] [INFO][CELL]: AT RX (11): ,99<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:31.461857] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 09:16:31.465860] Connection status: 2, cellular status: 2
[2020-06-04 09:16:31.468851] [INFO][CELL]: RSSI unknown
[2020-06-04 09:16:31.474960] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:31.475867] Unknown cellular status
[2020-06-04 09:16:31.479879] Connection status: 2, cellular status: 2
[2020-06-04 09:16:31.483869] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 09:16:31.487164] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:31.492890] [INFO][CELL]: AT RX (15): <cr><ln>+CGREG: 2,4<cr><ln>
[2020-06-04 09:16:31.499900] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 09:16:31.504793] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 09:16:31.510025] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 09:16:31.515884] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 09:16:31.517850] Unknown cellular status
[2020-06-04 09:16:31.520863] Connection status: 2, cellular status: 2
[2020-06-04 09:16:31.525886] [DBG ][CELL]: Registering network: retry 4/10
[2020-06-04 09:16:31.533967] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 4
[2020-06-04 09:16:31.536906] Unknown cellular status
[2020-06-04 09:16:31.542080] Connection status: 2, cellular status: 2
[2020-06-04 09:16:31.547389] [INFO][CELL]: Continue after 16 seconds
[2020-06-04 09:16:39.186229] [DBG ][CELL]: AT OoB readable 1, len 0
[2020-06-04 09:16:39.193189] [INFO][CELL]: AT RX (32): <cr><ln>+CREG: 5,"FFFE","1905202", 7<cr><ln>
[2020-06-04 09:16:39.200154] [DBG ][CELL]: +CREG: RegisteredRoaming, LAC 65534, cell 26235394, E_UTRAN
[2020-06-04 09:16:39.205203] [DBG ][CELL]: callback: 4101, err: 0, data: 7
[2020-06-04 09:16:39.208230] Connection status: 2, cellular status: 32
[2020-06-04 09:16:39.213245] [DBG ][CELL]: callback: 4098, err: 0, data: 5
[2020-06-04 09:16:39.219793] [INFO][CELL]: Registering network => Attaching network
[2020-06-04 09:16:39.223196] Connection status: 2, cellular status: 12
[2020-06-04 09:16:39.228197] [DBG ][CELL]: callback: 4100, err: 0, data: 26235394
[2020-06-04 09:16:39.232126] Connection status: 2, cellular status: 24
[2020-06-04 09:16:39.239211] [INFO][CELL]: AT RX (32): <cr><ln>+CGREG: 5,"FFFE","1905202",7<cr><ln>
[2020-06-04 09:16:39.246111] [DBG ][CELL]: +CGREG: RegisteredRoaming, LAC 65534, cell 26235394, E_UTRAN
[2020-06-04 09:16:39.251236] [DBG ][CELL]: callback: 4098, err: 0, data: 5
[2020-06-04 09:16:39.256172] Connection status: 2, cellular status: 12
[2020-06-04 09:16:39.258191] [DBG ][CELL]: AT OoB done
[2020-06-04 09:16:39.262112] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:39.266219] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:39.273201] [INFO][CELL]: AT RX ( 8): <cr><ln>+CGDCO
[2020-06-04 09:16:39.278515] [INFO][CELL]: AT RX (26): NT: 1,"IP","example.co
[2020-06-04 09:16:39.281233] [ERR ][CELL]: AT overflow
[2020-06-04 09:16:39.287177] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 09:16:39.295146] [INFO][CELL]: AT RX (32): m","1.2.3.4",0,0,0,0<cr><ln><cr><ln>OK<cr>
[2020-06-04 09:16:39.298115] [INFO][CELL]: AT RX ( 1): <ln>
[2020-06-04 09:16:39.302200] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 09:16:39.305101] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:39.310033] [INFO][CELL]: AT RX ( 2): <cr><ln>
[2020-06-04 09:16:39.316074] [INFO][CELL]: AT RX (19): +CSQ: 23,99<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:39.321133] [DBG ][CELL]: callback: 4104, err: 0, data: -1
[2020-06-04 09:16:39.325155] Connection status: 2, cellular status: 12
[2020-06-04 09:16:39.328207] [INFO][CELL]: RSSI -67 dBm
[2020-06-04 09:16:39.333209] [DBG ][CELL]: callback: 4106, err: 0, data: 4102
[2020-06-04 09:16:39.335232] Unknown cellular status
[2020-06-04 09:16:39.339131] Connection status: 2, cellular status: 12
[2020-06-04 09:16:39.344019] [INFO][CELL]: Attaching network (timeout 60000 ms)
[2020-06-04 09:16:39.348210] [INFO][CELL]: AT TX ( 9): AT+CGATT?
[2020-06-04 09:16:39.352065] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:39.356213] [INFO][CELL]: AT RX ( 2): <cr><ln>
[2020-06-04 09:16:39.362479] [INFO][CELL]: AT RX (17): +CGATT: 1<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 09:16:39.367178] [DBG ][CELL]: callback: 4102, err: 0, data: 1
[2020-06-04 09:16:39.370111] Connection status: 2, cellular status: 38
[2020-06-04 09:16:39.377049] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 09:16:39.378095] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:39.383562] [INFO][CELL]: AT RX ( 4): <cr><ln>+C
[2020-06-04 09:16:39.389098] [INFO][CELL]: AT RX (30): GDCONT: 1,"IP","example.co
[2020-06-04 09:16:39.396225] [INFO][CELL]: AT RX (32): m","1.2.3.4",0,0,0,0<cr><ln><cr><ln>OK<cr>
[2020-06-04 09:16:39.400227] [INFO][CELL]: AT RX ( 1): <ln>
[2020-06-04 09:16:39.404198] [INFO][CELL]: Found PDP context 1
[2020-06-04 09:16:39.408089] [INFO][CELL]: CellularContext PPP connect
[2020-06-04 09:16:39.412178] [INFO][CELL]: AT TX ( 9): ATD*99***
[2020-06-04 09:16:39.416225] [INFO][CELL]: AT TX ( 1): 1
[2020-06-04 09:16:39.419169] [INFO][CELL]: AT TX ( 1): #
[2020-06-04 09:16:39.423085] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 09:16:39.431203] [INFO][CELL]: AT RX ( 5): <cr><ln>CON
[2020-06-04 09:16:39.437196] [INFO][CELL]: AT RX (16): NECT 150000000<cr><ln>
[2020-06-04 09:16:39.443190] [DBG ][CELL]: ppp_status_cb: event 0, ptr 3
[2020-06-04 09:16:39.446210] [DBG ][CELL]: callback: 0, ptr: 3
[2020-06-04 09:16:39.452270] [DBG ][CELL]: process_oob, filehandle is not usable, return...
[2020-06-04 09:16:46.333611] [DBG ][CELL]: ppp_status_cb: event 0, ptr 1
[2020-06-04 09:16:46.338508] [DBG ][CELL]: callback: 0, ptr: 1
[2020-06-04 09:16:46.341525] Connection status: 3, cellular status: 38
[2020-06-04 09:16:46.375466] Global IP received but waiting for local IP (37812 ms)
[2020-06-04 09:16:46.478566] Connected as 1.2.3.4 in 37916 ms
[2020-06-04 09:16:46.483564] [INFO][CELL]: CellularContext set blocking 1
[2020-06-04 09:16:46.485603] Connected to network!
[2020-06-04 09:16:46.486485] RSSI: -67
[2020-06-04 09:16:46.488527] Test message sent (6)
[2020-06-04 09:16:46.488629]
[2020-06-04 09:16:46.488672]
@jdbruijn It might be possible that the default context with an empty APN ("") is activated here. To prevent that you might try with JSON configurations cellular.clear-on-connect and nsapi.default-cellular-apn to define APN early enough.
AriParkkila
on 4 Jun 2020
I've tried both, but makes no difference. I was already setting the credentials in my code before connecting. Also, AT_CellularNetwork::clear isn't even called according to my logs, which is the only place where MBED_CONF_NSAPI_DEFAULT_CELLULAR_APN is really used. @AriParkkila should that function be called?
I've overridden the CellularDevice::get_default_instance to set my own cellular device drivers so CellularInterface::set_default_parameters, the other place where MBED_CONF_NSAPI_DEFAULT_CELLULAR_APN is used, isn't called but I set those credentials as shown below.
_connection = mbed::CellularContext::get_default_instance();
_interface = _connection;
_connection->set_credentials("example.com", 0, 0);
Mostly for my personal reference: this is with the config defines below.
#define MBED_CONF_NSAPI_DEFAULT_CELLULAR_APN "example.com"
#define MBED_CONF_CELLULAR_CLEAR_ON_CONNECT 1
Okay, this is quite strange. I noticed that the code inside the MBED_CONF_CELLULAR_CLEAR_ON_CONNECT check #ifdef wasn't reached. I don't know why yet because it surely was configured in _mbed_config.h_, but when I manually removed it, something changed. I now as able to send a UDP packet to my server with only the clear on connect change, as I already configured the APN in the credentials call. In the logs I see that after the clear, it immediately sets the APN, so it indeed looks like something with the context although I don't quite understand it. In de end, it still sets the context previously so I don't get why it would run into the issue thinking it has sent data but not actually sent it.
[2020-06-04 12:26:26.762406] [INFO][CELL]: SIM is ready
[2020-06-04 12:26:26.766990] [DBG ][CELL]: callback: 4097, err: 0, data: 0
[2020-06-04 12:26:26.771066] Connection status: 2, cellular status: 2
[2020-06-04 12:26:26.774100] [INFO][CELL]: SIM_READY
[2020-06-04 12:26:26.777005] [INFO][CELL]: CLEAR_ON_CONNECT
[2020-06-04 12:26:26.781097] [INFO][CELL]: AT_CellularNetwork::clear
[2020-06-04 12:26:26.786190] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:26.789017] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.793032] [INFO][CELL]: AT RX ( 7): <cr><ln>+CGDC
[2020-06-04 12:26:26.799097] [INFO][CELL]: AT RX (27): ONT: 1,"IP","example.co
[2020-06-04 12:26:26.805996] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.811051] [DBG ][CELL]: Automatic network registration
And the change I had to do to work around the still unknown define issue.
diff --git a/features/cellular/framework/device/CellularStateMachine.cpp b/features/cellular/framework/device/CellularStateMachine.cpp
index 08b779773b..b82308a4b3 100644
--- a/features/cellular/framework/device/CellularStateMachine.cpp
+++ b/features/cellular/framework/device/CellularStateMachine.cpp
@@ -173,12 +173,14 @@ bool CellularStateMachine::open_sim()
bool sim_ready = state == CellularDevice::SimStateReady;
if (sim_ready) {
-#ifdef MBED_CONF_CELLULAR_CLEAR_ON_CONNECT
+ tr_info("SIM_READY");
+// #ifdef MBED_CONF_CELLULAR_CLEAR_ON_CONNECT
+ tr_info("CLEAR_ON_CONNECT");
if (_cellularDevice.clear() != NSAPI_ERROR_OK) {
tr_warning("CellularDevice clear failed");
return false;
}
-#endif
+// #endif
_cb_data.error = _network.set_registration(_plmn);
tr_debug("STM: set_registration: %d, plmn: %s", _cb_data.error, _plmn ? _plmn : "NULL");
if (_cb_data.error) {
Full log
[2020-06-04 12:26:25.313017] [DBG ][CELL]: Wait 100ms to init modem
[2020-06-04 12:26:25.416963] [DBG ][CELL]: Device ready: retry 0/10
[2020-06-04 12:26:25.424954] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4096, retrycount: 0
[2020-06-04 12:26:25.427030] Unknown cellular status
[2020-06-04 12:26:25.431003] Connection status: 2, cellular status: 0
[2020-06-04 12:26:25.435265] [INFO][CELL]: Continue after 1 seconds
[2020-06-04 12:26:26.436261] [DBG ][CELL]: callback: 4106, err: 0, data: 4096
[2020-06-04 12:26:26.438225] Unknown cellular status
[2020-06-04 12:26:26.440999] Connection status: 2, cellular status: 0
[2020-06-04 12:26:26.446983] [DBG ][CELL]: Device was not ready, calling soft_power_on()
[2020-06-04 12:26:26.651991] [WARN][CELL]: URC already added with prefix: +CGEV: NW DEACT
[2020-06-04 12:26:26.659044] [WARN][CELL]: URC already added with prefix: +CGEV: ME DEACT
[2020-06-04 12:26:26.663999] [WARN][CELL]: URC already added with prefix: +CGEV: NW PDN D
[2020-06-04 12:26:26.670056] [WARN][CELL]: URC already added with prefix: +CGEV: ME PDN D
[2020-06-04 12:26:26.673406] [DBG ][CELL]: AT flush
[2020-06-04 12:26:26.677083] [INFO][CELL]: AT TX ( 4): ATE0
[2020-06-04 12:26:26.681712] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.686045] [INFO][CELL]: AT RX (11): ATE0<cr><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.690233] [INFO][CELL]: AT TX ( 9): AT+CMEE=1
[2020-06-04 12:26:26.693061] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.698036] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.702422] [INFO][CELL]: AT TX ( 9): AT+CFUN=1
[2020-06-04 12:26:26.705817] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.710182] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.714407] [INFO][CELL]: Modem ready
[2020-06-04 12:26:26.718013] [DBG ][CELL]: callback: 4096, err: 0, data: 4096
[2020-06-04 12:26:26.722647] Connection status: 2, cellular status: 1
[2020-06-04 12:26:26.726080] [DBG ][CELL]: Device ready => SIM pin
[2020-06-04 12:26:26.731031] [DBG ][CELL]: callback: 4106, err: 0, data: 4097
[2020-06-04 12:26:26.733125] Unknown cellular status
[2020-06-04 12:26:26.737097] Connection status: 2, cellular status: 1
[2020-06-04 12:26:26.742093] [INFO][CELL]: Setup SIM (timeout 1000 ms)
[2020-06-04 12:26:26.744038] [DBG ][CELL]: AT flush
[2020-06-04 12:26:26.748345] [INFO][CELL]: AT TX ( 8): AT+CPIN?
[2020-06-04 12:26:26.752171] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.759181] [INFO][CELL]: AT RX (22): <cr><ln>+CPIN: READY<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.762406] [INFO][CELL]: SIM is ready
[2020-06-04 12:26:26.766990] [DBG ][CELL]: callback: 4097, err: 0, data: 0
[2020-06-04 12:26:26.771066] Connection status: 2, cellular status: 2
[2020-06-04 12:26:26.774100] [INFO][CELL]: SIM_READY
[2020-06-04 12:26:26.777005] [INFO][CELL]: CLEAR_ON_CONNECT
[2020-06-04 12:26:26.781097] [INFO][CELL]: AT_CellularNetwork::clear
[2020-06-04 12:26:26.786190] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:26.789017] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.793032] [INFO][CELL]: AT RX ( 7): <cr><ln>+CGDC
[2020-06-04 12:26:26.799097] [INFO][CELL]: AT RX (27): ONT: 1,"IP","example.co
[2020-06-04 12:26:26.805996] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.811051] [DBG ][CELL]: Automatic network registration
[2020-06-04 12:26:26.815444] [INFO][CELL]: AT TX ( 8): AT+COPS?
[2020-06-04 12:26:26.818155] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.822987] [INFO][CELL]: AT RX (10): <cr><ln>+COPS: 0
[2020-06-04 12:26:26.828196] [INFO][CELL]: AT RX ( 8): <cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.834012] [DBG ][CELL]: STM: set_registration: 0, plmn: NULL
[2020-06-04 12:26:26.837991] [INFO][CELL]: AT TX ( 9): AT+CGREG=
[2020-06-04 12:26:26.841179] [INFO][CELL]: AT TX ( 1): 2
[2020-06-04 12:26:26.844077] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.849046] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.853025] [INFO][CELL]: AT TX ( 8): AT+CREG=
[2020-06-04 12:26:26.856024] [INFO][CELL]: AT TX ( 1): 2
[2020-06-04 12:26:26.860053] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.865172] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.869018] [INFO][CELL]: AT TX ( 9): AT+CGACT?
[2020-06-04 12:26:26.871972] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.877016] [INFO][CELL]: AT RX ( 7): <cr><ln>+CGAC
[2020-06-04 12:26:26.883057] [INFO][CELL]: AT RX (14): T: 1,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.887331] [INFO][CELL]: AT TX ( 9): AT+CGATT?
[2020-06-04 12:26:26.890164] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.894007] [INFO][CELL]: AT RX ( 7): <cr><ln>+CGAT
[2020-06-04 12:26:26.900168] [INFO][CELL]: AT RX (12): T: 0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.904048] [INFO][CELL]: AT TX (10): AT+CGEREP=
[2020-06-04 12:26:26.908186] [INFO][CELL]: AT TX ( 1): 1
[2020-06-04 12:26:26.911070] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.915998] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.920175] [DBG ][CELL]: SIM pin => Signal quality
[2020-06-04 12:26:26.924001] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:26.928184] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.931978] [INFO][CELL]: AT RX ( 4): <cr><ln>+C
[2020-06-04 12:26:26.937982] [INFO][CELL]: AT RX (30): GDCONT: 1,"IP","example.co
[2020-06-04 12:26:26.941065] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:26.947139] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:26.953985] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:26.958029] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:26.960999] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.968016] [INFO][CELL]: AT RX (17): <cr><ln>+CSQ: 99,99<cr><ln><cr><ln>
[2020-06-04 12:26:26.971979] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 12:26:26.978083] [DBG ][CELL]: callback: 4104, err: 0, data: -1
[2020-06-04 12:26:26.980115] Connection status: 2, cellular status: 2
[2020-06-04 12:26:26.986180] [DBG ][CELL]: Signal quality => Registering network
[2020-06-04 12:26:26.990051] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:26.992973] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:26.997116] [INFO][CELL]: AT RX ( 3): <cr><ln>+
[2020-06-04 12:26:27.003156] [INFO][CELL]: AT RX (31): CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:27.006000] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:27.013265] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:27.019123] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:27.023044] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:27.027004] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:27.032262] [INFO][CELL]: AT RX (14): <cr><ln>+CSQ: 99,99<cr>
[2020-06-04 12:26:27.037373] [INFO][CELL]: AT RX ( 7): <ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:27.042151] [DBG ][CELL]: callback: 4104, err: 0, data: -1
[2020-06-04 12:26:27.046119] Connection status: 2, cellular status: 2
[2020-06-04 12:26:27.049022] [INFO][CELL]: RSSI unknown
[2020-06-04 12:26:27.054008] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:27.055978] Unknown cellular status
[2020-06-04 12:26:27.060003] Connection status: 2, cellular status: 2
[2020-06-04 12:26:27.064052] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 12:26:27.066992] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:27.073160] [INFO][CELL]: AT RX (17): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>
[2020-06-04 12:26:27.081160] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 12:26:27.085180] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 12:26:27.090062] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 12:26:27.095204] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:27.097058] Unknown cellular status
[2020-06-04 12:26:27.101307] Connection status: 2, cellular status: 2
[2020-06-04 12:26:27.106184] [DBG ][CELL]: Automatic network registration
[2020-06-04 12:26:27.110044] [INFO][CELL]: AT TX ( 8): AT+COPS?
[2020-06-04 12:26:27.113436] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:27.119017] [INFO][CELL]: AT RX (12): <cr><ln>+COPS: 0<cr><ln>
[2020-06-04 12:26:27.124015] [INFO][CELL]: AT RX ( 6): <cr><ln>OK<cr><ln>
[2020-06-04 12:26:27.128126] [DBG ][CELL]: Registering network: retry 0/10
[2020-06-04 12:26:27.136036] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 0
[2020-06-04 12:26:27.138175] Unknown cellular status
[2020-06-04 12:26:27.141991] Connection status: 2, cellular status: 2
[2020-06-04 12:26:27.146253] [INFO][CELL]: Continue after 1 seconds
[2020-06-04 12:26:28.146297] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:28.149106] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:28.153107] [INFO][CELL]: AT RX ( 2): <cr><ln>
[2020-06-04 12:26:28.159034] [INFO][CELL]: AT RX (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:28.163288] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:28.168097] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:28.175041] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:28.179459] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:28.183093] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:28.189071] [INFO][CELL]: AT RX (17): <cr><ln>+CSQ: 99,99<cr><ln><cr><ln>
[2020-06-04 12:26:28.193231] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 12:26:28.198134] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 12:26:28.202090] Connection status: 2, cellular status: 2
[2020-06-04 12:26:28.205049] [INFO][CELL]: RSSI unknown
[2020-06-04 12:26:28.210257] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:28.212581] Unknown cellular status
[2020-06-04 12:26:28.216221] Connection status: 2, cellular status: 2
[2020-06-04 12:26:28.220096] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 12:26:28.223154] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:28.229503] [INFO][CELL]: AT RX (17): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>
[2020-06-04 12:26:28.236032] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 12:26:28.241205] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 12:26:28.246252] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 12:26:28.251124] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:28.253020] Unknown cellular status
[2020-06-04 12:26:28.257092] Connection status: 2, cellular status: 2
[2020-06-04 12:26:28.263075] [DBG ][CELL]: Registering network: retry 1/10
[2020-06-04 12:26:28.270030] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 1
[2020-06-04 12:26:28.272026] Unknown cellular status
[2020-06-04 12:26:28.276038] Connection status: 2, cellular status: 2
[2020-06-04 12:26:28.280027] [INFO][CELL]: Continue after 2 seconds
[2020-06-04 12:26:30.276409] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:30.280302] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:30.283108] [INFO][CELL]: AT RX ( 1): <cr>
[2020-06-04 12:26:30.289146] [INFO][CELL]: AT RX (31): <ln>+CGDCONT: 1,"IP","example.
[2020-06-04 12:26:30.293107] [INFO][CELL]: AT RX ( 2): co
[2020-06-04 12:26:30.296104] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:30.302133] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:30.310280] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:30.314345] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:30.316284] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:30.321271] [INFO][CELL]: AT RX ( 7): <cr><ln>+CSQ:
[2020-06-04 12:26:30.326286] [INFO][CELL]: AT RX (14): 99,99<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:30.332294] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 12:26:30.335176] Connection status: 2, cellular status: 2
[2020-06-04 12:26:30.338079] [INFO][CELL]: RSSI unknown
[2020-06-04 12:26:30.344148] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:30.346054] Unknown cellular status
[2020-06-04 12:26:30.349514] Connection status: 2, cellular status: 2
[2020-06-04 12:26:30.354192] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 12:26:30.357264] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:30.363416] [INFO][CELL]: AT RX (17): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>
[2020-06-04 12:26:30.370108] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 12:26:30.374121] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 12:26:30.380106] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 12:26:30.385144] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:30.387116] Unknown cellular status
[2020-06-04 12:26:30.391279] Connection status: 2, cellular status: 2
[2020-06-04 12:26:30.396339] [DBG ][CELL]: Registering network: retry 2/10
[2020-06-04 12:26:30.404115] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 2
[2020-06-04 12:26:30.406086] Unknown cellular status
[2020-06-04 12:26:30.409083] Connection status: 2, cellular status: 2
[2020-06-04 12:26:30.414090] [INFO][CELL]: Continue after 4 seconds
[2020-06-04 12:26:34.403545] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:34.407405] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:34.412228] [INFO][CELL]: AT RX (21): <cr><ln>+CGDCONT: 1,"IP","w
[2020-06-04 12:26:34.417181] [INFO][CELL]: AT RX (13): iththegrid.co
[2020-06-04 12:26:34.420214] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:34.426274] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:34.433232] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:34.437211] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:34.440205] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:34.447796] [INFO][CELL]: AT RX (21): <cr><ln>+CSQ: 99,99<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:34.452232] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 12:26:34.456409] Connection status: 2, cellular status: 2
[2020-06-04 12:26:34.459412] [INFO][CELL]: RSSI unknown
[2020-06-04 12:26:34.464268] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:34.466410] Unknown cellular status
[2020-06-04 12:26:34.470182] Connection status: 2, cellular status: 2
[2020-06-04 12:26:34.474215] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 12:26:34.478401] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:34.485368] [INFO][CELL]: AT RX (21): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:34.492248] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 12:26:34.497340] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 12:26:34.502251] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:34.505273] Unknown cellular status
[2020-06-04 12:26:34.508209] Connection status: 2, cellular status: 2
[2020-06-04 12:26:34.513291] [DBG ][CELL]: Registering network: retry 3/10
[2020-06-04 12:26:34.521443] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 3
[2020-06-04 12:26:34.523371] Unknown cellular status
[2020-06-04 12:26:34.527223] Connection status: 2, cellular status: 2
[2020-06-04 12:26:34.531278] [INFO][CELL]: Continue after 8 seconds
[2020-06-04 12:26:42.507801] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:42.510678] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:42.514590] [INFO][CELL]: AT RX ( 1): <cr>
[2020-06-04 12:26:42.520457] [INFO][CELL]: AT RX (31): <ln>+CGDCONT: 1,"IP","example.
[2020-06-04 12:26:42.524541] [INFO][CELL]: AT RX ( 2): co
[2020-06-04 12:26:42.527462] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:42.533482] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:42.540461] [INFO][CELL]: AT RX (28): m","0.0.0.0",0,0,0,0<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:42.544526] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:42.547824] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:42.553516] [INFO][CELL]: AT RX (16): <cr><ln>+CSQ: 99,99<cr><ln><cr>
[2020-06-04 12:26:42.558614] [INFO][CELL]: AT RX ( 5): <ln>OK<cr><ln>
[2020-06-04 12:26:42.563823] [DBG ][CELL]: callback: 4104, err: 0, data: 4098
[2020-06-04 12:26:42.566493] Connection status: 2, cellular status: 2
[2020-06-04 12:26:42.570447] [INFO][CELL]: RSSI unknown
[2020-06-04 12:26:42.575439] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:42.577590] Unknown cellular status
[2020-06-04 12:26:42.581521] Connection status: 2, cellular status: 2
[2020-06-04 12:26:42.585891] [INFO][CELL]: AT TX ( 9): AT+CGREG?
[2020-06-04 12:26:42.588643] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:42.594890] [INFO][CELL]: AT RX (17): <cr><ln>+CGREG: 2,4<cr><ln><cr><ln>
[2020-06-04 12:26:42.601616] [DBG ][CELL]: +CGREG: RegistrationUnknown, LAC -1, cell -1, RAT unknown
[2020-06-04 12:26:42.605623] [INFO][CELL]: AT RX ( 4): OK<cr><ln>
[2020-06-04 12:26:42.611532] [INFO][CELL]: Network registration (timeout 180000 ms)
[2020-06-04 12:26:42.616482] [DBG ][CELL]: callback: 4106, err: 0, data: 4098
[2020-06-04 12:26:42.618517] Unknown cellular status
[2020-06-04 12:26:42.622705] Connection status: 2, cellular status: 2
[2020-06-04 12:26:42.627506] [DBG ][CELL]: Registering network: retry 4/10
[2020-06-04 12:26:42.635511] [DBG ][CELL]: callback: CellularStateRetryEvent, err: 0, data: 4098, retrycount: 4
[2020-06-04 12:26:42.637486] Unknown cellular status
[2020-06-04 12:26:42.641500] Connection status: 2, cellular status: 2
[2020-06-04 12:26:42.646977] [INFO][CELL]: Continue after 16 seconds
[2020-06-04 12:26:50.155930] [DBG ][CELL]: AT OoB readable 1, len 0
[2020-06-04 12:26:50.162872] [INFO][CELL]: AT RX (32): <cr><ln>+CREG: 5,"FFFE","1905202", 7<cr><ln>
[2020-06-04 12:26:50.169705] [DBG ][CELL]: +CREG: RegisteredRoaming, LAC 65534, cell 26235394, E_UTRAN
[2020-06-04 12:26:50.174776] [DBG ][CELL]: callback: 4101, err: 0, data: 7
[2020-06-04 12:26:50.182945] Connection status: 2, cellular status: 32
[2020-06-04 12:26:50.183950] [DBG ][CELL]: callback: 4098, err: 0, data: 5
[2020-06-04 12:26:50.191386] [INFO][CELL]: Registering network => Attaching network
[2020-06-04 12:26:50.192775] Connection status: 2, cellular status: 12
[2020-06-04 12:26:50.199848] [DBG ][CELL]: callback: 4100, err: 0, data: 26235394
[2020-06-04 12:26:50.205260] Connection status: 2, cellular status: 24
[2020-06-04 12:26:50.212511] [INFO][CELL]: AT RX (32): <cr><ln>+CGREG: 5,"FFFE","1905202",7<cr><ln>
[2020-06-04 12:26:50.218277] [DBG ][CELL]: +CGREG: RegisteredRoaming, LAC 65534, cell 26235394, E_UTRAN
[2020-06-04 12:26:50.221679] [DBG ][CELL]: callback: 4098, err: 0, data: 5
[2020-06-04 12:26:50.227468] Connection status: 2, cellular status: 12
[2020-06-04 12:26:50.235758] [DBG ][CELL]: AT OoB done
[2020-06-04 12:26:50.235899] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:50.236631] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:50.240886] [INFO][CELL]: AT RX ( 1): <cr>
[2020-06-04 12:26:50.246274] [INFO][CELL]: AT RX (31): <ln>+CGDCONT: 1,"IP","example.
[2020-06-04 12:26:50.250984] [INFO][CELL]: AT RX ( 2): co
[2020-06-04 12:26:50.253137] [ERR ][CELL]: AT overflow
[2020-06-04 12:26:50.258949] [INFO][CELL]: AT ERR (32): +CGDCONT: 1,"IP","example.co
[2020-06-04 12:26:50.267090] [INFO][CELL]: AT RX (32): m","1.2.3.4",0,0,0,0<cr><ln><cr><ln>OK<cr>
[2020-06-04 12:26:50.270144] [INFO][CELL]: AT RX ( 1): <ln>
[2020-06-04 12:26:50.272766] [INFO][CELL]: AT TX ( 6): AT+CSQ
[2020-06-04 12:26:50.278042] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:50.280916] [INFO][CELL]: AT RX ( 2): <cr><ln>
[2020-06-04 12:26:50.286757] [INFO][CELL]: AT RX (19): +CSQ: 31,99<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:50.292870] [DBG ][CELL]: callback: 4104, err: 0, data: -1
[2020-06-04 12:26:50.295745] Connection status: 2, cellular status: 12
[2020-06-04 12:26:50.298992] [INFO][CELL]: RSSI -51 dBm
[2020-06-04 12:26:50.303885] [DBG ][CELL]: callback: 4106, err: 0, data: 4102
[2020-06-04 12:26:50.306010] Unknown cellular status
[2020-06-04 12:26:50.309765] Connection status: 2, cellular status: 12
[2020-06-04 12:26:50.315397] [INFO][CELL]: Attaching network (timeout 60000 ms)
[2020-06-04 12:26:50.318755] [INFO][CELL]: AT TX ( 9): AT+CGATT?
[2020-06-04 12:26:50.322752] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:50.326902] [INFO][CELL]: AT RX ( 4): <cr><ln>+C
[2020-06-04 12:26:50.332703] [INFO][CELL]: AT RX (15): GATT: 1<cr><ln><cr><ln>OK<cr><ln>
[2020-06-04 12:26:50.337665] [DBG ][CELL]: callback: 4102, err: 0, data: 1
[2020-06-04 12:26:50.341679] Connection status: 2, cellular status: 38
[2020-06-04 12:26:50.345846] [INFO][CELL]: AT TX (11): AT+CGDCONT?
[2020-06-04 12:26:50.351043] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:50.354867] [INFO][CELL]: AT RX ( 8): <cr><ln>+CGDCO
[2020-06-04 12:26:50.360939] [INFO][CELL]: AT RX (26): NT: 1,"IP","example.co
[2020-06-04 12:26:50.367745] [INFO][CELL]: AT RX (32): m","1.2.3.4",0,0,0,0<cr><ln><cr><ln>OK<cr>
[2020-06-04 12:26:50.371786] [INFO][CELL]: AT RX ( 1): <ln>
[2020-06-04 12:26:50.376100] [INFO][CELL]: Found PDP context 1
[2020-06-04 12:26:50.379735] [INFO][CELL]: CellularContext PPP connect
[2020-06-04 12:26:50.383849] [INFO][CELL]: AT TX ( 9): ATD*99***
[2020-06-04 12:26:50.386751] [INFO][CELL]: AT TX ( 1): 1
[2020-06-04 12:26:50.390879] [INFO][CELL]: AT TX ( 1): #
[2020-06-04 12:26:50.393745] [INFO][CELL]: AT TX ( 1): <cr>
[2020-06-04 12:26:50.402874] [INFO][CELL]: AT RX ( 3): <cr><ln>C
[2020-06-04 12:26:50.407740] [INFO][CELL]: AT RX (18): ONNECT 150000000<cr><ln>
[2020-06-04 12:26:50.413065] [DBG ][CELL]: ppp_status_cb: event 0, ptr 3
[2020-06-04 12:26:50.416726] [DBG ][CELL]: callback: 0, ptr: 3
[2020-06-04 12:26:50.423304] [DBG ][CELL]: process_oob, filehandle is not usable, return...
[2020-06-04 12:26:51.558997] [DBG ][CELL]: ppp_status_cb: event 0, ptr 1
[2020-06-04 12:26:51.561999] [DBG ][CELL]: callback: 0, ptr: 1
[2020-06-04 12:26:51.565817] Connection status: 3, cellular status: 38
[2020-06-04 12:26:51.587753] Global IP received but waiting for local IP (31912 ms)
[2020-06-04 12:26:51.690005] Connected as 1.2.3.4 in 32016 ms
[2020-06-04 12:26:51.694874] [INFO][CELL]: CellularContext set blocking 1
[2020-06-04 12:26:51.696744] Connected to network!
[2020-06-04 12:26:51.697750] RSSI: -51
[2020-06-04 12:26:51.699914] Test message sent (6)
[2020-06-04 12:26:51.700002]
[2020-06-04 12:26:51.700030]
[2020-06-04 12:26:52.003029] Resolved IP address of platform 'x.x.x.x'
[2020-06-04 12:26:52.007904] [INFO][TLSW]: Starting TLS handshake with (null)
@jdbruijn That sounds weird, build cleanup could help... at least to get rid of any excessive mbed_config.h files.
Good it's working now. Effectively clear() should do pretty much the same as your workaround, i.e. set PDP ID 1 APN. Another possible fix could be to use the next but the initial context, but I don't know if that's in any way better.
AriParkkila
on 4 Jun 2020
@AriParkkila Okay, thanks for explaining. So do you recommend me just keep using the MBED_CONF_CELLULAR_CLEAR_ON_CONNECT (cellular.clear-on-connect) configuration?
Also, do you have any idea why this issue appears on the SARA-R412M/R410M and not on the SARA-G350?
As far as my issues in this ticket: both are now resolved as far as I consider. The issue with MBED_CONF_CELLULAR_CLEAR_ON_CONNECT looks to be on my side as its just a preprocessor macro so should work just fine. There still is the issue with the modem thinking it has sent something while I don't receive anything so as far as I'm considered we can either keep this issue open to track that or you can track it internally/create a different issue. In case of the latter, this issue may be closed.
jdbruijn
on 4 Jun 2020
@jdbruijn CID=1 probably needs clear-flag, but could probably also try to use some other CID. It should work without clear, so it could be a less "obstructive" in some cases, see e.g. context-id-offset
The difference between R412M/R410M and G350 could be that one is not saving the APN values in NVM when switching off the modem, or simply because G350 could be in GPRS network without combined attached and initial context... It's hard to say for sure as I'm not a specialist with these modems.
The issue with the modem thinking it has sent something and actually didn't, sounds like a modem bug.
AriParkkila
on 4 Jun 2020
Thank you for raising this detailed GitHub issue. I am now notifying our internal issue triagers.
Internal Jira reference: https://jira.arm.com/browse/IOTOSM-2222
ciarmcom
on 2 Oct 2020
Was this page helpful?
0 / 5 - 0 ratings
Related issues
ghost
路
4Comments
sarahmarshy
路
4Comments
cesarvandevelde
路
4Comments
neilt6
路
4Comments
toyowata
路
4Comments