Event loop error 3 and keepAlive (keep alive) times (SOLVED)

Firmware
1

I can’t get my 3G Electron (North America) to maintain a cloud connection using Rogers Canada SIM card.

Sure, it can connect to the cloud whenever it wants to, and I can publish data and receive function calls from the cloud no problem. The problem arises if I don’t publish data or don’t issue a function call from cloud to device for more than 250 seconds, the connection gets dropped by the carrier (I assume that’s what “Event Loop Error 3” means in the AT command serial trace).

I have a modified version of tinker running that publishes a test publish every 5 minutes.

I have set cellular credentials using the STARTUP() macro and have called Particle.keepAlive(10)

On the serial monitor, I don’t see any pings or heartbeats or whatever going out every 10 seconds, so I assume that this is something the modem is handling automatically (i.e. there is no corresponding AT command traffic between STM32 and modem that shows up in the SerialLogger AT command trace).

I have run a different program that publishes in decreasing frequency until the connection drops, so that’s how I know that if the time between network traffic events is more than 250 seconds that the connection resets.

I can confirm that both programs work as expected (sans dropped connection) with the stock Particle SIM card / APN / keepAlive

Is there a way ot confirm that the keepAlive pings are being sent out?

Does anyone know what AT codes are related to or configure the keepAlive time of the UDP socket?

From my examination of the AT command manual, it would seem that the keep alive is set by the AT+CGPERMSET command, but my serial debug log doesn’t have that in it (see below). From my reading of the AT command manual, it would seem that there is a provision for automatic keep alive packets being sent for TCP connections but that for UDP connections there is no automated keep alive method.

[Mon Oct 30 23:01:11.927 2017]      3.467 AT send       4 "AT\r\n"
[Mon Oct 30 23:01:13.247 2017]      4.787 AT send       4 "AT\r\n"
[Mon Oct 30 23:01:13.461 2017] CLOUD NOT CONNECTED!!!!!!!!!!!
[Mon Oct 30 23:01:14.567 2017]      6.107 AT send       4 "AT\r\n"
[Mon Oct 30 23:01:15.887 2017]      7.427 AT send       4 "AT\r\n"
[Mon Oct 30 23:01:15.897 2017]      7.437 AT read  +   11 "\r\n+PACSP1\r\n"
[Mon Oct 30 23:01:15.907 2017]      7.447 AT read UNK   3 "AT\r"
[Mon Oct 30 23:01:15.917 2017]      7.457 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.128 2017]      7.667 AT send       7 "AT E0\r\n"
[Mon Oct 30 23:01:16.137 2017]      7.677 AT read UNK   6 "AT E0\r"
[Mon Oct 30 23:01:16.147 2017]      7.687 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.148 2017]      7.687 AT send      11 "AT+CMEE=2\r\n"
[Mon Oct 30 23:01:16.157 2017]      7.697 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.158 2017]      7.697 AT send      19 "AT+CMER=1,0,0,2,1\r\n"
[Mon Oct 30 23:01:16.169 2017]      7.709 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.171 2017]      7.709 AT send      15 "AT+IPR=115200\r\n"
[Mon Oct 30 23:01:16.178 2017]      7.719 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.279 2017]      7.819 AT send      10 "AT+CPIN?\r\n"
[Mon Oct 30 23:01:16.281 2017]      7.819 AT read  +   14 "\r\n+CIEV: 5,1\r\n"
[Mon Oct 30 23:01:16.291 2017]      7.831 AT read  +   16 "\r\n+CPIN: READY\r\n"
[Mon Oct 30 23:01:16.301 2017]      7.841 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.303 2017] 0000007841 [system] INFO: Sim Ready
[Mon Oct 30 23:01:16.303 2017] 0000007841 [system] INFO: ARM_WLAN_WD 1
[Mon Oct 30 23:01:16.303 2017] 
[Mon Oct 30 23:01:16.303 2017] [ Modem::init ] = = = = = = = = = = = = = = =
[Mon Oct 30 23:01:16.304 2017]      7.843 AT send       9 "AT+CGSN\r\n"
[Mon Oct 30 23:01:16.323 2017]      7.863 AT read UNK  19 "\r\n353162070870036\r\n"
[Mon Oct 30 23:01:16.333 2017]      7.873 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.334 2017]      7.873 AT send       9 "AT+CGMI\r\n"
[Mon Oct 30 23:01:16.343 2017]      7.883 AT read UNK  10 "\r\nu-blox\r\n"
[Mon Oct 30 23:01:16.353 2017]      7.893 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.355 2017]      7.893 AT send       9 "AT+CGMM\r\n"
[Mon Oct 30 23:01:16.355 2017]      7.893 AT read  +   14 "\r\n+UMWI: 0,1\r\n"
[Mon Oct 30 23:01:16.365 2017]      7.905 AT read  +   14 "\r\n+UMWI: 0,2\r\n"
[Mon Oct 30 23:01:16.375 2017]      7.915 AT read  +   14 "\r\n+UMWI: 0,3\r\n"
[Mon Oct 30 23:01:16.384 2017]      7.925 AT read  +   14 "\r\n+UMWI: 0,4\r\n"
[Mon Oct 30 23:01:16.396 2017]      7.935 AT read UNK  13 "\r\nSARA-U260\r\n"
[Mon Oct 30 23:01:16.405 2017]      7.945 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.406 2017]      7.945 AT send       9 "AT+CGMR\r\n"
[Mon Oct 30 23:01:16.415 2017]      7.955 AT read UNK   9 "\r\n23.20\r\n"
[Mon Oct 30 23:01:16.425 2017]      7.965 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.426 2017]      7.965 AT send       9 "AT+CCID\r\n"
[Mon Oct 30 23:01:16.435 2017]      7.975 AT read  +   31 "\r\n+CCID: 89302720523013929652\r\n"
[Mon Oct 30 23:01:16.447 2017]      7.987 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.448 2017]      7.987 AT send      11 "AT+UPSV=1\r\n"
[Mon Oct 30 23:01:16.457 2017]      7.997 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.458 2017]      7.997 AT send      11 "AT+CMGF=1\r\n"
[Mon Oct 30 23:01:16.467 2017]      8.007 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.468 2017]      8.007 AT send      13 "AT+CNMI=2,1\r\n"
[Mon Oct 30 23:01:16.477 2017]      8.017 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.479 2017]      8.017 AT send       9 "AT+CIMI\r\n"
[Mon Oct 30 23:01:16.487 2017]      8.027 AT read UNK  19 "\r\n302720607325223\r\n"
[Mon Oct 30 23:01:16.497 2017]      8.037 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.499 2017] 
[Mon Oct 30 23:01:16.499 2017] [ Modem::register ] = = = = = = = = = = = = = =
[Mon Oct 30 23:01:16.499 2017]      8.037 AT send      10 "AT+CREG?\r\n"
[Mon Oct 30 23:01:16.509 2017]      8.049 AT read  +   14 "\r\n+CREG: 0,0\r\n"
[Mon Oct 30 23:01:16.519 2017]      8.059 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.521 2017]      8.059 AT send      11 "AT+CGREG?\r\n"
[Mon Oct 30 23:01:16.529 2017]      8.069 AT read  +   15 "\r\n+CGREG: 0,0\r\n"
[Mon Oct 30 23:01:16.539 2017]      8.079 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.541 2017]      8.079 AT send      12 "AT+CGREG=2\r\n"
[Mon Oct 30 23:01:16.550 2017]      8.089 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.551 2017]      8.089 AT send      11 "AT+CREG=2\r\n"
[Mon Oct 30 23:01:16.559 2017]      8.099 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.560 2017]      8.099 AT send      10 "AT+CREG?\r\n"
[Mon Oct 30 23:01:16.569 2017]      8.109 AT read  +   14 "\r\n+CREG: 2,0\r\n"
[Mon Oct 30 23:01:16.579 2017]      8.119 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:16.581 2017]      8.119 AT send      11 "AT+CGREG?\r\n"
[Mon Oct 30 23:01:16.589 2017]      8.129 AT read  +   15 "\r\n+CGREG: 2,0\r\n"
[Mon Oct 30 23:01:16.599 2017]      8.139 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:18.462 2017] CLOUD NOT CONNECTED!!!!!!!!!!!
[Mon Oct 30 23:01:23.465 2017] CLOUD NOT CONNECTED!!!!!!!!!!!
[Mon Oct 30 23:01:28.466 2017] CLOUD NOT CONNECTED!!!!!!!!!!!
[Mon Oct 30 23:01:31.599 2017]     23.139 AT send      10 "AT+CREG?\r\n"
[Mon Oct 30 23:01:31.601 2017]     23.139 AT read  +   14 "\r\n+CIEV: 2,2\r\n"
[Mon Oct 30 23:01:31.610 2017]     23.151 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"12317A\",2\r\n"
[Mon Oct 30 23:01:31.622 2017]     23.163 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"12317A\",2,\"01\"\r\n"
[Mon Oct 30 23:01:31.634 2017]     23.175 AT read  +   14 "\r\n+CIEV: 3,1\r\n"
[Mon Oct 30 23:01:31.645 2017]     23.185 AT read  +   14 "\r\n+CIEV: 7,0\r\n"
[Mon Oct 30 23:01:31.655 2017]     23.195 AT read  +   14 "\r\n+CIEV: 9,2\r\n"
[Mon Oct 30 23:01:31.657 2017] CIEV matched: 9,2
[Mon Oct 30 23:01:31.665 2017]     23.205 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"12020D\",2\r\n"
[Mon Oct 30 23:01:31.677 2017]     23.217 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"12020D\",2,\"01\"\r\n"
[Mon Oct 30 23:01:33.439 2017]     24.979 AT read  +   32 "\r\n+CREG: 2,1,\"CF35\",\"12020D\",2\r\n"
[Mon Oct 30 23:01:33.451 2017]     24.991 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.452 2017]     24.991 AT send      11 "AT+CGREG?\r\n"
[Mon Oct 30 23:01:33.461 2017]     25.001 AT read  +   38 "\r\n+CGREG: 2,1,\"CF35\",\"12020D\",2,\"01\"\r\n"
[Mon Oct 30 23:01:33.467 2017] CLOUD NOT CONNECTED!!!!!!!!!!!
[Mon Oct 30 23:01:33.473 2017]     25.013 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.475 2017]     25.013 AT send      10 "AT+COPS?\r\n"
[Mon Oct 30 23:01:33.533 2017]     25.073 AT read  +   25 "\r\n+COPS: 0,0,\"ROGERS\",2\r\n"
[Mon Oct 30 23:01:33.543 2017]     25.083 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.546 2017]     25.083 AT send       9 "AT+CNUM\r\n"
[Mon Oct 30 23:01:33.573 2017]     25.113 AT read  +   32 "\r\n+CNUM: \"\",\"+19024033091\",145\r\n"
[Mon Oct 30 23:01:33.585 2017]     25.125 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.587 2017]     25.125 AT send       8 "AT+CSQ\r\n"
[Mon Oct 30 23:01:33.595 2017]     25.135 AT read  +   14 "\r\n+CSQ: 12,5\r\n"
[Mon Oct 30 23:01:33.606 2017]     25.145 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.607 2017] 
[Mon Oct 30 23:01:33.607 2017] [ Modem::join ] = = = = = = = = = = = = = = = =
[Mon Oct 30 23:01:33.607 2017]     25.145 AT send      12 "AT+CGATT=1\r\n"
[Mon Oct 30 23:01:33.618 2017]     25.157 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.619 2017]     25.157 AT send      14 "AT+UPSND=0,8\r\n"
[Mon Oct 30 23:01:33.627 2017]     25.167 AT read  +   17 "\r\n+UPSND: 0,8,0\r\n"
[Mon Oct 30 23:01:33.636 2017]     25.177 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.638 2017]     25.177 AT send      23 "AT+UPSD=0,7,\"0.0.0.0\"\r\n"
[Mon Oct 30 23:01:33.650 2017]     25.189 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.651 2017]     25.189 AT send      28 "AT+UPSD=0,1,\"internet.com\"\r\n"
[Mon Oct 30 23:01:33.661 2017]     25.201 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.664 2017]     25.201 AT send      24 "AT+UPSD=0,2,\"wapuser1\"\r\n"
[Mon Oct 30 23:01:33.674 2017]     25.213 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.675 2017]     25.213 AT send      19 "AT+UPSD=0,3,\"wap\"\r\n"
[Mon Oct 30 23:01:33.686 2017]     25.225 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.688 2017]     25.225 AT send      15 "AT+UPSD=0,6,0\r\n"
[Mon Oct 30 23:01:33.695 2017]     25.235 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:33.697 2017]     25.235 AT send      14 "AT+UPSDA=0,3\r\n"
[Mon Oct 30 23:01:35.656 2017]     27.195 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:35.658 2017]     27.195 AT send      14 "AT+UPSND=0,0\r\n"
[Mon Oct 30 23:01:35.665 2017]     27.205 AT read  +   30 "\r\n+UPSND: 0,0,\"25.32.23.182\"\r\n"
[Mon Oct 30 23:01:35.678 2017]     27.217 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:35.678 2017] 0000027217 [system] INFO: ARM_WLAN_WD 2
[Mon Oct 30 23:01:35.680 2017] 0000027217 [system] INFO: CLR_WLAN_WD 1, DHCP success
[Mon Oct 30 23:01:35.680 2017] 0000027217 [system] INFO: Cloud: connecting
[Mon Oct 30 23:01:35.680 2017] 0000027219 [system] TRACE: sparkSocket Now =-1
[Mon Oct 30 23:01:35.682 2017] 0000027219 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
[Mon Oct 30 23:01:35.682 2017]     27.221 AT send      56 "AT+UDNSRN=0,\"260032000c51343334363138.udp.particle.io\"\r\n"
[Mon Oct 30 23:01:36.223 2017]     27.763 AT read  +   29 "\r\n+UDNSRN: \"34.201.112.170\"\r\n"
[Mon Oct 30 23:01:36.236 2017]     27.775 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:36.239 2017] 0000027776 [system] INFO: Resolved host 260032000c51343334363138.udp.particle.io to 34.201.112.170
[Mon Oct 30 23:01:36.239 2017] On first socketSocket use, free all open sockets
[Mon Oct 30 23:01:36.239 2017]     27.776 AT send      15 "AT+USOCTL=0,1\r\n"
[Mon Oct 30 23:01:36.247 2017]     27.788 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.251 2017]     27.790 AT send      15 "AT+USOCTL=1,1\r\n"
[Mon Oct 30 23:01:36.259 2017]     27.800 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.262 2017]     27.802 AT send      15 "AT+USOCTL=2,1\r\n"
[Mon Oct 30 23:01:36.272 2017]     27.812 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.274 2017]     27.814 AT send      15 "AT+USOCTL=3,1\r\n"
[Mon Oct 30 23:01:36.284 2017]     27.824 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.286 2017]     27.826 AT send      15 "AT+USOCTL=4,1\r\n"
[Mon Oct 30 23:01:36.296 2017]     27.836 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.299 2017]     27.838 AT send      15 "AT+USOCTL=5,1\r\n"
[Mon Oct 30 23:01:36.307 2017]     27.848 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.310 2017]     27.850 AT send      15 "AT+USOCTL=6,1\r\n"
[Mon Oct 30 23:01:36.320 2017]     27.860 AT read ERR  37 "\r\n+CME ERROR: operation not allowed\r\n"
[Mon Oct 30 23:01:36.322 2017] socketSocket(UDP)
[Mon Oct 30 23:01:36.322 2017]     27.862 AT send      18 "AT+USOCR=17,5684\r\n"
[Mon Oct 30 23:01:36.331 2017]     27.872 AT read  +   13 "\r\n+USOCR: 0\r\n"
[Mon Oct 30 23:01:36.343 2017]     27.882 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:36.343 2017] Socket 0: handle 0 was created
[Mon Oct 30 23:01:36.346 2017] 0000027882 [system] TRACE: socketed udp=1, sparkSocket=0, 1
[Mon Oct 30 23:01:36.346 2017] 0000027882 [system] TRACE: connection attempt to 34.201.112.170:5684
[Mon Oct 30 23:01:36.346 2017] 0000027884 [system] INFO: Cloud socket connected
[Mon Oct 30 23:01:36.346 2017] 0000027884 [system] INFO: Starting handshake: presense_announce=0
[Mon Oct 30 23:01:36.348 2017] 0000027886 [comm.protocol.handshake] INFO: Establish secure connection
[Mon Oct 30 23:01:36.368 2017] 0000027906 [comm.dtls] TRACE: restore size mismatch 1: 0/220
[Mon Oct 30 23:01:36.370 2017] 0000027906 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
[Mon Oct 30 23:01:36.372 2017] 0000027910 [system] TRACE: send 107
[Mon Oct 30 23:01:36.374 2017] socketSendTo(0,34.201.112.170,5684,,107)
[Mon Oct 30 23:01:36.374 2017]     27.912 AT send      38 "AT+USOST=0,\"34.201.112.170\",5684,107\r\n"
[Mon Oct 30 23:01:36.384 2017]     27.924 AT read  >    3 "\r\n@"
[Mon Oct 30 23:01:36.433 2017]     27.974 AT send     107 "\x16\xfe\xfd\x00\x00\x00\x00\x00\x00\x00\x00\x00^\x01\x00\x00R\x00\x00\x00\x00\x00\x00\x00R\xfe\xfdgX}}\xd2p\x8b\xb0\x9b\\\xac\xa0\xc9\xfb=v/\xbc\xe3\a\x90S\xe3\xbbO\x03\xbf\x03\xbd\xc5k\xc6\x00\x00\x00\x04\xc0\xae\x00\xff\x01\x00\x00$\x00\r\x00\x06\x00\x04\x04\x03\x03\x03\x00\n\x00\x04\x00\x02\x00\x17\x00\v\x00\x02\x01\x00\x00\x13\x00\x02\x01\x02\x00\x14\x00\x02\x01\x02"
[Mon Oct 30 23:01:36.580 2017]     28.120 AT read  +   17 "\r\n+USOST: 0,107\r\n"
[Mon Oct 30 23:01:36.590 2017]     28.130 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:01:36.592 2017]     28.130 AT read  +   17 "\r\n+UUSORD: 0,60\r\n"
[Mon Oct 30 23:01:36.594 2017] Socket 0: handle 0 has 60 bytes pending
[Mon Oct 30 23:01:36.601 2017]     28.142 AT send      16 "AT+USORF=0,813\r\n"
[Mon Oct 30 23:01:36.621 2017]     28.162 AT read  +   99 "\r\n+USORF:

BLAH BLAH BLAH

[Mon Oct 30 23:06:25.450 2017]    316.996 AT read  +   16 "\r\n+USOST: 0,44\r\n"
[Mon Oct 30 23:06:25.459 2017]    317.006 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:06:29.681 2017] Connected time = 00281 secondsConnected time = 00286 seconds   326.346 AT read  +   14 "\r\n+CIEV: 2,1\r\n"
[Mon Oct 30 23:06:39.683 2017] Connected time = 00291 seconds   331.956 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"122F94\",2\r\n"
[Mon Oct 30 23:06:40.522 2017]    332.068 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"122F94\",2,\"01\"\r\n"
[Mon Oct 30 23:06:40.963 2017]    332.510 AT read  +   14 "\r\n+CIEV: 2,0\r\n"
[Mon Oct 30 23:06:42.393 2017]    333.940 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"1223B5\",2\r\n"
[Mon Oct 30 23:06:42.506 2017]    334.052 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"1223B5\",2,\"01\"\r\n"
[Mon Oct 30 23:06:42.727 2017]    334.274 AT read  +   14 "\r\n+CIEV: 2,1\r\n"
[Mon Oct 30 23:06:44.167 2017] 0000335714 [system] TRACE: send 44
[Mon Oct 30 23:06:44.169 2017] socketSendTo(0,34.201.112.170,5684,,44)
[Mon Oct 30 23:06:44.169 2017]    335.714 AT send      37 "AT+USOST=0,\"34.201.112.170\",5684,44\r\n"
[Mon Oct 30 23:06:44.685 2017] Connected time = 00296 seconds   336.436 AT read  >    3 "\r\n@"
[Mon Oct 30 23:06:44.939 2017]    336.486 AT send      44 "\x17\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\r\x00\x1f\x00\x01\x00\x00\x00\x00\x00\r\xe4\x95\xf7!\x1e\xfdzx\xc5\xc7\x81\x1c\xd1\xc8\xc4\x03z\xdb*\xee\xe1\xc5Z"
[Mon Oct 30 23:06:45.082 2017]    336.628 AT read  +   16 "\r\n+USOST: 0,44\r\n"
[Mon Oct 30 23:06:45.090 2017]    336.638 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:06:47.281 2017]    338.828 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"12002D\",2\r\n"
[Mon Oct 30 23:06:47.393 2017]    338.940 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"12002D\",2,\"01\"\r\n"
[Mon Oct 30 23:06:49.685 2017] Connected time = 00301 secondsConnected time = 00306 seconds   347.742 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"12020D\",2\r\n"
[Mon Oct 30 23:06:56.307 2017]    347.854 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"12020D\",2,\"01\"\r\n"
[Mon Oct 30 23:06:56.639 2017]    348.186 AT read  +   14 "\r\n+CIEV: 2,2\r\n"
[Mon Oct 30 23:06:59.687 2017] Connected time = 00311 secondsConnected time = 00316 secondsConnected time = 00321 secondsConnected time = 00326 seconds   370.846 AT read  +   30 "\r\n+CREG: 1,\"CF35\",\"12002D\",2\r\n"
[Mon Oct 30 23:07:19.411 2017]    370.958 AT read  +   36 "\r\n+CGREG: 1,\"CF35\",\"12002D\",2,\"01\"\r\n"
[Mon Oct 30 23:07:19.632 2017]    371.180 AT read  +   14 "\r\n+CIEV: 2,1\r\n"
[Mon Oct 30 23:07:19.691 2017] Connected time = 00331 secondsConnected time = 00336 seconds0000378230 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 0
[Mon Oct 30 23:07:26.783 2017] 0000378330 [comm.protocol] ERROR: Event loop error 3
[Mon Oct 30 23:07:26.783 2017] 0000378330 [system] WARN: Communication loop error, closing cloud socket
[Mon Oct 30 23:07:26.883 2017] 0000378430 [system] INFO: Cloud: connecting
[Mon Oct 30 23:07:26.883 2017] 0000378430 [system] TRACE: sparkSocket Now =0
[Mon Oct 30 23:07:26.884 2017] 0000378430 [system] TRACE: Close Attempt
[Mon Oct 30 23:07:26.884 2017] socketClose(0)
[Mon Oct 30 23:07:26.886 2017]    378.430 AT send      12 "AT+USOCL=0\r\n"
[Mon Oct 30 23:07:28.806 2017]    380.352 AT read OK    6 "\r\nOK\r\n"
[Mon Oct 30 23:07:28.806 2017] socketFree(0)
[Mon Oct 30 23:07:28.806 2017] 0000380352 [system] TRACE: socket_close()=success
[Mon Oct 30 23:07:28.806 2017] 0000380352 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
[Mon Oct 30 23:07:28.809 2017]    380.354 AT send      56 "AT+UDNSRN=0,\"260032000c51343334363138.udp.particle.io\"\r\n"
[Mon Oct 30 23:07:29.693 2017] CLOUD NOT CONNECTED!!!!!!!!!!!

_
_
_
Here is my code:
_
_
#include “Particle.h”

//Configure how the app runs within the Particle ecosystem
SYSTEM_MODE(SEMI_AUTOMATIC);
SYSTEM_THREAD(ENABLED);

//Set credentials for Rogers Wireless
STARTUP(
   //Set cell credentials
   cellular_credentials_set("internet.com", "wapuser1", "wap", NULL);

);

//Define log handler using serial monitor (dumps logs to serial monitor)
SerialLogHandler logHandler(LOG_LEVEL_ALL,
   {
      {"app"                  , LOG_LEVEL_ALL   },
   }
);

Logger myLog("app.main");  //Logger object used in this "main.cpp" file

#define WATCHDOG_PATTER B0

class CD4541_Watchdog{
   public:
      void begin(){
         pinMode(WATCHDOG_PATTER, OUTPUT);
         digitalWrite(WATCHDOG_PATTER, HIGH);
         isSuspended = true;
      }
   private:
      bool isSuspended = false;
};

CD4541_Watchdog HW_Watchdog;


/* Function prototypes -------------------------------------------------------*/
int tinkerDigitalRead(String pin);
int tinkerDigitalWrite(String command);
int tinkerAnalogRead(String pin);
int tinkerAnalogWrite(String command);

/* This function is called once at start up ----------------------------------*/
void setup()
{
	//Register all the Tinker functions
	Particle.function("digitalread", tinkerDigitalRead);
	Particle.function("digitalwrite", tinkerDigitalWrite);
	Particle.function("analogread", tinkerAnalogRead);
	Particle.function("analogwrite", tinkerAnalogWrite);
   Serial.begin(115200);
   delay(3000);
   //Set the keepAlive time
   Particle.keepAlive(150);
   //Set bands
   Cellular.setBandSelect("1900");
   //Connect to cloud
   Particle.connect();
   //Debug
   myLog.info("Finished setup()");
}

/* This function loops forever --------------------------------------------*/
unsigned int printTimer = 0;
bool wasConnectedLastLoop = false;
unsigned int lastConnectedTimeStamp = 0;
unsigned int lastPublishTimeStamp = 0;
unsigned int numPublishes = 0;
char publishBuffer[100];

void loop(){
	//This will run in a loop
   if((millis() - printTimer) > 5000){
      printTimer = millis();
      if(!Particle.connected()){
         Serial.printlnf("CLOUD NOT CONNECTED!!!!!!!!!!!");
      }
      else{
         //Check if this is first connection in a while
         if(wasConnectedLastLoop){
            //Delete previous "Connected time" chars
            for(int i = 0; i < 30; i++){
               Serial.write(8);  //Backspace character
            }
         }
         else{
            lastConnectedTimeStamp = millis();
            Serial.println();
            Serial.print("Connected time = ");
         }
         Serial.printf("Connected time = ""%05u seconds", (millis() - lastConnectedTimeStamp)/1000);
         wasConnectedLastLoop = true;
      }
   }

   if((millis() - lastPublishTimeStamp) > (5*60*1000)){
      snprintf(publishBuffer, 100, "%u", numPublishes);
      Particle.publish("tester", publishBuffer);
      lastPublishTimeStamp = millis();
   }
}

/*******************************************************************************
 * Function Name  : tinkerDigitalRead
 * Description    : Reads the digital value of a given pin
 * Input          : Pin
 * Output         : None.
 * Return         : Value of the pin (0 or 1) in INT type
                    Returns a negative number on failure
 *******************************************************************************/
int tinkerDigitalRead(String pin)
{
	//convert ascii to integer
	int pinNumber = pin.charAt(1) - '0';
	//Sanity check to see if the pin numbers are within limits
	if (pinNumber< 0 || pinNumber >7) return -1;

	if(pin.startsWith("D"))
	{
		pinMode(pinNumber, INPUT_PULLDOWN);
		return digitalRead(pinNumber);
	}
	else if (pin.startsWith("A"))
	{
		pinMode(pinNumber+10, INPUT_PULLDOWN);
		return digitalRead(pinNumber+10);
	}
	return -2;
}

/*******************************************************************************
 * Function Name  : tinkerDigitalWrite
 * Description    : Sets the specified pin HIGH or LOW
 * Input          : Pin and value
 * Output         : None.
 * Return         : 1 on success and a negative number on failure
 *******************************************************************************/
int tinkerDigitalWrite(String command)
{
	bool value = 0;
	//convert ascii to integer
	int pinNumber = command.charAt(1) - '0';
	//Sanity check to see if the pin numbers are within limits
	if (pinNumber< 0 || pinNumber >7) return -1;

	if(command.substring(3,7) == "HIGH") value = 1;
	else if(command.substring(3,6) == "LOW") value = 0;
	else return -2;

	if(command.startsWith("D"))
	{
		pinMode(pinNumber, OUTPUT);
		digitalWrite(pinNumber, value);
		return 1;
	}
	else if(command.startsWith("A"))
	{
		pinMode(pinNumber+10, OUTPUT);
		digitalWrite(pinNumber+10, value);
		return 1;
	}
	else return -3;
}

/*******************************************************************************
 * Function Name  : tinkerAnalogRead
 * Description    : Reads the analog value of a pin
 * Input          : Pin
 * Output         : None.
 * Return         : Returns the analog value in INT type (0 to 4095)
                    Returns a negative number on failure
 *******************************************************************************/
int tinkerAnalogRead(String pin)
{
	//convert ascii to integer
	int pinNumber = pin.charAt(1) - '0';
	//Sanity check to see if the pin numbers are within limits
	if (pinNumber< 0 || pinNumber >7) return -1;

	if(pin.startsWith("D"))
	{
		return -3;
	}
	else if (pin.startsWith("A"))
	{
		return analogRead(pinNumber+10);
	}
	return -2;
}

/*******************************************************************************
 * Function Name  : tinkerAnalogWrite
 * Description    : Writes an analog value (PWM) to the specified pin
 * Input          : Pin and Value (0 to 255)
 * Output         : None.
 * Return         : 1 on success and a negative number on failure
 *******************************************************************************/
int tinkerAnalogWrite(String command)
{
	//convert ascii to integer
	int pinNumber = command.charAt(1) - '0';
	//Sanity check to see if the pin numbers are within limits
	if (pinNumber< 0 || pinNumber >7) return -1;

	String value = command.substring(3);

	if(command.startsWith("D"))
	{
		pinMode(pinNumber, OUTPUT);
		analogWrite(pinNumber, value.toInt());
		return 1;
	}
	else if(command.startsWith("A"))
	{
		pinMode(pinNumber+10, OUTPUT);
		analogWrite(pinNumber+10, value.toInt());
		return 1;
	}
	else return -2;
}
2

Let me ping someone that might be able to help, @rickkas7 are you able to assist?

Kyle

3

At least in 0.6.2, you have to call Particle.keepAlive() AFTER Particle.connect. I usually wait until it’s actually connected when using SYSTEM_THREAD(ENABLED) but I’m not sure that’s really necessary.

But you definitely can’t do it before in SEMI_AUTOMATIC or MANUAL, as the call will be silently ignored.

You also only need to do it once; if the cloud automatically reconnects the setting is remembered.

4

:ok_hand: THANK YOU @rickkas7 . As the great Beldar Conhead wisely said: “Once again, you have pulled me from the fire”:pray:

So, calling Particle.keepAlive() right after Particle.connect doesn’t work (not sure if putting a delay between would work). but in any case, if you write a simple state machine to wait until 2 seconds after the cloud connection is established to before calling Particle.keepAlive(), then everything works as expected with 33 bytes sent and 33 bytes received network pings going out every 10 seconds like clockwork (even in the AT serial pipe!)

This should really be mentioned in the firmware API in the SYSTEM_THREAD() section I think. Who do we ping about that?

Here is some working code for Rogers Canada:

#include "Particle.h"

//Configure how the app runs within the Particle ecosystem
SYSTEM_MODE(SEMI_AUTOMATIC);
SYSTEM_THREAD(ENABLED);

//Configure Particle system (runs this code before any Particle init code runs):
STARTUP(
   //Configure other Particle runtime parameters
   System.enableFeature(FEATURE_RETAINED_MEMORY);
);
STARTUP(
   //Enable system reset information
   System.enableFeature(FEATURE_RESET_INFO);
);
STARTUP(
   //Make sure that cloud DFU updates are enabled
   System.enableUpdates();
);
STARTUP(
   //Set cell credentials
   cellular_credentials_set("internet.com", "wapuser1", "wap", NULL);
);



//Define log handler using serial monitor (dumps logs to serial monitor)
SerialLogHandler logHandler(LOG_LEVEL_ALL,
   {
      {"app"                  , LOG_LEVEL_ALL   },
      // { "app.MAX11616"        , LOG_LEVEL_WARN},     //Logging level for logs from "MAX11616.cpp" log category
      // {"app.jazaSD"           , LOG_LEVEL_ALL },
      // {"app.pubRegistryDB"    , LOG_LEVEL_TRACE  },
      // {"app.hubPropertiesDB"  , LOG_LEVEL_TRACE  }
   }

);
static Logger myLog("app.main");  //Logger object used in this "main.cpp" file

//Stores a string containing the reset reason (encoded by evaluateResetReason() )
char resetReason[50];

//Function forward declarations
void checkSerialCommands();
void evaluateResetReason();
void countDown(unsigned short seconds);
void showProcessingChars();


#define WATCHDOG_PATTER B0

class CD4541_Watchdog{
   public:
      void begin(){
         pinMode(WATCHDOG_PATTER, OUTPUT);
         digitalWrite(WATCHDOG_PATTER, HIGH);
      }
      void pat(){
         isSuspended = false;
         digitalWrite(WATCHDOG_PATTER, HIGH);
         delayMicroseconds(2);
         digitalWrite(WATCHDOG_PATTER, LOW);
      }
      void suspend(){
         digitalWrite(WATCHDOG_PATTER, HIGH);
         isSuspended = true;
      }
      bool suspended(){
         return isSuspended;
      }

   private:
      bool isSuspended = false;

};

CD4541_Watchdog HW_Watchdog;

/*=============================================>>>>>
= SETUP =
===============================================>>>>>*/

void setup(){
   //Start the serial monitor, print some space... wait 3 seconds
   //For a technician to establish a serial connection
   Serial.begin(115200);
   Serial.flush();
   countDown(3);
   //Debug
   myLog.warn("setup() start");
   //See what the reason for reset is...
   //This call will cause firmwareVersionInitialization()
   //to be run at end of setup() if the reset reason was
   //a firmware update
   evaluateResetReason();
   //Set the Particle time to the retained time
   //Pat the watchdog (start the watchdog timer
   HW_Watchdog.begin();

   myLog.warn("Reset reason: %s:", resetReason);
   myLog.warn("System version: %s", System.version().c_str());
   myLog.warn("setup() end");
}


/*=============================================>>>>>
= MAIN LOOP =
===============================================>>>>>*/

unsigned long lastLoopTimestamp = 0;
const unsigned long LOOP_LATENCY_NOTIFICATION_THRESHOLD = 200;

unsigned long publishTimer = 0;
const unsigned long publishTimeout = 1000*60*5;
unsigned int numPublishes = 0;
unsigned int publishPeriod = 1000*60*5;
unsigned int lastPublishTimestamp = 0;


bool firstConnection = true;
unsigned int firstConnectionTimestamp = 0;
const unsigned int firstConnectionCooldownTillChores = 2000;


enum customConnectionState_t{
   CONNECT_FIRST_STATE,
   CONNECT_CONECTING,
   CONNECT_CONENCTED_WAITING,
   CONNECT_CONNECTED_CHORES,
   CONNECT_IDLE,
   CONNECT_NUM_STATES
};
const char* customConnectionStateNames[CONNECT_NUM_STATES] = {
   "CONNECT_FIRST_STATE",
   "CONNECT_CONECTING",
   "CONNECT_CONENCTED_WAITING",
   "CONNECT_CONNECTED_CHORES",
   "CONNECT_IDLE"
};

customConnectionState_t connectionState = CONNECT_FIRST_STATE;
const unsigned int stateProcessPeriod = 1000; //Process the state machine every 1000 seconds
unsigned int lastStateProcessTimestamp = 0;



void loop(){
   //Show message if its been a long-ass time since last time through this loop
   // if(millis() - lastLoopTimestamp > LOOP_LATENCY_NOTIFICATION_THRESHOLD){
   //    if(lastLoopTimestamp != 0) myLog.warn("%lu since last loop!", millis() - lastLoopTimestamp);
   // }
   // lastLoopTimestamp = millis();


   if((millis() - lastStateProcessTimestamp) > stateProcessPeriod){

      lastStateProcessTimestamp = millis();

      if(connectionState != CONNECT_IDLE) myLog.trace("connection state = %s", customConnectionStateNames[connectionState]);

      //Connecting process state machine
      switch( connectionState ){
         case CONNECT_FIRST_STATE:
            //Call particle.connect
            Particle.connect();
            connectionState = CONNECT_CONECTING;
         break;

         case CONNECT_CONECTING:
            //Wait for particle to connect
            if(Particle.connected()){
               connectionState = CONNECT_CONENCTED_WAITING;
               firstConnectionTimestamp = millis();
            }
         break;

         case CONNECT_CONENCTED_WAITING:
            if((millis() - firstConnectionTimestamp) > firstConnectionCooldownTillChores){
               connectionState = CONNECT_CONNECTED_CHORES;
            }
         break;

         case CONNECT_CONNECTED_CHORES:
            //Set keepAlive
            Particle.keepAlive(10);
            connectionState = CONNECT_IDLE;
         break;

         case CONNECT_IDLE:
         {
            char tempBuf[50];
            char pubEventName[13];
            //Publish something to web every 5 minutes
            if(lastPublishTimestamp == 0){
               snprintf(tempBuf, 50, "firstConnectionTimestamp = %u ms", firstConnectionTimestamp);
               Particle.publish("firstPub", tempBuf);
               numPublishes++;
               lastPublishTimestamp = millis();
            }
            else if((millis() - lastPublishTimestamp) > publishPeriod){
               snprintf(tempBuf, 50, "publish # %u | timestamp %u ms", numPublishes, millis());
               snprintf(pubEventName, 13, "pub%u", numPublishes);
               Particle.publish(pubEventName, tempBuf);
               numPublishes++;
               lastPublishTimestamp = millis();
            }

         }

         break;


      }//End SWITCH


   }

   //Pat the watchdog
   if(!HW_Watchdog.suspended()){
      HW_Watchdog.pat();
   }

   //show the spinning wheel
   showProcessingChars();

   //Check for serial commands
   checkSerialCommands();

}

//Function that takes serial commands from serial monitor
//and executes code based on the content of command
char serCommand[65];

// //Debug
void processSerialCommand(){

   //Analyze incoming serial command
   myLog.warn("SERIAL COMMAND IS: %s", serCommand);

   //Enter DFU mode
   if(strstr(serCommand, "dfu")){
      myLog.warn("DFU mode");
      Serial.flush();
      System.dfu();
   }
   else if(strstr(serCommand, "listen")){
      Cellular.listen();
   }
   else if(strstr(serCommand, "reset")){
      myLog.warn("Resetting");
      Serial.flush();
      System.reset();
   }
   else if(strstr(serCommand, "connect")){
      if(Particle.connected())Particle.disconnect();
      else Particle.connect();
   }
   else if(strstr(serCommand, "testPub")){
      Particle.publish("serialPub", "This is a serial publish test");
   }
}




void checkSerialCommands(){
   unsigned int numBytesAvailable = Serial.available();
   if(numBytesAvailable){
      //Allocate buffer to read serial command
      //Debug
      // printWarning(myLog, __LINE__, "INCOMING SERIAL COMMAND");
      for(unsigned int count = 0; count < numBytesAvailable; count++){
         //Read all incoming bytes
         int newByte = Serial.read();
         if(newByte >= 0){
            char newStr[2] = {(char)newByte, '\0'};
            strcat(serCommand, newStr);
            //Check if we got a carriage return
            if(newByte == 13){
               processSerialCommand();
               //Reset the serial command buffer
               serCommand[0] = '\0';
               return;
            }
         }
         else{
            break;
         }
      }//END for loop
   }//End if numBytesAvailable
}


void evaluateResetReason(){
   //Print out Electron system ID
   // char deviceID[ System.deviceID().length() + 1 ] ;
   // System.deviceID().toCharArray(deviceID, strlen(deviceID));
   // myLog.info("Device ID: %s ", deviceID);

   //Print out reset reason
   // uint32_t resetData = System.resetReasonData();

   switch( System.resetReason() ){
      case RESET_REASON_PIN_RESET:
         snprintf(resetReason, sizeof(resetReason), "%s", "button");
      break;
      case RESET_REASON_POWER_MANAGEMENT:
         snprintf(resetReason, sizeof(resetReason), "%s", "low-power mgmt");
      break;
      case RESET_REASON_POWER_DOWN:
         snprintf(resetReason, sizeof(resetReason), "%s", "power-down");
      break;
      case RESET_REASON_POWER_BROWNOUT:
         snprintf(resetReason, sizeof(resetReason), "%s", "brownout");
      break;
      case RESET_REASON_WATCHDOG:
         snprintf(resetReason, sizeof(resetReason), "%s", "software watchdog");
      break;
      case RESET_REASON_UPDATE:
         snprintf(resetReason, sizeof(resetReason), "%s", "firmware update");
      break;
      case RESET_REASON_UPDATE_TIMEOUT:
         snprintf(resetReason, sizeof(resetReason), "%s", "firmware update timeout");
      break;
      case RESET_REASON_FACTORY_RESET:
         snprintf(resetReason, sizeof(resetReason), "%s", "factory");
      break;
      case RESET_REASON_SAFE_MODE:
         snprintf(resetReason, sizeof(resetReason), "%s", "safe mode");
      break;
      case RESET_REASON_DFU_MODE:
         snprintf(resetReason, sizeof(resetReason), "%s", "DFU");
      break;
      case RESET_REASON_PANIC:
         snprintf(resetReason, sizeof(resetReason), "%s", "panic");
      break;
      case RESET_REASON_USER:
         snprintf(resetReason, sizeof(resetReason), "%s", "user");
         // if( resetData >= 0 && resetData < NUM_APP_REBOOT_REASONS ){
         //    snprintf(resetReason, sizeof(resetReason), "%s %s", "Reset user reason: ", AppRebootReasonNames[resetData]);
         // }
         // else{
         //    // myLog.warn("Invalid user reset data");
         // }

      break;
      case RESET_REASON_UNKNOWN:
         snprintf(resetReason, sizeof(resetReason), "%s", "unspecified");
         //This reset reason happens when new firmware is flashed to Electron over USB
      break;
      case RESET_REASON_NONE:
         snprintf(resetReason, sizeof(resetReason), "%s", "not available");
      break;
   }
   myLog.info("Reset reason: %s:", resetReason);
};


void countDown(unsigned short seconds){
   for(unsigned short count = 0; count < seconds; count++){
      Serial.printlnf("%u", (seconds - count));
      delay(1000);
   }
   Serial.println("GO!!!");
}

/*=============================================>>>>>
= SHOW PROCESSING CHARS ("processing" animated icon) =
===============================================>>>>>*/

const unsigned int LINE_FEED_DEBUG_RATE_MS = 250;
unsigned int lastLineFeedDebugTimestamp = 0;
const uint8_t numProcessingChars = 4;
const char processingChars[numProcessingChars] = {
   '/',
   '|',
   '\\',
   '-',
};
uint8_t processCharCount = 0;

void showProcessingChars(){

   //Print spaces between chunks of debug messages that are spaced apart in time
   if( (millis() - lastLineFeedDebugTimestamp) > LINE_FEED_DEBUG_RATE_MS ){
      lastLineFeedDebugTimestamp = millis();
      Serial.write(8);  //Backspace character
      Serial.print( processingChars[processCharCount] ); //The processing animation char
      if(++processCharCount == numProcessingChars) processCharCount = 0;
   }

}
2 Likes