Hi there,
Summary
When my electron runs DeviceOS 1.3.1 or higher, it fails to register cloud functions and variables. They do not show up in the web console and calling them from the cli using particle call yields Function call failed: Function ping not found.
steps to reproduce:
Code
The content of my main .ino file:
unsigned int lastLogTime = 0;
int ping(String command) {
return 1;
}
void setup() {
Particle.function("ping", ping);
Particle.variable("test", "test");
}
void loop() {
if (millis() - lastLogTime > 30000) { // do this once every 30s
Particle.publish("test",PRIVATE);
lastLogTime = millis();
}
}
Flash
Flash this code to the electron, having selected DeviceOS >= 1.3.1
Result
When flashing is finished, we expect the device page in the web console to show a function called ping and a variable called test. Instead it shows no functions and no variables. Calling the function from the cli using particle call <device> ping yields an error: Function call failed: Function ping not found.
We can see that the application is running and connected since it succeeds in publishing the test event every 30 seconds.
Downgrade
After downgrading DeviceOS (e.g. using a monolithic build) to a lower version, all works as expected.
Logs
The output of the flash command:
> Executing task: make -f '/home/luuk/.particle/toolchains/buildscripts/1.8.0/Makefile' flash-debug -s <
:::: PUTTING DEVICE INFO DFU MODE
Done.
:::: FLASHING APPLICATION FOR DEBUG
text data bss dec hex filename
285684 3048 9624 298356 48d74 /media/luuk/Data/development/afbuza/openr-particle/monolithic-test/monolithic-test/target/1.4.4/electron/monolithic-test.elf
Serial device PARTICLE_SERIAL_DEV : not available
Flashing using dfu:
dfu-util 0.9
Copyright 2005-2009 Weston Schmidt, Harald Welte and OpenMoko Inc.
Copyright 2010-2016 Tormod Volden and Stefan Schmidt
This program is Free Software and has ABSOLUTELY NO WARRANTY
Please report bugs to http://sourceforge.net/p/dfu-util/tickets/
Opening DFU capable USB device...
ID 2b04:d00a
Run-time device DFU version 011a
Claiming USB DFU Interface...
Setting Alternate Setting #0 ...
Determining device status: state = dfuIDLE, status = 0
dfuIDLE, continuing
DFU mode device DFU version 011a
Device returned transfer size 4096
DfuSe interface name: "Internal Flash "
Downloading to address = 0x08020000, size = 288736
Download [=========================] 100% 288736 bytes
Download done.
File downloaded successfully
> ONCE YOU ARE FINISHED DEBUGGING REMEMBER TO RUN `Particle: Flash application & DeviceOS (local)` <
*** FLASHED SUCCESSFULLY ***
Serial monitor of the monolithic build @ DeviceOS 1.4.4 with SerialLogHandler logHandler(LOG_LEVEL_ALL); prepended to code:
1.676 AT send 4 "AT\r\n"
1.679 AT read OK 6 "\r\nOK\r\n"
1.679 AT send 9 "AT+CGMM\r\n"
1.684 AT read UNK 13 "\r\nSARA-U270\r\n"
1.685 AT read OK 6 "\r\nOK\r\n"
1.886 AT send 6 "ATE0\r\n"
1.890 AT read OK 6 "\r\nOK\r\n"
1.890 AT send 11 "AT+CMEE=2\r\n"
1.895 AT read OK 6 "\r\nOK\r\n"
1.895 AT send 19 "AT+CMER=1,0,0,2,1\r\n"
1.900 AT read OK 6 "\r\nOK\r\n"
1.900 AT send 15 "AT+IPR=115200\r\n"
1.905 AT read OK 6 "\r\nOK\r\n"
2.005 AT send 10 "AT+CPIN?\r\n"
2.011 AT read + 16 "\r\n+CPIN: READY\r\n"
2.012 AT read OK 6 "\r\nOK\r\n"
[ Modem::init ] = = = = = = = = = = = = = = =
2.012 AT send 9 "AT+CGSN\r\n"
2.029 AT read UNK 19 "\r\n352253065026071\r\n"
2.030 AT read OK 6 "\r\nOK\r\n"
2.030 AT send 9 "AT+CGMI\r\n"
2.034 AT read UNK 10 "\r\nu-blox\r\n"
2.035 AT read OK 6 "\r\nOK\r\n"
2.035 AT send 9 "AT+CGMR\r\n"
2.040 AT read UNK 9 "\r\n23.20\r\n"
2.041 AT read OK 6 "\r\nOK\r\n"
2.041 AT send 6 "ATI9\r\n"
2.056 AT read UNK 16 "\r\n23.20,A01.01\r\n"
2.057 AT read OK 6 "\r\nOK\r\n"
2.057 AT send 9 "AT+CCID\r\n"
2.063 AT read + 30 "\r\n+CCID: 8934076500002972677\r\n"
2.064 AT read OK 6 "\r\nOK\r\n"
2.064 AT send 11 "AT+CMGF=1\r\n"
2.068 AT read OK 6 "\r\nOK\r\n"
2.068 AT send 13 "AT+CNMI=2,1\r\n"
2.072 AT read OK 6 "\r\nOK\r\n"
2.072 AT send 9 "AT+CIMI\r\n"
2.078 AT read UNK 19 "\r\n214074301595063\r\n"
2.079 AT read OK 6 "\r\nOK\r\n"
2.079 AT send 13 "AT+COPS=3,2\r\n"
2.084 AT read OK 6 "\r\nOK\r\n"
2.084 AT send 11 "AT+UPSV=1\r\n"
2.089 AT read OK 6 "\r\nOK\r\n"
0000002089 [system] INFO: Sim Ready
0000002089 [system] INFO: ARM_WLAN_WD 1
[ Modem::register ] = = = = = = = = = = = = = =
2.090 AT send 12 "AT+CGREG=2\r\n"
2.094 AT read OK 6 "\r\nOK\r\n"
2.094 AT send 11 "AT+CREG=2\r\n"
2.099 AT read OK 6 "\r\nOK\r\n"
2.099 AT send 10 "AT+CREG?\r\n"
2.106 AT read + 32 "\r\n+CREG: 2,5,\"1892\",\"AB8423\",6\r\n"
2.107 AT read OK 6 "\r\nOK\r\n"
2.107 AT send 11 "AT+CGREG?\r\n"
2.114 AT read + 38 "\r\n+CGREG: 2,5,\"1892\",\"AB8423\",6,\"00\"\r\n"
2.116 AT read OK 6 "\r\nOK\r\n"
2.116 AT send 4 "AT\r\n"
2.119 AT read OK 6 "\r\nOK\r\n"
2.119 AT send 13 "AT+COPS=3,2\r\n"
2.124 AT read OK 6 "\r\nOK\r\n"
2.124 AT send 10 "AT+COPS?\r\n"
2.131 AT read + 24 "\r\n+COPS: 0,2,\"20408\",2\r\n"
2.132 AT read OK 6 "\r\nOK\r\n"
2.132 AT send 8 "AT+CSQ\r\n"
2.137 AT read + 14 "\r\n+CSQ: 14,3\r\n"
2.138 AT read OK 6 "\r\nOK\r\n"
[ Modem::join ] = = = = = = = = = = = = = = = =
2.138 AT send 4 "AT\r\n"
2.141 AT read OK 6 "\r\nOK\r\n"
2.141 AT send 12 "AT+CGATT=1\r\n"
2.146 AT read OK 6 "\r\nOK\r\n"
2.146 AT send 14 "AT+UPSND=0,8\r\n"
2.153 AT read + 17 "\r\n+UPSND: 0,8,1\r\n"
2.154 AT read OK 6 "\r\nOK\r\n"
2.154 AT send 14 "AT+UPSND=0,0\r\n"
2.162 AT read + 31 "\r\n+UPSND: 0,0,\"10.47.179.174\"\r\n"
2.163 AT read OK 6 "\r\nOK\r\n"
2.163 AT send 14 "AT+UPSND=0,1\r\n"
2.170 AT read + 30 "\r\n+UPSND: 0,1,\"80.58.61.250\"\r\n"
2.171 AT read OK 6 "\r\nOK\r\n"
2.171 AT send 14 "AT+UPSND=0,2\r\n"
2.178 AT read + 30 "\r\n+UPSND: 0,2,\"80.58.61.254\"\r\n"
2.179 AT read OK 6 "\r\nOK\r\n"
0000002179 [system] INFO: ARM_WLAN_WD 2
0000002179 [system] INFO: CLR_WLAN_WD 1, DHCP success
0000002180 [comm] TRACE: UDP enabled 1
0000002180 [comm] TRACE: creating DTLS protocol
0000002209 [comm] INFO: channel inited
0000002209 [system] INFO: Cloud: connecting
0000002211 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000002212 [system] INFO: Loaded cloud server address and port from session data
2.212 AT send 4 "AT\r\n"
2.216 AT read OK 6 "\r\nOK\r\n"
2.216 AT send 15 "AT+USOCTL=0,0\r\n"
2.222 AT read + 19 "\r\n+USOCTL: 0,0,17\r\n"
2.223 AT read OK 6 "\r\nOK\r\n"
Socket handle 0 (UDP) open, closing...
2.223 AT send 12 "AT+USOCL=0\r\n"
2.489 AT read OK 6 "\r\nOK\r\n"
Socket handle 0 was closed.
2.489 AT send 15 "AT+USOCTL=1,0\r\n"
2.497 AT read ERR 37 "\r\n+CME ERROR: operation not allowed\r\n"
2.497 AT send 15 "AT+USOCTL=2,0\r\n"
2.506 AT read ERR 37 "\r\n+CME ERROR: operation not allowed\r\n"
2.506 AT send 15 "AT+USOCTL=3,0\r\n"
2.515 AT read ERR 37 "\r\n+CME ERROR: operation not allowed\r\n"
2.515 AT send 15 "AT+USOCTL=4,0\r\n"
2.524 AT read ERR 37 "\r\n+CME ERROR: operation not allowed\r\n"
2.524 AT send 15 "AT+USOCTL=5,0\r\n"
2.533 AT read ERR 37 "\r\n+CME ERROR: operation not allowed\r\n"
2.533 AT send 15 "AT+USOCTL=6,0\r\n"
2.542 AT read ERR 37 "\r\n+CME ERROR: operation not allowed\r\n"
socketSocket: closed/freed stale socket handle(s)
socketSocket(UDP)
2.543 AT send 18 "AT+USOCR=17,5684\r\n"
2.550 AT read + 13 "\r\n+USOCR: 0\r\n"
2.551 AT read OK 6 "\r\nOK\r\n"
Socket 0: handle 0 was created
0000002551 [system] TRACE: Connection attempt to 3.210.194.186:5684
0000002551 [system] INFO: Cloud socket connected
0000002552 [system] INFO: Starting handshake: presense_announce=0
0000002552 [comm.protocol.handshake] INFO: Establish secure connection
0000002562 [comm.dtls] WARN: session has 0 uses
0000002566 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=0
0000002566 [comm.dtls] INFO: out_ctr 0,1,0,0,0,0,0,18, next_coap_id=a
0000002566 [comm.dtls] INFO: app state crc: cached: 7427e93f, actual: 7427e93f
0000002567 [comm.dtls] WARN: skipping hello message
0000002567 [comm.dtls] INFO: restored session from persisted session data. next_msg_id=10
0000002568 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 2
0000002568 [comm.protocol.handshake] INFO: resumed session - not sending HELLO message
0000002569 [comm.coap] TRACE: sending message id=b
socketSendTo(0,3.210.194.186,5684,,46)
2.569 AT send 36 "AT+USOST=0,\"3.210.194.186\",5684,46\r\n"
2.577 AT read > 3 "\r\n@"
2.577 AT send 46 "\xfe\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\x12\x00\x14\x00\x01\x00\x00\x00\x00\x00\x12\xe5<\xaa\x13\xcaf\xb7\xd2\x15z\x96\x939\x00/\x00\x04Q541876\f"
2.713 AT read + 16 "\r\n+USOST: 0,46\r\n"
2.714 AT read OK 6 "\r\nOK\r\n"
2.714 AT send 4 "AT\r\n"
2.717 AT read OK 6 "\r\nOK\r\n"
2.717 AT send 14 "AT+USORF=0,0\r\n"
2.723 AT read + 15 "\r\n+USORF: 0,0\r\n"
Socket 0: handle 0 has 0 bytes pending
2.724 AT read OK 6 "\r\nOK\r\n"
0000002724 [system] INFO: cloud connected from existing session.
0000002724 [comm.coap] TRACE: sending message id=c
socketSendTo(0,3.210.194.186,5684,,86)
2.725 AT send 36 "AT+USOST=0,\"3.210.194.186\",5684,86\r\n"
2.733 AT read > 3 "\r\n@"
2.733 AT send 86 "\xfe\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\x13\x00<\x00\x01\x00\x00\x00\x00\x00\x13\xe2\xd4\x9f\x9cN\x03\x8f\x91}>~\xbe\xa0$qm\xec4-\xff7v\x81\xbe\x8e\xa1\x97|F*\xd9\xc4*\x13\x17e\xa1q\xc3]+\xaa\xd7#\xccZ\xd4\x1f2v8\x8b9\x00/\x00\x04Q541876\f"
2.877 AT read + 16 "\r\n+USOST: 0,86\r\n"
2.878 AT read OK 6 "\r\nOK\r\n"
2.878 AT send 4 "AT\r\n"
2.881 AT read OK 6 "\r\nOK\r\n"
2.881 AT send 14 "AT+USORF=0,0\r\n"
2.887 AT read + 15 "\r\n+USORF: 0,0\r\n"
Socket 0: handle 0 has 0 bytes pending
2.888 AT read OK 6 "\r\nOK\r\n"
0000002888 [comm.coap] TRACE: sending message id=d
socketSendTo(0,3.210.194.186,5684,,86)
2.888 AT send 36 "AT+USOST=0,\"3.210.194.186\",5684,86\r\n"
2.896 AT read > 3 "\r\n@"
2.896 AT send 86 "\xfe\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\x14\x00<\x00\x01\x00\x00\x00\x00\x00\x14\xd4\x03J\x1a\xd6\xd2\x10\xc1\xe9\x84\xb8\x11[\xecd\x8e\x1f\xa0\x9bS\xa4\xccR\xab\x94\xfaH\xd6\xac\x9b\xeb\x04\xdbW\x1c\xc0q\xe7\xb1\xa4(\xc1\xe7d\xad\xe6\xf0\xfd\xd6\vR\x829\x00/\x00\x04Q541876\f"
3.036 AT read + 16 "\r\n+USOST: 0,86\r\n"
3.037 AT read OK 6 "\r\nOK\r\n"
3.037 AT send 4 "AT\r\n"
3.040 AT read OK 6 "\r\nOK\r\n"
3.040 AT send 14 "AT+USORF=0,0\r\n"
3.046 AT read + 15 "\r\n+USORF: 0,0\r\n"
Socket 0: handle 0 has 0 bytes pending
3.047 AT read OK 6 "\r\nOK\r\n"
0000003047 [system] TRACE: Waiting until all handshake messages are processed by the protocol layer
3.772 AT read + 17 "\r\n+UUSORD: 0,33\r\n"
Socket 0: handle 0 has 33 bytes pending
3.773 AT send 17 "AT+USORF=0,1024\r\n"
3.784 AT read + 73 "\r\n+USORF: 0,\"3.210.194.186\",5684,33,\"\x17\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\x12\x00\x14\x00\x01\x00\x00\x00\x00\x00\x12R\x10\x9bj\xc5\x86c\xfa\xa5ORi\"\r\n"
3.787 AT read OK 4 "OK\r\n"
3.787 AT send 4 "AT\r\n"
3.787 AT read + 17 "\r\n+UUSORF: 0,66\r\n"
Socket 0: handle 0 has 66 bytes pending
3.790 AT read OK 6 "\r\nOK\r\n"
3.790 AT send 14 "AT+USORF=0,0\r\n"
3.795 AT read + 16 "\r\n+USORF: 0,66\r\n"
Socket 0: handle 0 has 66 bytes pending
3.796 AT read OK 6 "\r\nOK\r\n"
0000003796 [system] TRACE: received 33
0000003796 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000003796 [comm.coap] TRACE: recieved ACK for message id=b
0000003797 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000003797 [comm.protocol] INFO: message id 11 complete with code 0.00
0000003797 [comm.protocol] INFO: rcv'd message type=13
3.809 AT send 17 "AT+USORF=0,1024\r\n"
3.820 AT read + 73 "\r\n+USORF: 0,\"3.210.194.186\",5684,33,\"\x17\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\x13\x00\x14\x00\x01\x00\x00\x00\x00\x00\x13@P\xd6\v_y:Yo\x83\xd9E\"\r\n"
3.823 AT read OK 4 "OK\r\n"
0000003823 [system] TRACE: received 33
0000003823 [comm.coap] TRACE: recieved ACK for message id=c
0000003823 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000003823 [comm.protocol] INFO: message id 12 complete with code 0.00
0000003824 [comm.protocol] INFO: rcv'd message type=13
3.825 AT read + 17 "\r\n+UUSORF: 0,33\r\n"
Socket 0: handle 0 has 33 bytes pending
3.835 AT send 17 "AT+USORF=0,1024\r\n"
3.846 AT read + 73 "\r\n+USORF: 0,\"3.210.194.186\",5684,33,\"\x17\xfe\xfd\x00\x01\x00\x00\x00\x00\x00\x14\x00\x14\x00\x01\x00\x00\x00\x00\x00\x14'HX!/\xc6\x86\xba\t\xbe\xd9\xf2\"\r\n"
3.849 AT read OK 4 "OK\r\n"
3.849 AT send 4 "AT\r\n"
3.852 AT read OK 6 "\r\nOK\r\n"
3.852 AT send 14 "AT+USORF=0,0\r\n"
3.857 AT read + 15 "\r\n+USORF: 0,0\r\n"
Socket 0: handle 0 has 0 bytes pending
3.858 AT read OK 6 "\r\nOK\r\n"
0000003858 [system] TRACE: received 33
0000003858 [comm.coap] TRACE: recieved ACK for message id=d
0000003858 [system] INFO: All handshake messages have been processed
0000003859 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000003859 [comm.protocol] INFO: message id 13 complete with code 0.00
0000003859 [comm.protocol] INFO: rcv'd message type=13
0000003871 [system] INFO: Cloud connected