Photon on GWS gives panic, hard_fault


#1

I have had a BluzDK happily posting data for a few weeks, through a Photon+GWS. All brand new from a month ago.
Suddenly the BluzDK went offline, but the LED blinks cyan every two seconds. So, it thinks it’s online.
I then started the console to look at the events.
The photon on the GWS randomly goes offline, then the Bluz also goes offline.
The message from the Photon is panic, hard_fault. Then it reboots and goes back online.
A few seconds later the Photon reports the device ID of the GWS.
A few seconds later the BluzDK goes online.

The Photon breathes cyan, the GWS blinks white every 2sec and the Bluz blink cyan.
I open the Particle app on my Android.
The Photon and the GWS are online The Bluz is not, but still blinking cyan.
If I open the WebIDE, it gives me a magenta blink for the Bluz, while the Photon and the GWS breathe cyan.

The Photon and the GWS have been online for a few hours now without problems, but I still can’t talk to the BluzDK. It blinks cyan every 2sec, but it’s not online. This is confusing.
I cycled power to the Bluz and the Photon gave went into panic again.

I have tried a second Bluz and it behaves the same way.

I have another Photon on the same net and it never has any issues. I can change its code and it takes the changes.
So, that rules out internet problems. I could swap the Photons, but I am trying to avoid taking apart that project… complicated.
I would like a few pointers to debug first.
I read about hot-plugging the Photon to the GWS, no changes.
The resistor pull-ups I read about don’t seem to fix any problems, so I have not tried.

The Photon on the GWS has the gateway code from the WebIDE. Its FW version is 0.6.3. The GWS is 2.2.50.
I flashed the Photon again with the gateway code, but nothing changed.
I looked at http://staging-console.bluz.io/ and I see the GWS device ID and picture.

The Bluz is still running my code from the last time I was able to flash it. It consists of reading an LM35 and a
battery gauge chip on I2C. I know because it blinks D7 every 15 sec, when it reads the temperature.

Do I need to do anything to the Photon besides loading the gateway code? What about the coexistence pins?
Does the Photon put out any info on serial? How would I read it?

I am stuck, I appreciate any help you can provide.
Pescatore


#2

Sorry for the troubles, that is odd it would randomly start happening. Was there anything that could have happened leading up to the problem? No FW updates anywhere? And nothing got dropped/shorted or anything like that? No power surges?

The Photon does output console logging. You should just be able to plug a USB cable in between it and your computer and open the port with your favorite serial monitor software at speed 38400. If you can capture a log and post it here from startup of the device to the point it fails, that can help us debug.

When you say:
The Photon and the GWS have been online for a few hours now without problems, but I still can’t talk to the BluzDK. It blinks cyan every 2sec, but it’s not online. This is confusing.

How are you determining that bluz is not online? By checking the Particle system? Or is there data supposed to be coming from it that is not? I have found the status of offline/online in Particle can sometimes not always be correct (even for Photons). So it may be good to have bluz publish some data every 10 minutes or something to determine if it really is offline.

One other thought, how are you powering bluz? If it is through a battery, is the battery getting low?

You shouldn’t need to worry about hot plugging the Photon, that was an issue with the first version of the gateway FW which has since been fixed. Same with the resistors, that isn’t a problem anymore.


#3

All the devices were sitting on a desk, powered up for a couple weeks. I sent updates during that time and everything worked fine. No one touched them or dropped them.
The GWS with its photon is powered from and old Samsung phone charger, except when capturing the log it is powered by the PC USB port.
The Bluz is plugged into an Electron Power Shield, also connected to a wall charger.
I don’t know if there has been a power surge. It all started a few days ago and we haven’t had any bad storms.

I determine the online status three different ways: The WebIDE, the Android app and the Particle desktop IDE.
All agree that the Bluz is not online, even though it breathes cyan. I cannot update the code OTA, so I cannot add the publish function. The code that is loaded has a few variables that I used to be able to read with the Android app.

I was able to get the console log, but my terminal program (RealTerm) is fussy and disconnects from the serial port when the Photon crashes. It does not stay connected.
PuTTY complains that the serial port does not exist. Do you have another option for Windows 7?

This is a snippet of what I was able to capture while the Photon is up.

2778156:DEBUG: Receiving Network data of size 40
2778156:DEBUG: About to fill buffer
2778157:DEBUG: Available: 45 Filled: 45
2778157:DEBUG: Buffer filled with 45
2778157:DEBUG: About to send through SPI
2778157:DEBUG: Starting to send data
2778209:DEBUG: Completed Sending
2778209:DEBUG: 0->BLE    - 45
2784405:DEBUG: In SPI Receive
2784405:DEBUG: Handshake complete
2784410:DEBUG: Receiving SPI data of size 23
2784410:DEBUG: Reading chunk of size 23
2784416:DEBUG: Processing message of size 20 with clientID 3 and service ID 1
2784416:DEBUG: 3->Cloud  - 18
2784417:DEBUG: Read length = 18
2784417:DEBUG: All done in SPI Retreive

I reset the Bluz and this is what the log showed:

3250902:DEBUG: Receiving Network data of size 18
3250902:DEBUG: About to fill buffer
3250903:DEBUG: Available: 23 Filled: 23
3250903:DEBUG: Buffer filled with 23
3250903:DEBUG: About to send through SPI
3250905:DEBUG: Starting to send data
3250956:DEBUG: Completed Sending
3250956:DEBUG: 3->BLE    - 23
3263917:DEBUG: In SPI Receive
3263917:DEBUG: Handshake complete
3263922:DEBUG: Receiving SPI data of size 28
3263922:DEBUG: Reading chunk of size 28
3263928:DEBUG: Processing message of size 25 with clientID 0 and service ID 1
3263928:DEBUG: Connecting Client0
3264250:DEBUG: Read length = 23
3264250:DEBUG: All done in SPI Retreive
3264251:DEBUG: Receiving Network data of size 40
3264251:DEBUG: About to fill buffer
3264252:DEBUG: Available: 45 Filled: 45
3264252:DEBUG: Buffer filled with 45
3264252:DEBUG: About to send through SPI
3264252:DEBUG: Starting to send data
3264304:DEBUG: Completed Sending
3264304:DEBUG: 0->BLE    - 45
3265907:DEBUG: In SPI Receive
3265907:DEBUG: Handshake complete
3265912:DEBUG: Receiving SPI data of size 23
3265912:DEBUG: Reading chunk of size 23
3265918:DEBUG: Processing message of size 20 with clientID 3 and service ID 1
3265918:DEBUG: 3->Cloud  - 18
3265919:DEBUG: Read length = 18
3265919:DEBUG: All done in SPI Retreive
3265942:DEBUG: Receiving Network data of size 18
3265942:DEBUG: About to fill buffer
3265943:DEBUG: Available: 23 Filled: 23
3265943:DEBUG: Buffer filled with 23
3265943:DEBUG: About to send through SPI
3265943:DEBUG: Starting to send data
3265995:DEBUG: Completed Sending
3265995:DEBUG: 3->BLE    - 23
3267339:DEBUG: In SPI Receive
3267339:DEBUG: Handshake complete
3267344:DEBUG: Receiving SPI data of size 261
3267344:DEBUG: Reading chunk of size 255
3267354:DEBUG: Reading chunk of size 6
3267359:DEBUG: Processing message of size 258 with clientID 0 and service ID 1
3267360:DEBUG: 0->Cloud  - 256
3267360:DEBUG: Read length = 256
3267360:DEBUG: All done in SPI Retreive
3267391:DEBUG: Receiving Network data of size 128
3267391:DEBUG: About to fill buffer
3267391:DEBUG: Available: 133 Filled: 133
3267391:DEBUG: Available: 261 Filled: 261
3267393:DEBUG: Available: 389 Filled: 389
3267393:DEBUG: Buffer filled with 389
3267393:DEBUG: About to send through SPI
3267394:DEBUG: Starting to send data
3267501:DEBUG: Completed Sending
3267501:DEBUG: 0->BLE    - 389
3271298:DEBUG: In SPI Receive
3271298:DEBUG: Handshake complete
3271303:DEBUG: Receiving SPI data of size 23
3271303:DEBUG: Reading chunk of size 23
3271309:DEBUG: Processing message of size 20 with clientID 0 and service ID 1
3271309:DEBUG: 0->Cloud  - 18
3271310:DEBUG: Read length = 18
3271310:DEBUG: All done in SPI Retreive
3271338:DEBUG: Receiving Network data of size 18
3271338:DEBUG: About to fill buffer
3271340:DEBUG: Available: 23 Filled: 23
3271340:DEBUG: Buffer filled with 23
3271340:DEBUG: About to send through SPI
3271340:DEBUG: Starting to send data
3271391:DEBUG: Completed Sending
3271391:DEBUG: 0->BLE    - 23
3271419:DEBUG: In SPI Receive
3271419:DEBUG: Handshake complete
3271424:DEBUG: Receiving SPI data of size 23
3271424:DEBUG: Reading chunk of size 23
3271430:DEBUG: Processing message of size 20 with clientID 0 and service ID 1
3271430:DEBUG: 0->Cloud  - 18
3271431:DEBUG: Read length = 18
3271431:DEBUG: All done in SPI Retreive
3271477:DEBUG: Receiving Network data of size 18
3271477:DEBUG: About to fill buffer
3271478:DEBUG: Available: 23 Filled: 23
3271478:DEBUG: Buffer filled with 23
3271478:DEBUG: About to send through SPI
3271478:DEBUG: Starting to send data
3271529:DEBUG: Completed Sending
3271529:DEBUG: 0->BLE    - 23
3271716:DEBUG: In SPI Receive
3271716:DEBUG: Handshake complete
3271721:DEBUG: Receiving SPI data of size 55
3271721:DEBUG: Reading chunk of size 55
3271727:DEBUG: Processing message of size 52 with clientID 0 and service ID 1
3271728:DEBUG: 0->Cloud  - 50
3271728:DEBUG: Read length = 50
3271728:DEBUG: All done in SPI Retreive
3271927:DEBUG: In SPI Receive
3271927:DEBUG: Handshake complete
3271932:DEBUG: Receiving SPI data of size 55
3271932:DEBUG: Reading chunk of size 55
3271938:DEBUG: Processing message of size 52 with clientID 0 and service ID 1
3271939:DEBUG: 0->Cloud  - 50
3271939:DEBUG: Read length = 50
3271939:DEBUG: All done in SPI Retreive
3272318:DEBUG: In SPI Receive
3272318:DEBUG: Handshake complete
3272323:DEBUG: Receiving SPI data of size 55
3272323:DEBUG: Reading chunk of size 55
3272329:DEBUG: Processing message of size 52 with clientID 0 and service ID 1
3272330:DEBUG: 0->Cloud  - 50
3272330:DEBUG: Read length = 50
3272330:DEBUG: All done in SPI Retreive
3272590:DEBUG: Receiving Network data of size 18
3272590:DEBUG: About to fill buffer
3272592:DEBUG: Available: 23 Filled: 23
3272592:DEBUG: Buffer filled with 23
3272592:DEBUG: About to send through SPI
3272592:DEBUG: Starting to send data
3272643:DEBUG: Completed Sending
3272643:DEBUG: 0->BLE    - 23
3272827:DEBUG: In SPI Receive
3272827:DEBUG: Handshake complete
3272832:DEBUG: Receiving SPI data of size 119
3272832:DEBUG: Reading chunk of size 119
3272840:DEBUG: Processing message of size 116 with clientID 0 and service ID 1
3272840:DEBUG: 0->Cloud  - 114
3272840:DEBUG: Read length = 114
3272841:DEBUG: All done in SPI Retreive
3273006:DEBUG: In SPI Receive
3273006:DEBUG: Handshake complete
3273011:DEBUG: Receiving SPI data of size 23
3273011:DEBUG: Reading chunk of size 23
3273017:DEBUG: Processing message of size 20 with clientID 0 and service ID 1
3273017:DEBUG: 0->Cloud  - 18
3273018:DEBUG: Read length = 18
3273018:DEBUG: All done in SPI Retreive
3273042:DEBUG: Receiving Network data of size 18
3273042:DEBUG: About to fill buffer
3273043:DEBUG: Available: 23 Filled: 23
3273043:DEBUG: Buffer filled with 23
3273043:DEBUG: About to send through SPI
3273043:DEBUG: Starting to send data
3273095:DEBUG: Completed Sending
3273095:DEBUG: 0->BLE    - 23
3273099:DEBUG: In SPI Receive
3273099:DEBUG: Handshake complete
3273104:DEBUG: Receiving SPI data of size 23
3273104:DEBUG: Reading chunk of size 23
3273110:DEBUG: Processing message of size 20 with clientID 0 and service ID 1
3273110:DEBUG: 0->Cloud  - 18
3273111:DEBUG: Read length = 18
3273111:DEBUG: All done in SPI Retreive
3273133:DEBUG: Receiving Network data of size 18
3273134:DEBUG: About to fill buffer
3273135:DEBUG: Available: 23 Filled: 23
3273135:DEBUG: Buffer filled with 23
3273135:DEBUG: About to send through SPI
3273135:DEBUG: Starting to send data
3273186:DEBUG: Completed Sending
3273186:DEBUG: 0->BLE    - 23
3275797:DEBUG: In SPI Receive
3275797:DEBUG: Handshake complete
3275802:DEBUG: Receiving SPI data of size 167
3275802:DEBUG: Reading chunk of size 167
3275810:DEBUG: Processing message of size 164 with clientID 54 and service ID 1
3275811:DEBUG: 54->Cloud  - 162
3275811:DEBUG: Read length = 162
3275811:DEBUG: All done in SPI Retreive
3277675:DEBUG: Receiving Network data of size 18
3277675:DEBUG: About to fill buffer
3277676:DEBUG: Available: 23 Filled: 23
3277676:DEBUG: Buffer filled with 23
3277676:DEBUG: About to send through SPI
3277676:DEBUG: Starting to send data
3277728:DEBUG: Completed Sending
3277728:DEBUG: 0->BLE    - 23
3280945:DEBUG: In SPI Receive
3280945:DEBUG: Handshake complete
3280950:DEBUG: Receiving SPI data of size 23
3280950:DEBUG: Reading chunk of size 23
3280956:DEBUG: Processing message of size 20 with clientID 3 and service ID 1
3280956:DEBUG: 3->Cloud  - 18
3280957:DEBUG: Read length = 18
3280957:DEBUG: All done in SPI Retreive

I decided to reboot my router, just to try something. The Photon on the GWS crashed again after 20 minutes.
It rebooted, but I still cannot communicate with the Bluz.
This is the last piece of the log text when the Photon crashed:

4322552:DEBUG: Receiving Network data of size 18                                 
4322552:DEBUG: About to fill buffer                                              
4322553:DEBUG: Available: 23 Filled: 23                                          
4322553:DEBUG: Buffer filled with 23                                             
4322553:DEBUG: About to send through SPI                                         
4322553:DEBUG: Starting to send data                                             
4322604:DEBUG: Completed Sending                                                 
4322604:DEBUG: 3->BLE    - 23                                                    
4331381:DEBUG: In SPI Receive                                                    
4331381:DEBUG: Handshake complete                                                
4331386:DEBUG: Receiving SPI data of size 167                                    
4331386:DEBUG: Reading chunk of size 167                                         
4331394:DEBUG: Processing message of size 164 with clientID 174 and service ID 1 
4331395:DEBUG: 174->Cloud  - 162                                                 
4331395:DEBUG: Read length = 162                                                 
4331395:DEBUG: All done in SPI Retreive                                          
4331672:DEBUG: Receiving Network data of size 18                                 
4331672:DEBUG: About to fill buffer                                              
4331673:DEBUG: Available: 23 Filled: 23                                          
4331673:DEBUG: Buffer filled with 23                                             
4331673:DEBUG: About to send through SPI                                         
4331673:DEBUG: Starting to send data                                             
4331724:DEBUG: Completed Sending                                                 
4331724:DEBUG: 0->BLE    - 23                                                    
4334170:DEBUG: In SPI Receive                                                    
4334170:DEBUG: Handshake complete                                                
4334175:DEBUG: Receiving SPI data of size 167                                    
4334175:DEBUG: Reading chunk of size 167                                         

The frustrating part is that the blinks on the Bluz do not reflect the real online status. Is blinking cyan indicating a BLE connection, or a Particle cloud connection?
Can I send you all the modules to see if you can reproduce the problem?

Thanks for your time, Eric.
Pescatore


#4

Bluz will send pings to the cloud, one every 15 seconds. If 3 of those pings fail in a row, that it is doesn’t receive a response from the cloud, it will declare that it is no longer online and stop breathing cyan. So it can sometimes take up to 45 seconds for bluz to realize it isn’t online and disconnect.

However, it sounds like you are seeing bluz stay online much longer than that?

I can see the heartbeats in the log, especially the long one. It is these line:

0->Cloud  - 18
...
0->BLE    - 23

0 is the ID of the bluz device, and it sends 18 bytes of data as the ping, then receives a response back.

However, there definitely seems to be something wrong with the communication between the Photon and the gateway shield, as you can see in these lines:

4331394:DEBUG: Processing message of size 164 with clientID 174 and service ID 1 
4331395:DEBUG: 174->Cloud  - 162

The clientID is the device ID, which should be 0-2 for a connected bluz and 3 for the gateway. However, here it says the clientID is 174. This indicates corrupt data is getting to the Photon over the SPI bridge.

Not sure exactly how this could happen, and I haven’t seen this particular issue before. It could be a connection issue between the two devices, or some kind interference maybe. How old is the gateway shield? Have you had it for a long time? Same question with the Photon?

Do you have another Photon you could try? If we can rule that out, maybe we can replace your gateway shield and get that one back so we can test.


#5

Thank you for describing the log messages, it is informative. Maybe you can post a description, given all the free time you have. :smile:

The Bluz comes online right away, based on the WebIDE console messages (as long as the GWS is up).
The LED is always cyan after it boots up and keeps on blinking cyan unless the Photon crashes.
I cannot talk to it even right after the console says it is online.

All the modules (Photon, GWS, Bluz) were purchased recently, when the Bluz were back in stock at the end of the summer.
I will try another Photon from another project. It will take me another day to get to it.

Thank you!
Pescatore


#6

It looks like the Gateway Shield is causing the problem.
I took my other Photon and plugged it into the GWS. Once in a while it also blinks red and goes offline. This Photon never did that before.
I will put the new Photon into my old project next, but some reassembly is required.
P.