I2C/RTCM issues

[eviltwinkie]

Subject of the issue

ESP32 - I2C Messages timeout and rtcmFrameCounter keeps incrementing until panic occurs.
SAMD21 - I2C will not work unless I change #define I2C_BUFFER_LENGTH 255 as 256 will not work.

Your workbench

ESP32 (Sparkfun ESP32 1 Channel Gateway)/SAMD21 (Adafruit M0) both using I2C and similar sketches. Adafruit is more stable.
ZED-F9P

Steps to reproduce

Update all libs to latest version.
Load "Example3_StartRTCMBase" with debugging enabled on either platform.
ESP32 partially works. M0 will not work without changing the ring buffer size.

Expected behavior

Packets should be processed appropriately, ACKs received and the frame counter reset.

Actual behavior

Timeouts should not take 35 seconds. Eventually memory leak will stop the RTCM output or panic occurs.

See below debug.

Sending: CLS:CFG ID:8A Len: 0xA Payload: 0 1 0 0 BD 2 91 20 4 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 24040 bytes received
Incoming: Size: 9 Received: CLS:CFG ID:8B Len: 0x9 Payload: 1 1 0 0 BD 2 91 20 4
packetCfg now valid
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8B
packetCfg now valid
packetAck now valid
UBX ACK: Command sent/ack'd successfully
Module not ready with data
Module not ready with data
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8A
packetCfg now valid
packetAck now valid
waitForACKResponse: ACK received after 40664 msec
waitForACKResponse: New data successfully sent

Sending: CLS:CFG ID:SAVE Len: 0xC Payload: 0 0 0 0 FF 0 0 0 0 0 0 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 21557 bytes received
Module not ready with data
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 9
packetAck now valid
UBX ACK: Command sent/ack'd successfully
waitForACKResponse: ACK received after 36503 msec
waitForACKResponse: New data successfully sent
OK
CONFIG: CFG-MSGOUT-RTCM_3X_TYPE1077_I2C (0x209102cc)key: 0x209102CC

Sending: CLS:CFG ID:8B Len: 0x8 Payload: 0 1 0 0 CC 2 91 20
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 21197 bytes received
waitForACKResponse: timeout after 35795 msec. No ack packet received.

Sending: CLS:CFG ID:8A Len: 0xA Payload: 0 1 0 0 CC 2 91 20 4 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22026 bytes received
Incoming: Size: 9 Received: CLS:CFG ID:8B Len: 0x9 Payload: 1 1 0 0 CC 2 91 20 4
packetCfg now valid
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8A
packetCfg now valid
packetAck now valid
waitForACKResponse: Config was valid but ACK not received
waitForACKResponse: timeout after 37168 msec. No ack packet received.

Sending: CLS:CFG ID:SAVE Len: 0xC Payload: 0 0 0 0 FF 0 0 0 0 0 0 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22078 bytes received
Module not ready with data
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 9
packetAck now valid
UBX ACK: Command sent/ack'd successfully
waitForACKResponse: ACK received after 36866 msec
waitForACKResponse: New data successfully sent
OK
CONFIG: CFG-MSGOUT-RTCM_3X_TYPE1087_I2C (0x209102d1)key: 0x209102D1

Sending: CLS:CFG ID:8B Len: 0x8 Payload: 0 1 0 0 D1 2 91 20
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22820 bytes received
waitForACKResponse: timeout after 38205 msec. No ack packet received.

Sending: CLS:CFG ID:8A Len: 0xA Payload: 0 1 0 0 D1 2 91 20 4 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22224 bytes received
Incoming: Size: 9 Received: CLS:CFG ID:8B Len: 0x9 Payload: 1 1 0 0 D1 2 91 20 4
packetCfg now valid
Module not ready with data
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8A
packetCfg now valid
packetAck now valid
waitForACKResponse: Config was valid but ACK not received
waitForACKResponse: timeout after 37917 msec. No ack packet received.

Sending: CLS:CFG ID:SAVE Len: 0xC Payload: 0 0 0 0 FF 0 0 0 0 0 0 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 21402 bytes received
Module not ready with data
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 9
packetAck now valid
UBX ACK: Command sent/ack'd successfully
waitForACKResponse: ACK received after 36370 msec
waitForACKResponse: New data successfully sent
OK
CONFIG: CFG-MSGOUT-RTCM_3X_TYPE1097_I2C (0x20910318)key: 0x20910318

Sending: CLS:CFG ID:8B Len: 0x8 Payload: 0 1 0 0 18 3 91 20
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 21014 bytes received
waitForACKResponse: timeout after 35516 msec. No ack packet received.

Sending: CLS:CFG ID:8A Len: 0xA Payload: 0 1 0 0 18 3 91 20 4 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22325 bytes received
Incoming: Size: 9 Received: CLS:CFG ID:8B Len: 0x9 Payload: 1 1 0 0 18 3 91 20 4
packetCfg now valid
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8B
packetCfg now valid
packetAck now valid
UBX ACK: Command sent/ack'd successfully
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8A
packetCfg now valid
packetAck now valid
waitForACKResponse: ACK received after 37699 msec
waitForACKResponse: New data successfully sent

Sending: CLS:CFG ID:SAVE Len: 0xC Payload: 0 0 0 0 FF 0 0 0 0 0 0 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22506 bytes received
waitForACKResponse: timeout after 38125 msec. No ack packet received.
OK
CONFIG: CFG-MSGOUT-RTCM_3X_TYPE1127_I2C (0x209102d6)key: 0x209102D6

Sending: CLS:CFG ID:8B Len: 0x8 Payload: 0 1 0 0 D6 2 91 20
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 22447 bytes received
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 9
packetAck now valid
waitForACKResponse: timeout after 38223 msec. No ack packet received.

Sending: CLS:CFG ID:8A Len: 0xA Payload: 0 1 0 0 D6 2 91 20 4 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 24452 bytes received
Incoming: Size: 9 Received: CLS:CFG ID:8B Len: 0x9 Payload: 1 1 0 0 D6 2 91 20 4
packetCfg now valid
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8B
packetCfg now valid
packetAck now valid
UBX ACK: Command sent/ack'd successfully
Module not ready with data
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8A
packetCfg now valid
packetAck now valid
waitForACKResponse: ACK received after 41442 msec
waitForACKResponse: New data successfully sent

https://github.com/PaulZC/SparkFun_Ublox_Arduino_Library/tree/PaulZC_testing_%2364

This build appears to have fixed some of the issues on ESP32. Much faster too. But still seeing the leak.

Sending: CLS:NAV ID:3B Len: 0x0 Payload:
sendCommand: Waiting for No ACK response
checkUbloxI2C: OK, zero bytes available
Incoming: Size: 40 Received: CLS:NAV ID:3B Len: 0x28 Payload: 0 0 0 0 32 81 8 12 50 0 0 0 22 D1 81 FB 60 AA 78 DF 83 21 18 13 14 15 4 0 2B C3 0 0 C7 0 0 0 1 0 0 0
packetCfg now valid
waitForNoACKResponse: CLS/ID match after 73 msec
Active: 0 Valid: 1 Timer: 80 Accuracy: 5.00
Base survey complete!
Active: 0 Valid: 1 Timer: 80 Accuracy: 5.00
RTCM now broadcasting.
CONFIG: CFG-I2COUTPROT-RTCM3X (0x10720004)key: 0x10720004

Sending: CLS:CFG ID:VALGET Len: 0x8 Payload: 0 1 0 0 4 0 72 10
sendCommand: Waiting for ACK response
checkUbloxI2C: OK, zero bytes available
Incoming: Size: 9 Received: CLS:CFG ID:VALGET Len: 0x9 Payload: 1 1 0 0 4 0 72 10 0
packetCfg now valid
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8B
packetCfg now valid
packetAck now valid
UBX ACK: Command sent/ack'd successfully
waitForACKResponse: ACK received after 81 msec
waitForACKResponse: CLS/ID match after 86 msec

Sending: CLS:CFG ID:VALSET Len: 0xA Payload: 0 1 0 0 4 0 72 10 1 0
sendCommand: Waiting for ACK response
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 8A
packetAck now valid
UBX ACK: Command sent/ack'd successfully
waitForACKResponse: ACK received after 14 msec
waitForACKResponse: New data successfully sent

Sending: CLS:CFG ID:9 Len: 0xC Payload: 0 0 0 0 FF 0 0 0 0 0 0 0
sendCommand: Waiting for ACK response
checkUbloxI2C: OK, zero bytes available
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 9
packetAck now valid
UBX ACK: Command sent/ack'd successfully
waitForACKResponse: ACK received after 67 msec
waitForACKResponse: New data successfully sent

Sending: CLS:CFG ID:9 Len: 0xC Payload: 0 0 0 0 FF 0 0 0 0 0 0 0
sendCommand: Waiting for ACK response
checkUbloxI2C: Large packet of 803 bytes received
waitForACKResponse: timeout after 921 msec. No ack packet received.

checkUbloxI2C: Large packet of 838 bytes received
Incoming: Size: 2 Received: CLS:ACK ID:1 Len: 0x2 Payload: 6 9
packetAck now valid
UBX ACK: Command sent/ack'd successfully
.checkUbloxI2C: Large packet of 867 bytes received
.checkUbloxI2C: Large packet of 1656 bytes received
.checkUbloxI2C: Large packet of 2484 bytes received
.checkUbloxI2C: Large packet of 3312 bytes received
.checkUbloxI2C: Large packet of 4982 bytes received
.checkUbloxI2C: Large packet of 6538 bytes received
.checkUbloxI2C: Large packet of 9425 bytes received
.checkUbloxI2C: Large packet of 12851 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 16510 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 21621 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 22358 bytes received
.checkUbloxI2C: Large packet of 20828 bytes received
.checkUbloxI2C: Large packet of 22355 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 22558 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 23265 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
checkUbloxI2C: Module not ready with data. Retrying.
checkUbloxI2C: Module not ready with data. Retrying.
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 22979 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
checkUbloxI2C: Module not ready with data. Retrying.
.checkUbloxI2C: Large packet of 22157 bytes received
checkUbloxI2C: Module not ready with data. Retrying.
Guru Meditation Error: Core 1 panic'ed (IllegalInstruction). Exception was unhandled.
Core 1 register dump:
PC : 0x65000000 PS : 0x00060530 A0 : 0x800d1775 A1 : 0x3ffb1ed0
A2 : 0x3ffc0360 A3 : 0x3ffc015c A4 : 0x000000b0 A5 : 0x65000000
A6 : 0x00000000 A7 : 0x3ffb1f0c A8 : 0x800d35aa A9 : 0x3ffb1e90
A10 : 0x3ffc0360 A11 : 0x3ffb1f0c A12 : 0x00000002 A13 : 0x3ffbebf4
A14 : 0x00000010 A15 : 0x00000001 SAR : 0x00000013 EXCCAUSE: 0x00000000
EXCVADDR: 0x00000000 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000

Backtrace: 0x65000000:0x3ffb1ed0 0x400d1772:0x3ffb1ef0 0x400d1af3:0x3ffb1f10 0x400d2363:0x3ffb1f30 0x400d24ea:0x3ffb1f50 0x400d253e:0x3ffb1f70 0x400d15d2:0x3ffb1f90 0x400d5b91:0x3ffb1fb0 0x40088dbd:0x3ffb1fd0

Rebooting...

PC: 0x65000000
EXCVADDR: 0x00000000

Decoding stack results
0x400d1772: SFE_UBLOX_GPS::processRTCM(unsigned char) at ........\ADA_ESP32/ADA_ESP32.ino line 43
0x400d1af3: SFE_UBLOX_GPS::processRTCMframe(unsigned char) at ........\Arduino\libraries\SparkFun_Ublox_Arduino_Library-1.7.1\src\SparkFun_Ublox_Arduino_Library.cpp line 519
0x400d2363: SFE_UBLOX_GPS::process(unsigned char) at ........\Arduino\libraries\SparkFun_Ublox_Arduino_Library-1.7.1\src\SparkFun_Ublox_Arduino_Library.cpp line 470
0x400d24ea: SFE_UBLOX_GPS::checkUbloxI2C() at ........\Arduino\libraries\SparkFun_Ublox_Arduino_Library-1.7.1\src\SparkFun_Ublox_Arduino_Library.cpp line 374
0x400d253e: SFE_UBLOX_GPS::checkUblox() at ........\Arduino\libraries\SparkFun_Ublox_Arduino_Library-1.7.1\src\SparkFun_Ublox_Arduino_Library.cpp line 266
0x400d15d2: loop() at ........\ADA_ESP32/ADA_ESP32.ino line 23
0x400d5b91: loopTask(void*) at ........\Arduino15\packages\esp32\hardware\esp32\1.0.4\cores\esp32\main.cpp line 19
0x40088dbd: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c line 143

Line 43 on the .ino: sendData(buffz, frame_length);

I do have a radio onboard that's attached to SPI and has interrupts which is , but not sure if that's involved somehow.

[nseidle]

This sounds very similar to the fix we put in place a few days ago. If the packet length gets corrupt we can potentially load more bytes than the payload can handle.

If the rtcmLen variable gets corrupt then we have to wait until for (rtcmFrameCounter == rtcmLen) for the completion of a RTCM frame; this could be up to uint16_t or 65k bytes. I believe RTCM frames are limited to ~1k max (just off the top of my head here) so we could put a sanity check in there...

Can you give this branch a try and let me know if it works any better? I don't know what you're doing within processRTCM but that too may be a culprit.

I believe Adafruit defines the I2C ring buffer differently on their trinket than other SAMD21 based boards. Not sure. But I've changed the I2C_BUFFER_LENGTH define to:

#define I2C_BUFFER_LENGTH (SERIAL_BUFFER_SIZE - 1)

In an attempt to hit your 255 issue.

[eviltwinkie]

I'll try the new branch and let you know. I think I also came to the conclusion that its a processRTCM problem. I'm checking the frame counter for the "1" and then doing an action. If I take too long in processing, bad things start to happen all over the place.

So I'm going to implement a ring buffer to handle it by sending it to somewhere else and do processing via a second thread so it doesn't block or interrupt the processRTCM function.

[eviltwinkie]

The panic's have reduced but I'm still seeing some issues. Also, still hitting the counter. The BUFFER_LENGTH on the M0 works (as it should) so you should definitely keep the change in there.

Also, the ZED-F9P has an I2C address of 0x84. I have to do a saveConfiguration and then wait for it to be ready with...

while(myGPS.getVal8(0x20510001) != 0x84){delay(100);}

before sending in the other configs.

It would also be nice to give people the option to set the antenna to active.

while(doVal(0x20410010,0x02,"CFG-ITFM-ANTSETTING (0x20410010)") == false){ delay(100); }

processUBX: counter hit MAX_PAYLOAD_SIZE

I've also for sure narrowed down that some of the issue was due to the processing time while inside the processRTCM function. Using a tasks and queues I could see the queue get filled pretty quick. After it filled up, Bad Things...

Definitely some sort of locking/blocking/ISR issue. I might move the entire SFE_UBLOX_GPS::process into its own task and give it a queue to keep that on its own processor.

[PaulZC]

Hi @eviltwinkie ,
Can you please test V1.8.0 of the library as I think it will resolve most of your issues?
I am going to close this issue but please do reopen it again if it needs further discussion.
Thanks for contributing!
Best wishes,
Paul