Cellular.command freezes electron when cloud disconnected

I am having serious problems with my electrons, when they lose the cloud connection due to celluar signal issues.
I happens out in the field, but can be reproduced by disconnecting the GSM antenna.
The LED starts flashing cyan (indicating cell still connected, cloud disconnected)
When I do a Cellular.command(10000, “AT+CFUN=15\r\n”); the electron is not responding anymore, the loop stops. The device gets restarted by the watchdog and then runs normally until the next disconnect…
In most cases, it will not reconnect to the cloud even after the signal quality is fine again…

Here’s some code sample:

SYSTEM_MODE(SEMI_AUTOMATIC);
SYSTEM_THREAD(ENABLED);

unsigned long CloudConnOK = 0;
ApplicationWatchdog wd(69000, watchdogReboot);
retained byte ResetReason = 0;

void setup()
{
			Particle.connect();
}

void loop()
{
 if (Particle.connected()) CloudConnOK=millis();
  if ((millis() - CloudConnOK) > 60000) {
		Serial5.println("NOGSM1! /m:" + String(millis()) + "/CellReady:" + String(Cellular.ready())+"/PartCon:" + String(Particle.connected()));
		Serial5.println("A1");
		Serial5.println("A2");
		Cellular.command(10000, "AT+CFUN=15\r\n");
		Serial5.println("A3");
		delay(1000);
		Serial5.println("A4");
		Particle.process();
	}
}

void watchdogReboot()
{
    ResetReason = 99;
	System.reset();
}

When it happens, Cellular.ready() = true, Parcticle.connected()=false
The serial output stops at “A2”… so the cellular.command is clearly the culprit. It does not return even after the 10000ms.

All the USB log shows is this:

0000194681 [comm.dtls] WARN: mbedtls_ssl_write returned ffffffff
0000194681 [comm.protocol] ERROR: Event loop error 20
0000194682 [system] WARN: Communication loop error, closing cloud socket
0000194682 [system] INFO: Cloud: disconnecting
0000194683 [system] INFO: Cloud: disconnected
0000194783 [system] INFO: Cloud: connecting
0000216688 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000216688 [system] ERROR: Failed to load session data from persistent storage
0000216690 [system] INFO: Discarding session data
0000306798 [system] ERROR: Unable to resolve IP for 31xxxx0135363038xxx739.udp.particle.io (1)
0000306798 [system] ERROR: Failed to determine server address
0000306799 [system] WARN: Cloud socket connection failed: -230
0000307800 [system] WARN: Internet Test Failed!
0000307800 [system] WARN: Resetting WLAN due to 2 failed connect attempts
0000307800 [system] WARN: Handling cloud error: 2

So far I have tried the following firmware releases:
0.7.0
0.8.0rc12
1.0.0
1.0.1
1.1.0
1.1.1-rc1
1.2.1-rc3
All show the same behavior.

With 1.0.0 and later you should not attempt to manage the cloud connection in that way. Device OS will automatically power cycle the modem after 5 minutes of attempting to connect. You may still want to see if you’ve failed to connect for several minutes and go back to sleep if you want to preserve battery power.

What is happening is that the modem is protected by a mutex since only one thread can use it at a time. You’re most likely running into a situation where the modem is locked by the system thread, so Cellular.command is blocked from executing until released, but since you can’t connect, it’s not getting released.

If you really must reset the modem manually, you should set a flag in retained memory, System.reset() the device in SEMI_AUTOMATIC mode, turn the modem on, and issue the AT+CFUN=16 then before connecting to the cloud. But this shouldn’t be necessary because Device OS does this automatically after 5 minutes of failing to connect.

Also 60 seconds is not enough time to allow the modem to connect.

Thanks. I will implement your advice and let you know if it reduces the Watchdog reset events.

Is there a way my code can modify this 5 minute timer? I’d like to reduce it to about 3 minutes.
These disconnects usually happen when the electron moves through an area with poor cellular service.
I have noticed, that in these cases, when I manually reset the device it usually reconnects within 30 seconds. So there is something wrong with the automatic reconnect. It only gets triggerred properly when the unit resets.

The 5 minute connection timer is not configurable, unless you modify the Device OS (system firmware).

OK. I did some testing and maybe found something out about the reconnecting issues.
I have enable the “TRACE” Logging on serial.
Here’s what happens when I do a “Cellular.disconnect()” wait a second or ten and then do a “Cellular.connect()”:

0000042364 [system] INFO: Cloud: disconnecting
0000042364 [system] TRACE: Close Attempt
socketClose(0)
    42.362 AT send      12 "AT+USOCL=0\r\n"
    42.628 AT read OK    6 "\r\nOK\r\n"
socketFree(0)
0000042632 [system] TRACE: socket_close()=success
0000042632 [system] INFO: Cloud: disconnected

[ Modem::deactivate ] = = = = = = = = = = = = =
    42.630 AT send      14 "AT+UPSDA=0,4\r\n"
    43.827 AT read OK    6 "\r\nOK\r\n"

[ Modem::detach ] = = = = = = = = = = = = = = =
    43.827 AT send      12 "AT+CGATT=0\r\n"
    44.821 AT read OK    6 "\r\nOK\r\n"
0000044825 [system] INFO: Sim Ready
0000044826 [system] INFO: ARM_WLAN_WD 1

[ Modem::register ] = = = = = = = = = = = = = =
    44.822 AT send      12 "AT+CGREG=2\r\n"
    44.824 AT read  +   13 "\r\n+CGREG: 0\r\n"
    44.825 AT read  +   14 "\r\n+CIEV: 9,1\r\n"
CIEV matched: 9,1
    44.828 AT read OK    6 "\r\nOK\r\n"
    44.828 AT send      11 "AT+CREG=2\r\n"
    44.832 AT read OK    6 "\r\nOK\r\n"
    44.832 AT send      10 "AT+CREG?\r\n"
    44.839 AT read  +   33 "\r\n+CREG: 2,5,\"AEA8\",\"19CD02D\",4\r\n"
    44.842 AT read OK    6 "\r\nOK\r\n"
    44.842 AT send      11 "AT+CGREG?\r\n"
    44.847 AT read  +   15 "\r\n+CGREG: 2,0\r\n"
    44.848 AT read OK    6 "\r\nOK\r\n"
    44.848 AT send       4 "AT\r\n"
    44.851 AT read OK    6 "\r\nOK\r\n"
    44.851 AT send      10 "AT+COPS?\r\n"
    44.962 AT read  +   26 "\r\n+COPS: 0,0,\"o2 - de\",2\r\n"
    44.965 AT read OK    6 "\r\nOK\r\n"
    44.965 AT send       8 "AT+CSQ\r\n"
    44.970 AT read  +   14 "\r\n+CSQ: 19,3\r\n"
    44.971 AT read OK    6 "\r\nOK\r\n"
    44.971 AT send      10 "AT+URAT?\r\n"
    44.976 AT read  +   14 "\r\n+URAT: 1,2\r\n"
    44.977 AT read OK    6 "\r\nOK\r\n"
    44.977 AT send      10 "AT+CREG?\r\n"
    44.984 AT read  +   33 "\r\n+CREG: 2,5,\"AEA8\",\"19CD02D\",4\r\n"
    44.987 AT read OK    6 "\r\nOK\r\n"
    44.987 AT send      11 "AT+CGREG?\r\n"
    44.992 AT read  +   15 "\r\n+CGREG: 2,0\r\n"
    44.993 AT read OK    6 "\r\nOK\r\n"
    44.993 AT send       4 "AT\r\n"
    44.996 AT read OK    6 "\r\nOK\r\n"
    44.996 AT send      10 "AT+COPS?\r\n"
    45.106 AT read  +   26 "\r\n+COPS: 0,0,\"o2 - de\",2\r\n"
    45.109 AT read OK    6 "\r\nOK\r\n"
    45.109 AT send       8 "AT+CSQ\r\n"
    45.114 AT read  +   14 "\r\n+CSQ: 19,3\r\n"
    45.115 AT read OK    6 "\r\nOK\r\n"
    60.119 AT send      10 "AT+CREG?\r\n"
    61.120 AT send      11 "AT+CGREG?\r\n"
    61.263 AT read  +   33 "\r\n+CREG: 2,5,\"AEA8\",\"19CD02D\",4\r\n"
    61.266 AT read OK    6 "\r\nOK\r\n"
    61.266 AT send       4 "AT\r\n"
    61.270 AT read OK    6 "\r\nOK\r\n"
    61.270 AT send      10 "AT+COPS?\r\n"
    61.393 AT read  +   26 "\r\n+COPS: 0,0,\"o2 - de\",2\r\n"
    61.394 AT read OK    6 "\r\nOK\r\n"
    61.394 AT send       8 "AT+CSQ\r\n"
    61.399 AT read  +   14 "\r\n+CSQ: 18,2\r\n"
    61.400 AT read OK    6 "\r\nOK\r\n"
    76.404 AT send      10 "AT+CREG?\r\n"
    77.405 AT send      11 "AT+CGREG?\r\n"
    77.759 AT read  +   33 "\r\n+CREG: 2,5,\"AEA8\",\"19CD02D\",4\r\n"
    77.762 AT read OK    6 "\r\nOK\r\n"
    77.762 AT send       4 "AT\r\n"
    77.765 AT read OK    6 "\r\nOK\r\n"
    77.765 AT send      10 "AT+COPS?\r\n"
    77.888 AT read  +   26 "\r\n+COPS: 0,0,\"o2 - de\",2\r\n"
    77.891 AT read OK    6 "\r\nOK\r\n"
    77.891 AT send       8 "AT+CSQ\r\n"
    77.896 AT read  +   14 "\r\n+CSQ: 19,2\r\n"
    77.897 AT read OK    6 "\r\nOK\r\n"

Here its basically stuck. A cellular.connect() will NOT connect to the network. No AT commands are issued after sending the cellular.connect().
When you send a Cellular.command at this point, the electron freezes, loop() gets no longer called.

The device can be reconnected by Calling cellular.off() followed by cellular.on() or cellular.connect().
Or you can wait for the 5 Minute timer to kick in.
In both cases, the modem will be powered down (AT+CPWROFF) and restarted.

To me this isn’t working as expected. maybe you can shed some light into this…
Thanks!

I did some more testing and can reproduce the issue with some test code. ( I apologize for the lengthy code, I just used my production code and stripped it down somewhat)

#include "Particle.h"
#include "Serial4/Serial4.h"
#include "Serial5/Serial5.h"
#include "math.h"
#include "cellular_hal.h"
#define SDS_DATA_length 6
#define SER_OUT_SIZE 256
#define MAX_PACK_LEN 255
#define MAX_TEXT_LEN 600
#define MAX_TEXT_LEN_RAW 800
#define MAX_TEXT_LENQ 900
SYSTEM_MODE(SEMI_AUTOMATIC);
SYSTEM_THREAD(ENABLED);
//SYSTEM_MODE(MANUAL);
STARTUP(System.enableFeature(FEATURE_RESET_INFO));
// ALL_LEVEL, TRACE_LEVEL, DEBUG_LEVEL, INFO_LEVEL, WARN_LEVEL, ERROR_LEVEL, PANIC_LEVEL, NO_LOG_LEVEL
SerialLogHandler logHandler(LOG_LEVEL_ALL);
void riInterrupt(void);

char FWVERSION[] = "e2.0.9 20190708";
//retained uint8_t publishQueueRetainedBuffer[2048];
//PublishQueueAsync publishQueue(publishQueueRetainedBuffer, sizeof(publishQueueRetainedBuffer));

int WebMessage(String arg);
void setBatOFF();
void SetupCellAPN();
int CellCallbackNull(int, const char *, int, char *);
int phoneCallback(int, const char *, int, char *);
void fullReboot();
void watchdogReboot();
//
PMIC pmic;
String INFOstr = "X";
char INFOchar[620];
volatile bool DoPublishInput = false;	
unsigned int CloudConnTS = 16;
unsigned int CloudConnOK = 18;
int INGRMN_length;
int IN_length;
int INtmpPOS;
int DATA_length;
byte INGRMN[MAX_TEXT_LEN];
byte IN[MAX_TEXT_LEN_RAW];
byte INtmp[MAX_TEXT_LEN_RAW];
unsigned long time5;
unsigned long timer5s = 0;
volatile int IND3 = 0;			
int OUTD7;						
byte OUTD5 = LOW;                 // Status Relais 1 / D5
byte OUTD6 = HIGH;                 // Status Relais 2 / D6
bool DebugMode = true;				
int KEEPALIVE = 115;
int CELLstate = LOW;
char szReturn[32] = "";
char SMSlastNum[18] = "";
char SMSlastText[160] = "";
uint8_t SMSprocessed = 0;
bool SMSisNext = false;
byte cellAPNID = 0;
String cellAPN = "iotde.telefonica.com";
int SMSmaxIndex = 1;
byte BATena = 0;
byte SMSena = 1;
uint8_t LastMsgType = 0;

//ApplicationWatchdog wd(369000, watchdogReboot); //6 Min, 9 Sek
ApplicationWatchdog wd(129000, watchdogReboot); //2 Min, 9 Sek
retained uint8_t ResetReason = 0;

int CellCallbackNull(int type, const char *buf, int len, char *param)
{
    if (DebugMode) {
    	Serial5.print("CELL Callback: ");
    	Serial5.write((const uint8_t *)buf, len);
    	Serial5.println();
    	Serial5.print("Type: ");
    	Serial5.println(type);
    }
	//return RESP_OK;
	return WAIT;
}

int phoneCallback(int type, const char *buf, int len, char *param)
{
    if (DebugMode) {
    	Serial5.print("Phone Callback ");
    	Serial5.print(len);
    	Serial5.print(":");
    	Serial5.write((const uint8_t *)buf, len);
    	Serial5.println();
    	Serial5.print("Type: ");
    	Serial5.println(type);
    	Serial5.println("B: " + String(buf[0], DEC) + " " + String(buf[1], DEC));
    }
	if (strncmp(&buf[2], "+C", 2) != 0) {
		if (type == 0 && buf[0] != 13 && len > 40) {
			//Unkown type mit Text
			SMSisNext = true;
			if (DebugMode) Serial5.println("Evtl SDS...");
		}
	}

	if (strncmp(&buf[2], "+UU", 3) == 0) {
		CELLstate = LOW;
		if (DebugMode) Serial5.println("Exit");
		return RESP_OK;
	}
	if (SMSisNext) {
		SMSisNext = false;
		strncpy(SMSlastText, &buf[0], len);
		SMSlastText[len] = 0;
		SMSprocessed = 1;
		LastMsgType = 2;
	}
	if (strncmp(&buf[2], "+CMGL:", 6) == 0) {
		if (DebugMode) Serial5.write((const uint8_t *)&buf[2], len - 2);
		char szState[32];
		char szPhoneNumber[18];
		sscanf(&buf[11], "%[^/','],%[^/','],%s", szState, szPhoneNumber);

		SMSmaxIndex++;
		strcpy(SMSlastNum, &szPhoneNumber[1]);
		SMSlastNum[strlen(SMSlastNum) - 1] = 0;
		if (strcmp("+491727245855", SMSlastNum) == 0) {
			if (DebugMode) Serial5.println("AUTH SMS detected");

			//isCallRecognized = true;    
		}
		SMSisNext = true;
	}
	if (strncmp(&buf[2], "+CMGR:", 6) == 0) {
		if (DebugMode) Serial5.write((const uint8_t *)&buf[2], len - 2);

		char szState[32];
		char szPhoneNumber[18];
		sscanf(&buf[9], "%[^/','],%[^/','],%s", szState, szPhoneNumber);

		SMSmaxIndex++;
		strcpy(SMSlastNum, &szPhoneNumber[1]);
		SMSlastNum[strlen(SMSlastNum) - 1] = 0;
		if (strcmp("+441227241234", SMSlastNum) == 0) {
			if (DebugMode) Serial5.println("AUTH SMS detected");

			//isCallRecognized = true;    
		}
		SMSisNext = true;
	}

	CELLstate = LOW;
	return WAIT;
}

void SetupCellAPN()
{
		cellular_credentials_set("TM", "", "", NULL);
		cellAPN = "ThingsMobile";
		KEEPALIVE = 19;
	Particle.keepAlive(KEEPALIVE);
}
void setup()
{
	pinMode(D5, OUTPUT);
	pinMode(D6, OUTPUT);
	pinMode(D7, OUTPUT);
	digitalWrite(D7, LOW);
	OUTD7 = LOW;
	pinMode(D2, INPUT_PULLUP);
	pinMode(D3, INPUT_PULLDOWN);
	Particle.function("Message", WebMessage);
	Particle.function("SerOut", SerOut2);
	Particle.variable("info", INFOchar);
	Serial1.begin(9600);
	int lbaud = 38400;
	Serial4.begin(38400);
	Serial5.begin(38400);
	//InitEEPROM();
	setBatOFF();
	digitalWrite(D5, OUTD5);
	digitalWrite(D6, OUTD6);
    SetupCellAPN();
	delay(200);
    if (SMSena == 1) {
    delay(300);
    	Cellular.command(2000, "AT+CMGF=1\r\n");
    	Cellular.command(2000, "AT+CSCS=\"8859-1\"\r\n");
    }
	time5 = millis();
	if (DebugMode) Serial5.println("Get Cloud Ready...");
	Cellular.setListenTimeout(60);
		if (DebugMode) Serial5.println("Start Connect...");
		//Particle.keepAlive(2 * 60 - 1);
		Particle.keepAlive(KEEPALIVE);
		Particle.connect();
	if (DebugMode) Serial5.println("Setup Completed...");
	if (SMSena == 1) {
    	pinMode(RI_UC, INPUT_PULLUP);
    	attachInterrupt(RI_UC, riInterrupt, CHANGE);
	}
	CELLstate = LOW;
    Particle.process();
}

void loop()
{
  	if (CELLstate == HIGH) {
		//Cellular.command(phoneCallback, szReturn, 10000, szCommand);
		ResetReason = 31;
		if (DebugMode) Serial5.println("Receive SMS...");
		//delay(100);
		//Cellular.command(phoneCallback, szReturn, 12000, "AT+CMGR=1\r\n");
		Cellular.command(phoneCallback, szReturn, 12000, "AT+CMGL\r\n");
		CELLstate = LOW;
		if (SMSmaxIndex > 1) {
	        ResetReason = 32;
			if (DebugMode) Serial5.println("DELETE ALL");
			Cellular.command(CellCallbackNull, szReturn, 5000, "AT+CMGD=1,4\r\n");
			SMSmaxIndex = 1;
		}
		ResetReason = 2;
	}
	if (SMSprocessed == 1) {
	    if (DebugMode) {
    		Serial5.print("SMS Received from ");
	    	Serial5.println(SMSlastNum);
		    Serial5.print("Text: ");
		    Serial5.println(SMSlastText);
		    Serial5.println(strlen(SMSlastText));
	    }
		SMSprocessed = 0;
		if (strlen(SMSlastText) > 2) {
			//strncpy((char*)IN, &SDSlastText, strlen(SDSlastText));
			strcpy((char *)IN, SMSlastText);
			//strcat
			IN_length = strlen(SMSlastText);
			if (Particle.connected())
				Particle.publish("Info", SMSlastText, 300, PRIVATE);
		}
	}
	while (Serial4.available()) {
		int inByte = Serial4.read();
	}
    
	while (Serial1.available()) {
		int inByte = Serial1.read();
	}

	while (Serial.available()) {
		int inSer = Serial.read();
			Serial4.write(inSer);
	}
	while (Serial5.available()) {
		int inSer5 = Serial5.read();
    		if (DebugMode) { 
        		if (inSer5 == 49) {
        		    // 1
        			Particle.disconnect();
        			Serial5.println("Particle Disconnect");
        		}
        		if (inSer5 == 50) {
        		    // 2
        			Particle.connect();
        			Serial5.println("Particle Connect");
        		}
        		if (inSer5 == 51) {
        		    // 3
        			Cellular.disconnect();
        			Serial5.println("Cellular Disconnect");
        		}
        		if (inSer5 == 52) {
        		    // 4
        			Cellular.connect();
        			Serial5.println("Cellular Connect");
        		}
        		if (inSer5 == 53) {
        		    // 5
        			Cellular.off();
        			Serial5.println("Cellular OFF");
        		}
        		if (inSer5 == 54) {
        			// 6
        			Cellular.on();
        			Serial5.println("Cellular ON");
        		}
        		if (inSer5 == 55) {
        			//cellular_credentials_set("iotde.telefonica.com", "", "", NULL);
        			Serial5.print("Test AT CMD...");
        			Cellular.command(2000, "AT+CSCS=\"8859-1\"\r\n");
        			Serial5.println("DONE");
        		}
        		if (inSer5 == 56) {
        			Serial5.print("CFUN=15");
        			Cellular.command(30000, "AT+CFUN=15\r\n");
        			Serial5.println(" DONE");
        		}
        		if (inSer5 == 57) {
        		    // 9a
        			Serial5.print("CFUN=16");
        			Cellular.command(30000, "AT+CFUN=16\r\n");
        			Serial5.println(" DONE");
        		}
        		if (inSer5 == 99) {
        		    //c
        			Serial5.print("CGATT=1");
        			Cellular.command(5000, "AT+GATT=1\r\n");
        			Serial5.println(" DONE");
        		}
        		if (inSer5 == 67) {
        		    //C
        			Serial5.print("UPSDA=0,3");
        			Cellular.command(5000, "AT+UPSDA=0,3\r\n");
        			Serial5.println(" DONE");
        		}
        
        		if (inSer5 == 48) {
        			Serial5.println("CellConnecting:" + String(Cellular.connecting()));
        			Serial5.println("CellReady:" + String(Cellular.ready()));
        			Serial5.println("Particle:" + String(Particle.connected()));
        			CellularSignal sig = Cellular.RSSI();
        			Serial5.println("RSSI: " + String(sig.rssi) + "/" + String((sig.qual + 1) * 2) + "%");
        		}
        		if (inSer5 == 103) {
        			// g
        		}
    		}
	}

	if (millis() - time5 > 5000 || millis() < time5) {
		timer5s++;
		wd.checkin();
		if (DebugMode) Serial5.println("Loop. Millis=" + String(millis()) + "/CellReady:" + String(Cellular.ready())+"/PartCon:" + String(Particle.connected()));
		time5 = millis();
		Particle.process();
	}
}

void riInterrupt()
{
	CELLstate = digitalRead(RI_UC);
}

void setBatOFF() {
    pmic.begin();
    pmic.disableCharging();
	pmic.disableBATFET();
    pmic.disableWatchdog();
	byte DATA = pmic.readChargeTermRegister();
	DATA &= 0b11000110;
	Wire3.beginTransmission(PMIC_ADDRESS);
	Wire3.write(CHARGE_TIMER_CONTROL_REGISTER);
	Wire3.write(DATA);
	Wire3.endTransmission(true);
}


void fullReboot()
{
	Cellular.command(20000, "AT+CFUN=16\r\n");
	delay(1000);
	SetupCellAPN();
	Cellular.off();
	delay(1000);
	System.reset();
}

void watchdogReboot()
{
    ResetReason += 98;
	System.reset();
}

int WebMessage(String arg)
{
	byte bTEXT[MAX_TEXT_LEN];
	arg.getBytes(bTEXT, MAX_TEXT_LEN);
	snprintf(INFOchar,620,"%s",(const char*)arg);
	return strlen(arg);
}

int SerOut2(String arg)
{
	Serial4.println(arg);
	return strlen(arg);
}

You can connect to Serial5 and after the device is successfully connected press the “3” key issuing a Cellular.disconnect(). If you then press “7” sending an AT Command to the modem, the loop stops running.
After Two minutes the configured watchdog restarts the device.
If you run this code on your electron you will probably have to change the APN settings.

The usb log looks like this until it freezes:

[ ElectronSerialPipe::begin ] pipeTx=0 pipeRx=0
[ Modem::powerOn ] = = = = = = = = = = = = = =
[ Modem::init ] = = = = = = = = = = = = = = =0000006169 [system] INFO: Sim Ready
0000006169 [system] INFO: ARM_WLAN_WD 1

[ Modem::register ] = = = = = = = = = = = = = =
[ Modem::cancel ] = = = = = = = = = = = = = = =
[ Modem::resume ] = = = = = = = = = = = = = = =
[ Modem::powerOff ] = = = = = = = = = = = = = =[ ElectronSerialPipe::end ] pipeTx=0 pipeRx=0[ ElectronSerialPipe::begin ] pipeTx=0 pipeRx=0
[ Modem::powerOn ] = = = = = = = = = = = = = =
[ Modem::init ] = = = = = = = = = = = = = = =0000074631 [system] WARN: Resetting WLAN due to WLAN_WD_TO()

[ Modem::powerOff ] = = = = = = = = = = = = = =[ ElectronSerialPipe::end ] pipeTx=0 pipeRx=0[ ElectronSerialPipe::begin ] pipeTx=0 pipeRx=0
[ Modem::powerOn ] = = = = = = = = = = = = = =
[ Modem::init ] = = = = = = = = = = = = = = =0000091041 [system] INFO: Sim Ready
0000091041 [system] INFO: ARM_WLAN_WD 1

[ Modem::register ] = = = = = = = = = = = = = =
[ Modem::join ] = = = = = = = = = = = = = = = =0000099030 [system] INFO: ARM_WLAN_WD 2
0000099030 [system] INFO: CLR_WLAN_WD 1, DHCP success
0000099030 [system] INFO: Cloud: connecting
0000099033 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000099033 [system] INFO: Loaded cloud server address and port from session data
0000099274 [system] TRACE: Connection attempt to 18.206.150.141:5684
0000099274 [system] INFO: Cloud socket connected
0000099276 [system] INFO: Starting handshake: presense_announce=0
0000099276 [comm.protocol.handshake] INFO: Establish secure connection
0000099296 [comm.dtls] WARN: session has 0 uses
0000099304 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=0
0000099306 [comm.dtls] INFO: out_ctr 0,1,0,0,0,0,0,65, next_coap_id=39
0000099306 [comm.dtls] INFO: app state crc: cached: 4947c0ce, actual: 4947c0ce
0000099308 [comm.dtls] WARN: skipping hello message
0000099308 [comm.dtls] INFO: restored session from persisted session data. next_msg_id=57
0000099310 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 2
0000099310 [comm.protocol.handshake] INFO: resumed session - not sending HELLO message
0000099312 [comm.coap] TRACE: sending message id=3a
0000099464 [system] INFO: Send spark/device/last_reset event
0000099464 [comm.coap] TRACE: sending message id=3b
0000099617 [comm.coap] TRACE: sending message id=3c
0000099769 [comm.coap] TRACE: sending message id=3d
0000099921 [system] INFO: Send subscriptions
0000099921 [comm.coap] TRACE: sending message id=3e
0000100071 [comm.coap] TRACE: sending message id=3f
0000100225 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000100225 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000100227 [comm] INFO: Sending TIME request
0000100227 [comm.coap] TRACE: sending message id=40
0000100388 [system] INFO: Cloud connected
0000101083 [system] TRACE: received 33
0000101083 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000101083 [comm.coap] TRACE: recieved ACK for message id=3a
0000101085 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000101085 [comm.protocol] INFO: message id 58 complete with code 0.00
0000101087 [comm.protocol] INFO: rcv'd message type=13
0000101210 [system] TRACE: received 33
0000101210 [comm.coap] TRACE: recieved ACK for message id=3c
0000101210 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000101212 [comm.protocol] INFO: message id 60 complete with code 0.00
0000101212 [comm.protocol] INFO: rcv'd message type=13
0000101337 [system] TRACE: received 33
0000101337 [comm.coap] TRACE: recieved ACK for message id=3d
0000101337 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000101339 [comm.protocol] INFO: message id 61 complete with code 0.00
0000101339 [comm.protocol] INFO: rcv'd message type=13
0000101464 [system] TRACE: received 33
0000101464 [comm.coap] TRACE: recieved ACK for message id=3e
0000101464 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000101466 [comm.protocol] INFO: message id 62 complete with code 0.00
0000101466 [comm.protocol] INFO: rcv'd message type=13
0000101591 [system] TRACE: received 33
0000101591 [comm.coap] TRACE: recieved ACK for message id=3f
0000101591 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000101593 [comm.protocol] INFO: message id 63 complete with code 0.00
0000101593 [comm.protocol] INFO: rcv'd message type=13
0000101724 [system] TRACE: received 39
0000101724 [comm.coap] TRACE: recieved ACK for message id=40
0000101724 [comm.protocol] TRACE: Reply recieved: type=2, code=69
0000101726 [comm.protocol] INFO: message id 64 complete with code 2.05
0000101726 [comm.protocol] INFO: Received TIME response: 1563023186
0000101728 [comm.protocol] INFO: rcv'd message type=12
0000106231 [system] TRACE: received 33
0000106231 [comm.coap] TRACE: recieved ACK for message id=3b
0000106231 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000106233 [comm.protocol] INFO: message id 59 complete with code 0.00
0000106233 [comm.protocol] INFO: rcv'd message type=13
0000112155 [system] INFO: Cloud: disconnecting
0000112155 [system] TRACE: Close Attempt
0000112421 [system] TRACE: socket_close()=success
0000112421 [system] INFO: Cloud: disconnected

[ Modem::deactivate ] = = = = = = = = = = = = =
[ Modem::detach ] = = = = = = = = = = = = = = =0000113818 [system] INFO: Sim Ready
0000113818 [system] INFO: ARM_WLAN_WD 1

[ Modem::register ] = = = = = = = = = = = = = =

To me this is a serious issue. I suspect this not only happens when send a command to the modem but in some cases when the firmware checks on the modem as well (signal, etc.) because some devices out in the field ocassionally reboot due to the watchdog and it’s usually the ones with poor cellular reception.

I’m having the same issue here as well when using SYSTEM_MODE(SEMI_AUTOMATIC); and
SYSTEM_THREAD(ENABLED);

Edit: I just tried this. If you do semiautomatic or manual in addition to the system thread, you’ll run into crashes. Maybe because the system thread is also trying to handle the cellular at the same time and maybe they are not meant to work together? Just an assumption.