Skip to content

Commit

Permalink
[gen2][electron] modem brownout or unexpected reset causes system to …
Browse files Browse the repository at this point in the history
…think it still is connected [ch64465]
  • Loading branch information
technobly committed Oct 15, 2020
1 parent 6edbe27 commit a8ed2bd
Show file tree
Hide file tree
Showing 3 changed files with 179 additions and 43 deletions.
163 changes: 121 additions & 42 deletions hal/src/electron/modem/mdm_hal.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,7 @@ std::recursive_mutex mdm_mutex;
#define MAX_SIZE 1024 //!< max expected messages (used with RX)
#define USO_MAX_WRITE 1024 //!< maximum number of bytes to write to socket (used with TX)
#define MDM_URC_POLL_INTERVAL_MS (1000) //!< URC poll interval
#define MDM_C_REG_POLL_INTERVAL_MS (30000) //!< CREG/CGREG/CEREG poll interval to check for unexpected modem reset
#define MDM_SOCKET_SEND_RETRIES_R4_BUG (3)

// ID of the PDP context used to configure the default EPS bearer when registering in an LTE network
Expand All @@ -74,28 +75,28 @@ std::recursive_mutex mdm_mutex;
#define USOST_TIMEOUT ( 10 * 1000) /* 10s for R4, 1s for U2/G3, changed to 40s due to R410 firmware */
#define USOST_TIMEOUT_R4 ( 40 * 1000) /* L0.0.00.00.05.08,A.02.04 background DNS lookup and other factors */
#define USORF_TIMEOUT ( 10 * 1000) /* FIXME: 1s for R4/U2/G3, but longer timeouts required in deployments */
#define CGATT_TIMEOUT (180 * 1000)
#define CEDRXS_TIMEOUT ( 10 * 1000)
#define CEER_TIMEOUT ( 10 * 1000)
#define CEREG_TIMEOUT ( 60 * 1000)
#define CFUN_TIMEOUT (180 * 1000)
#define CGDCONT_TIMEOUT ( 10 * 1000)
#define CGREG_TIMEOUT ( 60 * 1000)
#define CGATT_TIMEOUT (180 * 1000)
#define CIMI_TIMEOUT ( 10 * 1000) /* Should be immediate, but have observed 3 seconds occassionally on u-blox and rarely longer times */
#define CMGS_TIMEOUT (150 * 1000) /* 180s for R4 (set to 150s to match previous implementation) */
#define COPS_TIMEOUT (180 * 1000)
#define CPWROFF_TIMEOUT ( 40 * 1000)
#define CREG_TIMEOUT ( 60 * 1000)
#define CSQ_TIMEOUT ( 10 * 1000)
#define CREG_TIMEOUT ( 60 * 1000)
#define CGREG_TIMEOUT ( 60 * 1000)
#define CEREG_TIMEOUT ( 60 * 1000)
#define UBANDSEL_TIMEOUT ( 40 * 1000)
#define UBANDMASK_TIMEOUT ( 10 * 1000)
#define UCGED_TIMEOUT ( 10 * 1000)
#define UDNSRN_TIMEOUT ( 30 * 1000) /* 70s for R4 (set to 30s to match previous implementation) */
#define URAT_TIMEOUT ( 10 * 1000)
#define UMNOPROF_TIMEOUT ( 10 * 1000)
#define UPSD_TIMEOUT ( 10 * 1000)
#define UPSDA_TIMEOUT (180 * 1000)
#define UPSND_TIMEOUT ( 10 * 1000)
#define UMNOPROF_TIMEOUT ( 10 * 1000)
#define CEDRXS_TIMEOUT ( 10 * 1000)
#define CFUN_TIMEOUT (180 * 1000)
#define UCGED_TIMEOUT ( 10 * 1000)
#define CIMI_TIMEOUT ( 10 * 1000) /* Should be immediate, but have observed 3 seconds occassionally on u-blox and rarely longer times */
#define URAT_TIMEOUT ( 10 * 1000)

// num sockets
#define NUMSOCKETS ((int)(sizeof(_sockets)/sizeof(*_sockets)))
Expand Down Expand Up @@ -248,6 +249,10 @@ MDMParser::MDMParser(void)
inst = this;
memset(&_dev, 0, sizeof(_dev));
memset(&_net, 0, sizeof(_net));
memset(_sockets, 0, sizeof(_sockets));
for (int socket = 0; socket < NUMSOCKETS; socket ++) {
_sockets[socket].handle = MDM_SOCKET_ERROR;
}
_net.cgi.location_area_code = 0xFFFF;
_net.cgi.cell_id = 0xFFFFFFFF;
_ip = NOIP;
Expand All @@ -263,11 +268,13 @@ MDMParser::MDMParser(void)
sms_cb = NULL;
_timePowerOn = 0;
_timeRegistered = 0;
memset(_sockets, 0, sizeof(_sockets));
for (int socket = 0; socket < NUMSOCKETS; socket ++)
_sockets[socket].handle = MDM_SOCKET_ERROR;
_error = 0;
_lastVerboseC_regUpdate = 0;
_verboseCregEnabled = false;
_verboseCgregEnabled = false;
_verboseCeregEnabled = false;
_lastProcess = 0;
_error = 0;
_reinitModem = 0xFF;
#ifdef MDM_DEBUG
_debugLevel = 3;
#endif
Expand Down Expand Up @@ -408,6 +415,7 @@ bool MDMParser::_checkModem(bool force /* = true */) {
}

int MDMParser::process() {

if (!(_init && _pwr)) {
return 0;
}
Expand All @@ -418,34 +426,38 @@ int MDMParser::process() {

{
LOCK();
if (!_checkModem(false /* force */)) {
if (_reinitModem == 0x55 || !_checkModem(false /* force */)) {
if (_reinitModem != 0x55) {
MDM_ERROR("[ Modem not responsive ]\r\n");
}
_reinitModem = 0xFF;
// We've notified system layer that we'll require a modem reset
// This will get reset once the system (or something else) calls on()
_cancel_all_operations = true;
// Short-circuit disconnect() call
_ip = NOIP;
_ip = NOIP; // Short-circuit disconnect() call
_attached = false;
_activated = false;
HAL_NET_notify_disconnected();
MDM_ERROR("[ Modem not responsive ]\r\n");
return -1;
}
}

if ((HAL_Timer_Get_Milli_Seconds() - _lastProcess) >= MDM_URC_POLL_INTERVAL_MS) {
LOCK();
// Process URCs
waitFinalResp(nullptr, nullptr, 0);
waitFinalResp(nullptr, nullptr, 0); // Process URCs
_lastProcess = HAL_Timer_Get_Milli_Seconds();
}

if (_activated && !_attached) {
LOCK();
if (!reconnect()) {
return -1;
return -2;
}
}

// Periodically check if C*REG URCs are still enabled, will cause modem re-init if not.
_checkVerboseC_reg();

return 0;
}

Expand Down Expand Up @@ -501,7 +513,7 @@ int MDMParser::waitFinalResp(_CALLBACKPTR cb /* = NULL*/,
// handle unsolicited commands here
if (type == TYPE_PLUS) {
const char* cmd = buf+3; // assume all TYPE_PLUS commands have \r\n+ and skip
int a, b, c, d, r;
int mode, a, b, c, d, r;
char s[32];

// SMS Command ---------------------------------
Expand Down Expand Up @@ -565,13 +577,14 @@ int MDMParser::waitFinalResp(_CALLBACKPTR cb /* = NULL*/,
HAL_NET_notify_dhcp(false);
}
} else {
// +CREG|CGREG: <n>,<stat>[,<lac>,<ci>[,AcT[,<rac>]]] // reply to AT+CREG|AT+CGREG
// +CREG|CGREG: <stat>[,<lac>,<ci>[,AcT[,<rac>]]] // URC
b = (int)0xFFFF; c = (int)0xFFFFFFFF; d = -1;
r = sscanf(cmd, "%31s %*d,%d,\"%x\",\"%x\",%d",s,&a,&b,&c,&d);
// +CREG|CGREG: <n>,<stat>[,<lac>,<ci>[,AcT[,<rac>]]] // reply to AT+CREG|AT+CGREG (2,4,5,6 results)
// +CREG|CGREG: <stat>[,<lac>,<ci>[,AcT[,<rac>]]] // URC (1,3,4,5 results)
b = (int)0xFFFF; c = (int)0xFFFFFFFF; d = -1; mode = 2;
r = sscanf(cmd, "%31s %d,%d,\"%x\",\"%x\",%d",s,&mode,&a,&b,&c,&d);
if (r <= 1)
r = sscanf(cmd, "%31s %d,\"%x\",\"%x\",%d",s,&a,&b,&c,&d);
if (r >= 2) {
if (r == 2) mode = 2; // Single URC <stat>, so fix mode that got overwritten in the first sscanf
Reg *reg = !strcmp(s, "CREG:") ? &_net.csd :
!strcmp(s, "CGREG:") ? &_net.psd :
!strcmp(s, "CEREG:") ? &_net.eps : NULL;
Expand All @@ -584,13 +597,32 @@ int MDMParser::waitFinalResp(_CALLBACKPTR cb /* = NULL*/,
else if (a == 4) *reg = REG_UNKNOWN; // 4: unknown
else if (a == 5) *reg = REG_ROAMING; // 5: registered, roaming

// R410 : Look out for a CEREG: de-registration URC while attached
if (_dev.dev == DEV_SARA_R410 && _attached && !REG_OK(*reg) && !strcmp(s, "CEREG:")) {
MDM_PRINTF("Cell de-registered\r\n");
_attached_urc = 0;
_ip = NOIP;
_attached = false;
HAL_NET_notify_disconnected();
_reinitModem = 0xFF;
if (mode == 0) {
if (_dev.dev == DEV_SARA_R410) {
if (_verboseCeregEnabled && !strcmp(s, "CEREG:")) {
_reinitModem = 0x55;
}
} else {
if (_verboseCregEnabled && !strcmp(s, "CREG:")) {
_reinitModem = 0x55;
} else if (_verboseCgregEnabled && !strcmp(s, "CGREG:")) {
_reinitModem = 0x55;
}
}
}
if (_reinitModem == 0x55) {
MDM_ERROR("[ Modem unexpectedly reset ]\r\n");
_lastVerboseC_regUpdate = 0;
_verboseCregEnabled = false;
_verboseCgregEnabled = false;
_verboseCeregEnabled = false;
// reinit handled in MDMParser::process()
} else if (_dev.dev == DEV_SARA_R410 && _attached && !REG_OK(*reg) && !strcmp(s, "CEREG:")) {
// R410 : Look out for a CEREG: de-registration URC while attached
MDM_ERROR("[ Cell de-registered ]\r\n");
_reinitModem = 0x55;
// reinit handled in MDMParser::process()
}

if ((r >= 3) && (b != (int)0xFFFF)) _net.cgi.location_area_code = b;
Expand Down Expand Up @@ -752,6 +784,11 @@ void MDMParser::reset(void)
_timeRegistered = 0;
// Increment the state change counter
_incModemStateChangeCount();
// Reset our verbose C*REG variables
_lastVerboseC_regUpdate = 0;
_verboseCregEnabled = false;
_verboseCgregEnabled = false;
_verboseCeregEnabled = false;
}

bool MDMParser::_powerOn(void)
Expand Down Expand Up @@ -1211,11 +1248,12 @@ bool MDMParser::powerState(void) const {
bool MDMParser::powerOff(void)
{
LOCK();
const char * POWER_OFF_MSG = "\r\n[ Modem::powerOff ]";
bool ok = false;
bool continue_cancel = false;
bool check_ri = false;
if (_init && _pwr) {
MDM_INFO("\r\n[ Modem::powerOff ] = = = = = = = = = = = = = =");
MDM_INFO("%s = = = = = = = = = = = = = =", POWER_OFF_MSG);
if (_cancel_all_operations) {
continue_cancel = true;
resume(); // make sure we can use the AT parser
Expand All @@ -1229,7 +1267,7 @@ bool MDMParser::powerOff(void)
// to avoid hitting the 124 day memory housekeeping issue, AT+CPWROFF will
// handle this delay automatically, or timeout after 40s.
if (_memoryIssuePresent) {
MDM_INFO("\r\n[ Modem::powerOff ] Modem not responsive, waiting up to 30s to power off with PWR_UC...");
MDM_INFO("%s Modem not responsive, waiting up to 30s to power off with PWR_UC...", POWER_OFF_MSG);
system_tick_t now = HAL_Timer_Get_Milli_Seconds();
if (_timePowerOn == 0) {
// fallback to max timeout of 30s to be safe
Expand All @@ -1253,7 +1291,7 @@ bool MDMParser::powerOff(void)
_timePowerOn = 0;
}
}
MDM_INFO("\r\n[ Modem::powerOff ] Modem not responsive, trying PWR_UC...");
MDM_INFO("%s Modem not responsive, trying PWR_UC...", POWER_OFF_MSG);
// Skip power off sequence if power is already off
if (!powerState()) {
break;
Expand All @@ -1274,16 +1312,16 @@ bool MDMParser::powerOff(void)
}
break;
} else if (RESP_ABORTED == ret) {
MDM_INFO("\r\n[ Modem::powerOff ] found ABORTED, retrying...");
MDM_INFO("%s found ABORTED, retrying...", POWER_OFF_MSG);
} else {
MDM_INFO("\r\n[ Modem::powerOff ] timeout, retrying...");
MDM_INFO("%s timeout, retrying...", POWER_OFF_MSG);
}
}
}
} else {
if (powerState()) {
check_ri = true;
MDM_INFO("[ Modem::powerOff ] modem is on unexpectedly. Turning it off...");
MDM_INFO("%s modem is on unexpectedly. Turning it off...", POWER_OFF_MSG);
// Delay this long period so that the modem is fully on to accept the power-off sequence.
HAL_Delay_Milliseconds(12000);

Expand All @@ -1307,9 +1345,9 @@ bool MDMParser::powerOff(void)
_pwr = false;
}
if (!power_state) {
MDM_INFO("\r\n[ Modem::powerOff ] took %lu ms", HAL_Timer_Get_Milli_Seconds() - t0);
MDM_INFO("%s took %lu ms", POWER_OFF_MSG, HAL_Timer_Get_Milli_Seconds() - t0);
} else {
MDM_INFO("\r\n[ Modem::powerOff ] failed");
MDM_INFO("%s failed", POWER_OFF_MSG);
}
} else {
_pwr = false;
Expand All @@ -1318,9 +1356,13 @@ bool MDMParser::powerOff(void)
//_attached = false;
}
HAL_Delay_Milliseconds(1000); // give peace a chance
// Increment the state change counter to show that the modem has been powered off -> on
// Increment the state change counter to show that the modem has been powered on -> off
if (!_pwr) {
_incModemStateChangeCount();
_lastVerboseC_regUpdate = 0;
_verboseCregEnabled = false;
_verboseCgregEnabled = false;
_verboseCeregEnabled = false;
}

// Close serial connection
Expand Down Expand Up @@ -1427,6 +1469,38 @@ int MDMParser::_cbCCID(int type, const char* buf, int len, CStringHelper* str)
return WAIT;
}

void MDMParser::_checkVerboseC_reg(void) {
if (!_attached) {
return;
}

if (_lastVerboseC_regUpdate &&
(HAL_Timer_Get_Milli_Seconds() - _lastVerboseC_regUpdate) >= MDM_C_REG_POLL_INTERVAL_MS)
{
LOCK();
if (!_checkModem()) {
return;
}
_lastVerboseC_regUpdate = HAL_Timer_Get_Milli_Seconds();
// Check if C*REG URCs are enabled, handled in waitFinalResp()
if (_dev.dev == DEV_SARA_R410) {
if (_verboseCeregEnabled) {
sendFormated("AT+CEREG?\r\n");
waitFinalResp(nullptr, nullptr, CEREG_TIMEOUT);
}
} else {
if (_verboseCregEnabled) {
sendFormated("AT+CREG?\r\n");
waitFinalResp(nullptr, nullptr, CREG_TIMEOUT);
}
if (_verboseCgregEnabled) {
sendFormated("AT+CGREG?\r\n");
waitFinalResp(nullptr, nullptr, CGREG_TIMEOUT);
}
}
}
}

bool MDMParser::_checkEpsReg(void) {
// On the SARA R410M check EPS registration
if (_dev.dev == DEV_SARA_R410) {
Expand Down Expand Up @@ -1487,6 +1561,8 @@ bool MDMParser::registerNet(const char* apn, NetStatus* status, system_tick_t ti
if (RESP_OK != waitFinalResp(nullptr, nullptr, CEREG_TIMEOUT)) {
goto failure;
}
_verboseCeregEnabled = true;
_lastVerboseC_regUpdate = HAL_Timer_Get_Milli_Seconds();
} else {
// Set up the GPRS network registration URC
sendFormated("AT+CGREG=2\r\n");
Expand All @@ -1498,6 +1574,9 @@ bool MDMParser::registerNet(const char* apn, NetStatus* status, system_tick_t ti
if (RESP_OK != waitFinalResp(nullptr, nullptr, CREG_TIMEOUT)) {
goto failure;
}
_verboseCgregEnabled = true;
_verboseCregEnabled = true;
_lastVerboseC_regUpdate = HAL_Timer_Get_Milli_Seconds();
}
if (!(ok = checkNetStatus())) {
if (_dev.dev == DEV_SARA_R410) {
Expand Down
9 changes: 9 additions & 0 deletions hal/src/electron/modem/mdm_hal.h
Original file line number Diff line number Diff line change
Expand Up @@ -553,6 +553,9 @@ class MDMParser
static int _cbCPIN(int type, const char* buf, int len, Sim* sim);
static int _cbCCID(int type, const char* buf, int len, CStringHelper* ccid);
// network
static int _cbCREG(int type, const char* buf, int len, int* mode);
static int _cbCGREG(int type, const char* buf, int len, int* mode);
static int _cbCEREG(int type, const char* buf, int len, int* mode);
static int _cbUMNOPROF(int type, const char *buf, int len, int* i);
static int _cbCFUN(int type, const char* buf, int len, int* i);
static int _cbUBANDMASK(int type, const char *buf, int len, uint64_t* i);
Expand Down Expand Up @@ -648,6 +651,7 @@ class MDMParser
int _checkAtResponse(void);
bool _atOk(void);
bool _checkModem(bool force = true);
void _checkVerboseC_reg(void);
bool _checkEpsReg(void);
int _socketError(void);
static MDMParser* inst;
Expand All @@ -661,6 +665,11 @@ class MDMParser
volatile bool _cancel_all_operations;
volatile uint32_t _error;
system_tick_t _lastProcess;
system_tick_t _lastVerboseC_regUpdate;
bool _verboseCregEnabled;
bool _verboseCgregEnabled;
bool _verboseCeregEnabled;
int _reinitModem;
#ifdef MDM_DEBUG
int _debugLevel;
void _debugPrint(int level, const char* color, const char* format, ...) __attribute__((format(printf, 4, 5)));
Expand Down
Loading

0 comments on commit a8ed2bd

Please sign in to comment.