FaradayRF / Faraday-Firmware

Faraday node firmware
Other
25 stars 10 forks source link

(I2C - CP2120) SPI Firmware Updates Corrupting Telemetry Packets #82

Closed kb1lqd closed 6 years ago

kb1lqd commented 6 years ago

It was found that the SPI updates that were included while adding support for the CP2120 SPI to I2C converter also improved the SPI SRAM support. It has been found however that telemetry is now corrupt on this branch and I suspect something odd occurring with the telemetry packets from the SRAM device due to the modified SPI support.

Initial Notes:

Plan Of Attack

Bonus:

References

kb1lqd commented 6 years ago

I reverted firmware to master and left the unit running. I saw the Proxy crap out sometime during runtime in the day. Bad packets were reported:

(faraday) kb1lqd@raspberrypi:~/virtualenvironment/faraday/bin $ faraday-proxy --start
2017-10-27 07:48:28,075 - Proxy - INFO - Starting proxy server
2017-10-27 07:48:28,087 - Proxy - INFO - Started server on raspberrypi:10000
2017-10-27 07:48:28,097 - Proxy - INFO - Started server on raspberrypi:10010
2017-10-27 07:49:06,737 - UARTStack - WARNING - Layer 2 UART Protocol Unpack
2017-10-27 07:49:06,739 - UARTStack - WARNING - Data: '\x05{\x03\x00aKB1LQCaKB\x06\x02KB1LQC\x02KB\x06\x02\x011\x0f\x1b\x05\n\xe1\x073400.0405N11826.1673W99.10000M0.32012.20\x00\x07\x00\x02\xa1\x04\xe8\x079\x06X\x05o\x05\x12\x05j\x00\x1a\x0b"\x00\x00\x1c \x00\x00B1LQC\xff\x00\x00\x06\x0270\x0f\x1b\x05\n\xe1\x0734\x16\x16\xb8'
2017-10-27 08:04:26,753 - UARTStack - WARNING - Layer 2 UART Protocol Unpack
2017-10-27 08:04:26,781 - UARTStack - WARNING - Data: '\x05{\x03\x00aKB1LQC182\x06\x02KB1LQC\x00\x00\x00\x06\x02\x15\x04\x10\x1b\x05\n\xe1\x073400.0226N11826.1694W44.50000M0.48011.70\x00\x07\x00\x02\xa2\x04\xe8\x07A\x06\xce\x061\x05\xe6\x05l\x00\x1b\x0b\x1f\x00\x00\x1c \x00\x00KB1LQC\x00\x00\x00\x06\x02\x13\x04\x10\x1b\x05\n\xe1\x0734\x15\xc4'
2017-10-27 08:04:39,007 - UARTStack - WARNING - Layer 2 UART Protocol Unpack
2017-10-27 08:04:39,041 - UARTStack - WARNING - Data: '\x05{\x03\x00aKB1LQC182\x06\x02KB1LQC\x00\x00\x00\x06\x02!\x04\x10\x1b\x05\n\xe1\x073400.0214N11826.1717W44.00000M0.48011.70\x00\x07\x00\x02\xa1\x04\xe8\x077\x06\xce\x065\x05\xe7\x05m\x00\x1a\x0b\x14\x00\x00\x1c \x00\x00KB1LQC\xff\x00\x00\x06\x02\x1f\x04\x10\x1b\x05\n\xe1\x0734\x16\xbe'
2017-10-27 08:11:10,680 - UARTStack - WARNING - Layer 2 UART Protocol Unpack
2017-10-27 08:11:10,680 - UARTStack - WARNING - Data: '\x05{\x03\x00aKB1LQC\x00\x00\r\x06\x02KB1LQC\x00\x00\x00\x06\x02\x05\x0b\x10\x1b\x05\n\xe1\x073400.0174N11826.1768W39.30000M0.15011.10\x00\x07\x00\x02\xa1\x04\xe7\x07;\x06\xf3\x06\x9d\x061\x05l\x00\x18\x0b&\x00\x00\x1c \x00\x001LQC\x00\x00\x00\x06\x027\n\x10\xec\xc4\x00\x00\x97#\x00\x00|\x16\n'
2017-10-27 08:12:10,644 - UARTStack - WARNING - Layer 2 UART Protocol Unpack
2017-10-27 08:12:10,644 - UARTStack - WARNING - Data: '\x05{\x03\x00aKB1LQC\x00\x00J\x06\x02KB1LQC\x00\x00\x00\x06\x02\x05\x0c\x10\x1b\x05\n\xe1\x073400.0171N11826.1761W39.30000M0.16011.04\x00\x07\x00\x02\xa1\x04\xe7\x07B\x06\xf8\x06\xac\x069\x05l\x00\x1a\x0b\x17\x00\x00\x1c \x00\x001LQC\xff\x00\x00\x06\x027\x0b\x10\xec\xc4\x00\x00\x97#\x00\x00|\x17X'
2017-10-27 08:47:26,662 - UARTStack - WARNING - Layer 2 UART Protocol Unpack
2017-10-27 08:47:26,676 - UARTStack - WARNING - Data: '\x05{\x03\x00aKB1LQC\x00\x00\x0b\x06\x02KB1LQC\x00\x00\x00\x06\x02\x15/\x10\x1b\x05\n\xe1\x073400.0218N11826.1781W14.70000M0.16010.92\x00\x07\x00\x02\xa2\x04\xe7\x07@\x07a\x07h\x076\x05m\x00\x18\x0b)\x00\x00\x1c \x00\x00KB1LQC\x00\x00\x00\x06\x02\x13t\xac\x00\x00\x97#\x00\x00|\x15G'
kb1lqd commented 6 years ago

I rigged up a simple test script to simulate the problem (we should add the execption printing of the failure for traceback in proxy @kb1lqc so this can more easily be debugged in the future).

import struct

datalink_packet_struct = struct.Struct('BBB125s')

data = '\x05{\x03\x00aKB1LQC\x00\x00\x0b\x06\x02KB1LQC\x00\x00\x00\x06\x02\x15/\x10\x1b\x05\n\xe1\x073400.0218N11826.1781W14.70000M0.16010.92\x00\x07\x00\x02\xa2\x04\xe7\x07@\x07a\x07h\x076\x05m\x00\x18\x0b)\x00\x00\x1c \x00\x00KB1LQC\x00\x00\x00\x06\x02\x13t\xac\x00\x00\x97#\x00\x00|\x15G'
print len(data)
unpacked_datalink = datalink_packet_struct.unpack(data)
*** Remote Interpreter Reinitialized  ***
>>> 
125
Traceback (most recent call last):
  File "<module1>", line 7, in <module>
error: unpack requires a string argument of length 128
>>> 

It looks like most/all of the data being received and erroring is 125 bytes long instead of 128...

Wait this is WRONG! The error is printing previous unpacked "data" and the variable data should be viewed in the warning.

kb1lqd commented 6 years ago

OK so I started getting all gibierish, increasing bytes and BLOB's in the telemetry: image

I believe I traced an issue down to the mode setting which also relates to the write/read (seemingly read in this issue case) and the delays given. I was getting a return of all 0xFF and thus after read bit shift showed up as 0b00000011 (3) which is incorrect SRAM mode on init. This may have been an intermitant issue...

unsigned char Faraday_SRAM_Read_Settings(void){
    // 0 = Byte Mode
    // 1 = Page Mode
    // 2 = Sequential Mode
    // 4 = Reserved (Test?)

    //Select the SRAM chip select
    spi_enable_chip_select(SPI_HAL_CS_SRAM);
    __delay_cycles(SPI_BYTE_CYCLES*5);

    //Send the READ command
    spi_tx(SRAM_RDSR);
    __delay_cycles(SPI_BYTE_CYCLES*5);

    //Send dummy byte to shift SPI registers out of SRAM into RX CC430
    spi_tx(0x00); //dummy

    __delay_cycles(SPI_BYTE_CYCLES*5); //Per datasheet at 3.0V CS delay is 25ns = @16MHz is 2.5 clock cycles
    spi_disable_chip_select(SPI_HAL_CS_SRAM);

    unsigned char test2;
    test2 = UCB0RXBUF>>6; // Shift mode bytes down from bits 6 & 7 to LSB
    return test2;
}

@kb1lqc What this means is that the common thread between issues in telemetry (not all but likely some) in current master and what are exaggerated in the new branch is that I don't fully understand the SPI delays and settings. This probably got through me so long because I was not using proxy and such for a long time just adding I2C functionality while the proxy branch was really not working.

Adding LONG delays between read statements seems to get the correct READ of the mode bit, I suspect just setting the mode correctly and/or slowing down other SRAM reads might alleviate this issue.

EDIT:

It looks like I'm getting good data now... image

It may just be setting MODE correctly with improved byte timing. I still need to verify and clean the SPI delays/byte syncing better to ensure operation.

image

kb1lqd commented 6 years ago

OK Adding in those delays allowed the unit to work on the Rpi3 for 13 hours with no issues, still going strong.

I don't exactly know why the timing is weird in the settings function but adding the long delays worked and it's only on boot. Normal read/write for SRAM is using the tested and byte length counting functions.

I'm inclined to leave this as is and push for a PR. @kb1lqc

kb1lqd commented 6 years ago

Closing due to scope reduction, not adding I2C sensors and focusing on core telemetry and analog to then move onto other Faraday uses such as TUN network adapter and RPI integration.