From d2948c3fcd6fdf3c3835f06b67ebf9e7643404a2 Mon Sep 17 00:00:00 2001 From: Adeeb Shihadeh Date: Wed, 5 Jun 2024 17:27:57 -0700 Subject: [PATCH] pandad: add more context to spi logs (#32639) * pandad: add more context to spi logs * cleanup --------- Co-authored-by: Comma Device old-commit-hash: e828a7bdcf7744102a321b68076ad7842ec31af4 --- selfdrive/pandad/panda_comms.h | 10 ++++++++++ selfdrive/pandad/spi.cc | 35 +++++++++++++++++----------------- 2 files changed, 27 insertions(+), 18 deletions(-) diff --git a/selfdrive/pandad/panda_comms.h b/selfdrive/pandad/panda_comms.h index 6b64768c1..9c452faf6 100644 --- a/selfdrive/pandad/panda_comms.h +++ b/selfdrive/pandad/panda_comms.h @@ -56,6 +56,13 @@ private: }; #ifndef __APPLE__ +struct __attribute__((packed)) spi_header { + uint8_t sync; + uint8_t endpoint; + uint16_t tx_len; + uint16_t max_rx_len; +}; + class PandaSpiHandle : public PandaCommsHandle { public: PandaSpiHandle(std::string serial); @@ -79,5 +86,8 @@ private: int spi_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t tx_len, uint8_t *rx_data, uint16_t max_rx_len, unsigned int timeout); int spi_transfer_retry(uint8_t endpoint, uint8_t *tx_data, uint16_t tx_len, uint8_t *rx_data, uint16_t max_rx_len, unsigned int timeout); int lltransfer(spi_ioc_transfer &t); + + spi_header header; + uint32_t xfer_count = 0; }; #endif diff --git a/selfdrive/pandad/spi.cc b/selfdrive/pandad/spi.cc index 836df5986..e2bef203e 100644 --- a/selfdrive/pandad/spi.cc +++ b/selfdrive/pandad/spi.cc @@ -28,13 +28,6 @@ enum SpiError { ACK_TIMEOUT = -3, }; -struct __attribute__((packed)) spi_header { - uint8_t sync; - uint8_t endpoint; - uint16_t tx_len; - uint16_t max_rx_len; -}; - const unsigned int SPI_ACK_TIMEOUT = 500; // milliseconds const std::string SPI_DEVICE = "/dev/spidev0.0"; @@ -55,6 +48,11 @@ private: std::recursive_mutex &m; }; +#define SPILOG(fn, fmt, ...) do { \ + fn(fmt, ## __VA_ARGS__); \ + fn(" %d / 0x%x / %d / %d", \ + xfer_count, header.endpoint, header.tx_len, header.max_rx_len); \ + } while(0) PandaSpiHandle::PandaSpiHandle(std::string serial) : PandaCommsHandle(serial) { int ret; @@ -178,7 +176,7 @@ int PandaSpiHandle::bulk_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t t } if (d < 0) { - LOGE("SPI: bulk transfer failed with %d", d); + SPILOG(LOGE, "SPI: bulk transfer failed with %d", d); comms_healthy = false; return d; } @@ -247,7 +245,7 @@ int PandaSpiHandle::spi_transfer_retry(uint8_t endpoint, uint8_t *tx_data, uint1 } while (ret < 0 && connected && !timed_out); if (ret < 0) { - LOGE("transfer failed, after %d tries, %.2fms", timeout_count, millis_since_boot() - start_time); + SPILOG(LOGE, "transfer failed, after %d tries, %.2fms", timeout_count, millis_since_boot() - start_time); } return ret; @@ -270,20 +268,20 @@ int PandaSpiHandle::wait_for_ack(uint8_t ack, uint8_t tx, unsigned int timeout, while (true) { int ret = lltransfer(transfer); if (ret < 0) { - LOGE("SPI: failed to send ACK request"); + SPILOG(LOGE, "SPI: failed to send ACK request"); return ret; } if (rx_buf[0] == ack) { break; } else if (rx_buf[0] == SPI_NACK) { - LOGD("SPI: got NACK"); + SPILOG(LOGD, "SPI: got NACK"); return SpiError::NACK; } // handle timeout if (millis_since_boot() - start_millis > timeout) { - LOGD("SPI: timed out waiting for ACK"); + SPILOG(LOGW, "SPI: timed out waiting for ACK"); return SpiError::ACK_TIMEOUT; } } @@ -334,7 +332,8 @@ int PandaSpiHandle::spi_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t tx assert(tx_len < SPI_BUF_SIZE); assert(max_rx_len < SPI_BUF_SIZE); - spi_header header = { + xfer_count++; + header = { .sync = SPI_SYNC, .endpoint = endpoint, .tx_len = tx_len, @@ -352,7 +351,7 @@ int PandaSpiHandle::spi_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t tx transfer.len = sizeof(header) + 1; ret = lltransfer(transfer); if (ret < 0) { - LOGE("SPI: failed to send header"); + SPILOG(LOGE, "SPI: failed to send header"); return ret; } @@ -370,7 +369,7 @@ int PandaSpiHandle::spi_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t tx transfer.len = tx_len + 1; ret = lltransfer(transfer); if (ret < 0) { - LOGE("SPI: failed to send data"); + SPILOG(LOGE, "SPI: failed to send data"); return ret; } @@ -383,7 +382,7 @@ int PandaSpiHandle::spi_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t tx // Read data rx_data_len = *(uint16_t *)(rx_buf+1); if (rx_data_len >= SPI_BUF_SIZE) { - LOGE("SPI: RX data len larger than buf size %d", rx_data_len); + SPILOG(LOGE, "SPI: RX data len larger than buf size %d", rx_data_len); return -1; } @@ -391,11 +390,11 @@ int PandaSpiHandle::spi_transfer(uint8_t endpoint, uint8_t *tx_data, uint16_t tx transfer.rx_buf = (uint64_t)(rx_buf + 2 + 1); ret = lltransfer(transfer); if (ret < 0) { - LOGE("SPI: failed to read rx data"); + SPILOG(LOGE, "SPI: failed to read rx data"); return ret; } if (!check_checksum(rx_buf, rx_data_len + 4)) { - LOGE("SPI: bad checksum"); + SPILOG(LOGE, "SPI: bad checksum"); return -1; }