Xenon won't stay online long enough to flash RC26


#7

Yes it’s up and running with RC26. Unfortunately it hasn’t resolved the SOS issues. I’ll open a support ticket as I assume this is a hardware issue.


#8

You should be able to flash the firmware via USB.
Download the system binary
Put your device in DFU Mode (blinking yellow)
And run

particle flash --usb system-part1-0.8.0-rc.26-xenon.bin -v

After that you can hit reset and should have rc.26. With rc.26 stability should be better and future OTA updates should work better.


other rc.26 binaries can be found here


#9

@ScruffR Could you please explain what the hybrid binaries are for? Also, is it necessary or not to update the bootloader for RC.26? Thanks


#10

Hybrid binaries are mainly used for BLE OTA upgrade from the current factory firmware. They pretend to be monolithic, despite being modular and contain the tinker binary inside as well. For all the normal use-cases, system-part1 should be used.

It’s not necessary to update the bootloader separately, it will be automagically updated if needed.


#11

Thanks


#12

I also have the SOS followed by a 7x Red flash (Exit ?), on my Argon, connected to on Xenon via mesh, and to particle cloud over WiFi.
My applications (i have tried 2 different) boots, and runs for about a minute before SOS’ing and rebooting.

I have seen the issue on RC25 and now RC26. I few times on RC26 the SOS was followed by only 1xRED flash (Hard fault).

What does the 7xRED “exit” error code indicate ?

I have not yet tried running a non-mesh application.


Mesh Firmware 0.8.0.rc.26 Feedback
#14

I’ve also updated my Xenon to RC26 and it is also still SOS/exit. So seems that RC26 has not resolved this SOS/exit issue.


#15

UPDATE: I’ve uploaded new binaries that enable logging from an ISR.

I would appreciate if you could flash the following debug system firmware. They will automatically log on Serial1 @ 115200, you should not instantiate Serial1LogHandler in the user application. Unfortunately we cannot reliably log from an ISR to Serial. If you don’t have an UART-USB adapter, you can use another device running a simple app and connecting its RX to TX of the device being debugged.

SYSTEM_MODE(MANUAL);
void setup(void) {
    Serial1.begin(115200);
    Serial.begin();
    while (true) {
        while (Serial1.available() > 0 && Serial.availableForWrite() > 0) {
            Serial.write(Serial1.read());
        }
    }
}


#16

Hi @avtolstoy

I couldn’t flash the firmware OTA due to the SOS issue. I used DFU mode and flashed it using the particle flash --usb.

I added the USB logging line to my code outside of setup and loop. I then flashed the Xenon which took longer then usual. I hope this didn’t overwrite the system-part1 you provided.

Doesn’t look like there’s anything interesting in the log. Hopefully you think otherwise :slight_smile:

https://drive.google.com/open?id=1qOe8yNmr9lN09k3PLrar7I8iCOeZgkFp

Thanks,
Kev


#17

The is all I get from the output from your SOS7 firmware on the xenon.

0000000001 [system] TRACE: Last reset reason: 140 (data: 0x00)
0000000137 [net.ifapi] TRACE: LwIP started
0000000146 [ot.api] INFO: OpenThread version: OPENTHREAD/0.01.00; Xenon; Dec 14 2018 14:21:18
0000000149 [ot.api] INFO: Max transmit power: 8
0000000268 [ot.api] INFO: Network name: MESH1
0000000269 [ot.api] INFO: 802.15.4 channel: 11
0000000401 [ot.api] INFO: 802.15.4 PAN ID: 0x5733
0000000401 [net.th] INFO: Creating new LwIP OpenThread interface
0000000534 [net.ifapi] INFO: Netif th1 added
0000000536 [net.ifapi] INFO: Netif dm2 added
0000000536 [net.ifapi] INFO: Netif dm2 deleted
0000000668 [hal] TRACE: Heap: 54/171 Kbytes used
0000000668 [net.th] TRACE: OpenThread state changed: 17f333b
0000000805 [system.ctrl.ble] INFO: Device name: Xenon-KN8CML
0000000806 [system.nm] INFO: State changed: NONE -> DISABLED
0000000817 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
0000000935 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000001068 [net.ifapi] INFO: Netif th1 state UP
0000001069 [net.th] INFO: Bringing OpenThreadNetif down
0000001083 [net.th] INFO: Bringing OpenThreadNetif up
0000001201 [net.th] INFO: Network name: MESH1
0000001202 [net.th] INFO: 802.15.4 channel: 11
0000001334 [net.th] INFO: 802.15.4 PAN ID: 0x5733
0000001435 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000001536 [net.th] TRACE: OpenThread state changed: 4
0000001536 [net.th] TRACE: OT_CHANGED_THREAD_ROLE
0000001537 [system.ot] INFO: Role changed: detached
0000002023 [net.th] TRACE: OpenThread state changed: 10e5
0000002023 [net.ifapi] INFO: Netif th1 link UP
0000002024 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0000002098 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002158 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002232 [net.th] TRACE: Added FD61:ECAE:8BB::FF:FE00:FC00 0
0000002291 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002365 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002425 [net.th] TRACE: Added FE80::ECEC:3F91:9C7A:4117 0
0000002498 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002558 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002632 [net.th] TRACE: Added FD61:ECAE:8BB:0:ED37:7A0D:5498:3149 0
0000002691 [net.th] TRACE: OT_CHANGED_IP6_ADDRESS_ADDED
0000002765 [net.th] TRACE: OT_CHANGED_THREAD_ROLE
0000002824 [net.th] TRACE: OT_CHANGED_THREAD_RLOC_ADDED
0000002898 [net.th] TRACE: OT_CHANGED_THREAD_RLOC_REMOVED
0000002958 [net.th] TRACE: OT_CHANGED_THREAD_PARTITION_ID
0000003032 [net.th] TRACE: OT_CHANGED_IP6_MULTICAST_SUBSRCRIBED
0000003091 [system.ot] TRACE: IPv6 address was added
0000003165 [system.ot] INFO: Role changed: leader
0000003165 [system.ot] TRACE: RLOC was added
0000003224 [system.ot] TRACE: RLOC was removed
0000003298 [system.ot] TRACE: Partition ID changed
0000003358 [system.ot] TRACE: Subscribed to IPv6 multicast address
0000003437 [comm] INFO: channel inited
0000003448 [net.th] TRACE: OpenThread state changed: 200
0000003491 [net.th] TRACE: OT_CHANGED_THREAD_NETDATA
0000003565 [net.th] TRACE: Candidate preferred prefix: FD1E:8C1F:8BC::/64, preference = Medium, RLOC16 = 9c00, preferred = 1, stable = 1
0000003699 [net.th] INFO: Switched over to a new preferred prefix: FD1E:8C1F:8BC::/64, preference = Medium, RLOC16 = 9c00, preferred = 1, stable = 1
0000003891 [hal] INFO: DNS server list changed
0000003892 [net.th] INFO: DNS server on mesh network: FD1E:8C1F:8BC::1
0000004024 [system.ot] TRACE: Thread network data changed
0000004099 [net.th] TRACE: OpenThread state changed: 1
0000004099 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000004158 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000004232 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0000004365 [net.th] TRACE: Added FD1E:8C1F:8BC:0:FCD9:7A96:92C:A557 0
0000004424 [net.th] TRACE: OT_CHANGED_IP6_ADDRESS_ADDED
0000004498 [system.ot] TRACE: IPv6 address was added
0000004501 [system] INFO: Cloud: connecting
0000004559 [system] INFO: Read Server Address = type:1,domain:$id.udp-mesh.particle.io
0000004632 [system] INFO: Loaded cloud server address and port from session data
0000004765 [system] TRACE: Address type: 1
0000004766 [system] TRACE: Cloud socket=0, family=10, type=2, protocol=17
0000004898 [system] INFO: Cloud socket=0, connecting to 64:FF9B::36E3:ABAB#5684
0000004958 [system] TRACE: Cloud socket=0, connected to 64:FF9B::36E3:ABAB#5684
0000005032 [system] TRACE: Updating cloud keepalive for AF_INET6: 30000 -> 30000
0000005165 [system] TRACE: Applying new keepalive interval now
0000005166 [system] INFO: Cloud socket connected
0000005225 [system] INFO: Starting handshake: presense_announce=0
0000005299 [comm.protocol.handshake] INFO: Establish secure connection
0000005549 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=0
0000005549 [comm.dtls] INFO: out_ctr 0,1,0,0,0,0,0,25, next_coap_id=11
0000005625 [comm.dtls] INFO: app state crc: cached: 87f5edde, actual: 5cdd4e9d
0000005683 [comm.dtls] INFO: restored session from persisted session data. next_msg_id=17
0000005758 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 2
0000005817 [comm.protocol.handshake] INFO: Sending HELLO message
0000006205 [comm.protocol.handshake] INFO: Handshake completed
0000006206 [system] INFO: Send spark/hardware/max_binary event
0000006210 [system] INFO: Send spark/device/last_reset event
0000006341 [system] INFO: Send subscriptions
0000006342 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000006473 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000006474 [comm] INFO: Sending TIME request
0000006608 [comm.protocol] INFO: Sending 'M' describe message
0000006609 [comm.protocol] INFO: rcv'd message type=1
0000006740 [system] INFO: Cloud connected
0000006740 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000006749 [comm.protocol] INFO: message id 20 complete with code 0.00
0000006873 [comm.protocol] INFO: rcv'd message type=13
0000006883 [system] TRACE: Updating cloud keepalive for AF_INET6: 30000 -> 30000
0000007007 [system] TRACE: Applying new keepalive interval now
0000007140 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000007140 [comm.protocol] INFO: message id 21 complete with code 0.00
0000007273 [comm.protocol] INFO: rcv'd message type=13
0000007883 [comm.protocol] TRACE: Reply recieved: type=2, code=69
0000007883 [comm.protocol] INFO: message id 22 complete with code 2.05
0000007936 [comm.protocol] INFO: Received TIME response: 1544780577
0000008017 [comm.protocol] INFO: rcv'd message type=12
0000008883 [comm] INFO: Forcing a cloud ping
0000009068 [comm.protocol] INFO: Sending 'S' describe message
0000009072 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000009318 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000009318 [comm.protocol] INFO: rcv'd message type=1
0000009883 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000009883 [comm.protocol] INFO: message id 23 complete with code 0.00
0000010016 [comm.protocol] INFO: rcv'd message type=13
0000010882 [comm] INFO: Forcing a cloud ping
0000010884 [comm.protocol] INFO: Sending 'A' describe message
0000010886 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000010948 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000011064 [comm.protocol] INFO: rcv'd message type=1
0000012067 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000012068 [comm.protocol] INFO: message id 24 complete with code 0.00
0000012089 [comm.protocol] INFO: rcv'd message type=13
0000013066 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000013066 [comm.protocol] INFO: message id 19 complete with code 0.00
0000013152 [comm.protocol] INFO: rcv'd message type=13
0000044067 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000044067 [comm.protocol] INFO: message id 25 complete with code 0.00
0000044085 [comm.protocol] INFO: rcv'd message type=13
0000075068 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000075068 [comm.protocol] INFO: message id 26 complete with code 0.00
0000075150 [comm.protocol] INFO: rcv'd message type=13
0000106153 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000106153 [comm.protocol] INFO: message id 27 complete with code 0.00
0000106166 [comm.protocol] INFO: rcv'd message type=13
0000000001 [system] INFO: Device e00fce680ce097caaa31e5fa started
0000000001 [system] TRACE: Last reset reason: 130 (data: 0x0a)
0000000137 [net.ifapi] TRACE: LwIP started
0000000146 [ot.api] INFO: OpenThread version: OPENTHREAD/0.01.00; Xenon; Dec 14 2018 14:21:18
0000000149 [ot.api] INFO: Max transmit power: 8
0000000268 [ot.api] INFO: Network name: MESH1
0000000269 [ot.api] INFO: 802.15.4 channel: 11
0000000401 [ot.api] INFO: 802.15.4 PAN ID: 0x5733
0000000401 [net.th] INFO: Creating new LwIP OpenThread interface
0000000534 [net.ifapi] INFO: Netif th1 added
0000000536 [net.ifapi] INFO: Netif dm2 added
0000000536 [net.ifapi] INFO: Netif dm2 deleted
0000000668 [hal] TRACE: Heap: 54/171 Kbytes used
0000000668 [net.th] TRACE: OpenThread state changed: 17f333b
0000000805 [system.ctrl.ble] INFO: Device name: Xenon-KN8CML
0000000806 [system.nm] INFO: State changed: NONE -> DISABLED
0000000817 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
0000000935 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000001068 [net.ifapi] INFO: Netif th1 state UP
0000001069 [net.th] INFO: Bringing OpenThreadNetif down
0000001083 [net.th] INFO: Bringing OpenThreadNetif up
0000001201 [net.th] INFO: Network name: MESH1
0000001202 [net.th] INFO: 802.15.4 channel: 11
0000001335 [net.th] INFO: 802.15.4 PAN ID: 0x5733
0000001435 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000001538 [net.th] TRACE: OpenThread state changed: 4
0000001538 [net.th] TRACE: OT_CHANGED_THREAD_ROLE
0000001538 [system.ot] INFO: Role changed: detached
0000002025 [net.th] TRACE: OpenThread state changed: 10e5
0000002025 [net.ifapi] INFO: Netif th1 link UP
0000002026 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0000002101 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002160 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002234 [net.th] TRACE: Added FD61:ECAE:8BB::FF:FE00:FC00 0
0000002293 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002367 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002427 [net.th] TRACE: Added FE80::ECEC:3F91:9C7A:4117 0
0000002500 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002560 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000002634 [net.th] TRACE: Added FD61:ECAE:8BB:0:ED37:7A0D:5498:3149 0
0000002693 [net.th] TRACE: OT_CHANGED_IP6_ADDRESS_ADDED
0000002767 [net.th] TRACE: OT_CHANGED_THREAD_ROLE
0000002826 [net.th] TRACE: OT_CHANGED_THREAD_RLOC_ADDED
0000002900 [net.th] TRACE: OT_CHANGED_THREAD_RLOC_REMOVED
0000002960 [net.th] TRACE: OT_CHANGED_THREAD_PARTITION_ID
0000003034 [net.th] TRACE: OT_CHANGED_IP6_MULTICAST_SUBSRCRIBED
0000003093 [system.ot] TRACE: IPv6 address was added
0000003167 [system.ot] INFO: Role changed: leader
0000003167 [system.ot] TRACE: RLOC was added
0000003226 [system.ot] TRACE: RLOC was removed
0000003300 [system.ot] TRACE: Partition ID changed
0000003360 [system.ot] TRACE: Subscribed to IPv6 multicast address
0000003439 [comm] INFO: channel inited
0000003457 [net.th] TRACE: OpenThread state changed: 200
0000003493 [net.th] TRACE: OT_CHANGED_THREAD_NETDATA
0000003567 [net.th] TRACE: Candidate preferred prefix: FD1E:8C1F:8BC::/64, preference = Medium, RLOC16 = 9c00, preferred = 1, stable = 1
0000003701 [net.th] INFO: Switched over to a new preferred prefix: FD1E:8C1F:8BC::/64, preference = Medium, RLOC16 = 9c00, preferred = 1, stable = 1
0000003893 [hal] INFO: DNS server list changed
0000003894 [net.th] INFO: DNS server on mesh network: FD1E:8C1F:8BC::1
0000004026 [system.ot] TRACE: Thread network data changed
0000004102 [net.th] TRACE: OpenThread state changed: 1
0000004103 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000004161 [net.ifapi] TRACE: Netif th1 ipv6 addr state changed
0000004235 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0000004367 [net.th] TRACE: Added FD1E:8C1F:8BC:0:F1FC:D97A:9609:2CA5 0
0000004426 [net.th] TRACE: OT_CHANGED_IP6_ADDRESS_ADDED
0000004500 [system.ot] TRACE: IPv6 address was added
0000004502 [system] INFO: Cloud: connecting
0000004561 [system] INFO: Read Server Address = type:1,domain:$id.udp-mesh.particle.io
0000004634 [system] INFO: Loaded cloud server address and port from session data
0000004767 [system] TRACE: Address type: 1
0000004768 [system] TRACE: Cloud socket=0, family=10, type=2, protocol=17
0000004901 [system] INFO: Cloud socket=0, connecting to 64:FF9B::36E3:ABAB#5684
0000004960 [system] TRACE: Cloud socket=0, connected to 64:FF9B::36E3:ABAB#5684
0000005034 [system] TRACE: Updating cloud keepalive for AF_INET6: 30000 -> 30000
0000005167 [system] TRACE: Applying new keepalive interval now
0000005168 [system] INFO: Cloud socket connected
0000005227 [system] INFO: Starting handshake: presense_announce=0
0000005301 [comm.protocol.handshake] INFO: Establish secure connection
0000005551 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=0
0000005551 [comm.dtls] INFO: out_ctr 0,1,0,0,0,0,0,39, next_coap_id=1b
0000005626 [comm.dtls] INFO: app state crc: cached: 5cdd4e9d, actual: 5cdd4e9d
0000005685 [comm.dtls] WARN: skipping hello message
0000005759 [comm.dtls] INFO: restored session from persisted session data. next_msg_id=27
0000005819 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 2
0000005893 [comm.protocol.handshake] INFO: resumed session - not sending HELLO message
0000006028 [system] INFO: Send spark/hardware/max_binary event
0000006087 [system] INFO: Send spark/device/last_reset event
0000006161 [system] INFO: Send subscriptions
0000006162 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000006219 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000006293 [comm] INFO: Sending TIME request
0000006354 [system] INFO: Cloud connected
0000007429 [system] TRACE: Updating cloud keepalive for AF_INET6: 30000 -> 30000
0000007429 [system] TRACE: Applying new keepalive interval now
0000007482 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000007563 [comm.protocol] INFO: message id 28 complete with code 0.00
0000007615 [comm.protocol] INFO: rcv'd message type=13
0000008429 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000008429 [comm.protocol] INFO: message id 29 complete with code 0.00
0000008528 [comm.protocol] INFO: rcv'd message type=13
0000009429 [comm] INFO: Forcing a cloud ping
0000009431 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000009431 [comm.protocol] INFO: message id 30 complete with code 0.00
0000009563 [comm.protocol] INFO: rcv'd message type=13


#18

@johnnyfp @JumpMaster Thank you for trying the binaries I’ve posted. Seems that the issue comes from an ISR and we don’t enable logging from an ISR by default when instantiating log handlers in user application.

I’ve uploaded new binaries here. I would appreciate if you could try those out. They will automatically log on Serial1 @ 115200, you should not instantiate Serial1LogHandler in the user application. Unfortunately we cannot reliably log from an ISR to Serial. If you don’t have an UART-USB adapter, you can use another device running a simple app and connecting its RX to TX of the device being debugged.

SYSTEM_MODE(MANUAL);
void setup(void) {
    Serial1.begin(115200);
    Serial.begin();
    while (true) {
        while (Serial1.available() > 0 && Serial.availableForWrite() > 0) {
            Serial.write(Serial1.read());
        }
    }
}


#19

@avtolstoy

Thanks for providing the code. It made using a Photon as a UART-USB device simple. Here’s the full log but the line you’re after is

0000120401 [hal] ERROR: Assertion failed: openthread/third_party/NordicSemiconductor/drivers/radio/raal/softdevice/nrf_raal_softdevice.c:236 timer_jitter_adjust (cc_margin > rtc_tick~

https://drive.google.com/open?id=1qOe8yNmr9lN09k3PLrar7I8iCOeZgkFp


#20

Thank you! Could you please also time how long it approximately takes for the device to SOS after reset?

We are currently working with two theories about the root cause of this issue, could you please see if either test1 or test2 binaries resolve it? Please note that test2 might simply take more time for the issue to appear.


#21

It’s consistently 2:20 between reboots. I’ll give the two binaries a try now.


#22

No change with either I’m afraid. Same error before the SOS after 2:18.


#23

Thank you for testing and confirming. We’ll continue investigating this internally and I’ll post an update once we have some news.


#24

I’ve got an Argon that is also showing the SOS7 behavior. It consistently crashes exactly two minutes after reset, but only when configured with a mesh network, not when using just wifi. I had this issue with RC25 and confirmed that it still exists with RC26.


#25

So I’ve installed RC27 and the xenon has now been up for the last 40minutes with no SOS. Looks like this firmware has fixed the issue.


#26

Hello folks,

Wanted to follow-up with this thread to let everyone know that a fix for the SOS-7 issue has been released with v0.8.0-rc.27. The issues was tracked to a problem with the Nordic 802.15.4 driver. Instructions for upgrading are available below. We’d love to know if applying the release fixes the issue SOS-7 issue that you’re experiencing.


Note that we have seen some reports of change in behavior for rc.27 when users call the Mesh.subscribe() function within the setup() loop that can result in a separate SOS-10 code which we’re currently investigating. If this issue affects you, please note the following workaround.


#27

I’ve had my Argon and two Xenons online for 2.5 hours running a Marco Polo test across the mesh. It hasn’t dropped a single one.

VERY stable so far!