diff --git a/.github/workflows/test.yaml b/.github/workflows/test.yaml index 72c329bc..fad852a0 100644 --- a/.github/workflows/test.yaml +++ b/.github/workflows/test.yaml @@ -68,8 +68,6 @@ jobs: run: $RUN "scons -j4" - name: Test communication protocols run: $RUN "cd tests/usbprotocol && ./test.sh" - - name: Test logging - run: $RUN "cd tests/logging && ./test.sh" safety: name: safety diff --git a/__init__.py b/__init__.py index 41876ee2..bf487fdd 100644 --- a/__init__.py +++ b/__init__.py @@ -3,7 +3,7 @@ from .python.spi import PandaSpiException, PandaProtocolMismatch, STBootloaderSP from .python.serial import PandaSerial # noqa: F401 from .python.canhandle import CanHandle # noqa: F401 from .python import (Panda, PandaDFU, # noqa: F401 - pack_can_buffer, unpack_can_buffer, calculate_checksum, unpack_log, + pack_can_buffer, unpack_can_buffer, calculate_checksum, DLC_TO_LEN, LEN_TO_DLC, ALTERNATIVE_EXPERIENCE, CANPACKET_HEAD_SIZE) diff --git a/board/drivers/logging.h b/board/drivers/logging.h deleted file mode 100644 index 6198b548..00000000 --- a/board/drivers/logging.h +++ /dev/null @@ -1,208 +0,0 @@ -#ifdef ENABLE_LOGGING - -#include "logging_definitions.h" - -#define BANK_SIZE LOGGING_FLASH_SECTOR_SIZE -#define BANK_LOG_CAPACITY (BANK_SIZE / sizeof(log_t)) -#define TOTAL_LOG_CAPACITY (BANK_LOG_CAPACITY * 2U) - -#define LOGGING_MAX_LOGS_PER_MINUTE 10U - -struct logging_state_t { - uint16_t read_index; - uint16_t write_index; - uint16_t last_id; - - uint8_t rate_limit_counter; - uint8_t rate_limit_log_count; -}; -struct logging_state_t log_state = { 0 }; -log_t *log_arr = (log_t *) LOGGING_FLASH_BASE_A; - -uint16_t logging_next_id(uint16_t id) { - return (id + 1U) % 0xFFFEU; -} - -uint16_t logging_next_index(uint16_t index) { - return (index + 1U) % TOTAL_LOG_CAPACITY; -} - -void logging_erase_bank(uint8_t flash_sector) { - print("erasing sector "); puth(flash_sector); print("\n"); - flash_unlock(); - if (!flash_erase_sector(flash_sector)) { - print("failed to erase sector "); puth(flash_sector); print("\n"); - } - flash_lock(); -} - -void logging_erase(void) { - logging_erase_bank(LOGGING_FLASH_SECTOR_A); - logging_erase_bank(LOGGING_FLASH_SECTOR_B); - log_state.read_index = 0U; - log_state.write_index = 0U; -} - -void logging_find_read_index(uint16_t last_id) { - // Figure out the read index by the last empty slot - log_state.read_index = BANK_LOG_CAPACITY; - for (uint16_t i = 0U; i < TOTAL_LOG_CAPACITY; i++) { - if (log_arr[i].id == last_id) { - log_state.read_index = logging_next_index(i); - } - } -} - -void logging_init_read_index(void) { - return logging_find_read_index(0xFFFFU); -} - -void logging_init(void) { - COMPILE_TIME_ASSERT(sizeof(log_t) == 64U); - COMPILE_TIME_ASSERT((LOGGING_FLASH_BASE_A + BANK_SIZE) == LOGGING_FLASH_BASE_B); - - // Make sure all empty-ID logs are fully empty - log_t empty_log; - (void) memset(&empty_log, 0xFF, sizeof(log_t)); - - for (uint16_t i = 0U; i < TOTAL_LOG_CAPACITY; i++) { - if ((log_arr[i].id == 0xFFFFU) && (memcmp(&log_arr[i], &empty_log, sizeof(log_t)) != 0)) { - logging_erase(); - break; - } - } - - logging_init_read_index(); - - // At initialization, the read index should always be at the beginning of a bank - // If not, clean slate - if ((log_state.read_index != 0U) && (log_state.read_index != BANK_LOG_CAPACITY)) { - logging_erase(); - } - - // Figure out the write index - log_state.write_index = log_state.read_index; - log_state.last_id = log_arr[log_state.write_index].id - 1U; - for (uint16_t i = 0U; i < TOTAL_LOG_CAPACITY; i++) { - bool done = false; - if (log_arr[log_state.write_index].id == 0xFFFFU) { - // Found the first empty slot after the read pointer - done = true; - } else if (log_arr[log_state.write_index].id != logging_next_id(log_state.last_id)) { - // Discontinuity in the index, shouldn't happen! - logging_erase(); - done = true; - } else { - log_state.last_id = log_arr[log_state.write_index].id; - log_state.write_index = logging_next_index(log_state.write_index); - } - - if (done) { - break; - } - } - - // Reset rate limit - log_state.rate_limit_counter = 0U; - log_state.rate_limit_log_count = 0U; -} - -// Call at 1Hz -void logging_tick(void) { - flush_write_buffer(); - - log_state.rate_limit_counter++; - if (log_state.rate_limit_counter >= 60U) { - log_state.rate_limit_counter = 0U; - log_state.rate_limit_log_count = 0U; - } -} - -void log(const char* msg){ - if (log_state.rate_limit_log_count < LOGGING_MAX_LOGS_PER_MINUTE) { - ENTER_CRITICAL(); - log_t new_log = {0}; - new_log.id = logging_next_id(log_state.last_id); - log_state.last_id = new_log.id; - new_log.uptime = uptime_cnt; - if (current_board->has_rtc_battery) { - new_log.timestamp = rtc_get_time(); - } - - uint8_t i = 0U; - for (const char *in = msg; *in; in++) { - new_log.msg[i] = *in; - i++; - if (i >= sizeof(new_log.msg)) { - print("log message too long\n"); - break; - } - } - - // If we are at the beginning of a bank, erase it first and move the read pointer if needed - switch (log_state.write_index) { - case ((2U * BANK_LOG_CAPACITY) - 1U): - logging_erase_bank(LOGGING_FLASH_SECTOR_A); - if ((log_state.read_index < BANK_LOG_CAPACITY)) { - log_state.read_index = BANK_LOG_CAPACITY; - } - break; - case (BANK_LOG_CAPACITY - 1U): - // beginning to write in bank B - logging_erase_bank(LOGGING_FLASH_SECTOR_B); - if ((log_state.read_index > BANK_LOG_CAPACITY)) { - log_state.read_index = 0U; - } - break; - default: - break; - } - - // Write! - void *addr = &log_arr[log_state.write_index]; - uint32_t data[sizeof(log_t) / sizeof(uint32_t)]; - (void) memcpy(data, &new_log, sizeof(log_t)); - - flash_unlock(); - for (uint8_t j = 0U; j < sizeof(log_t) / sizeof(uint32_t); j++) { - flash_write_word(&((uint32_t *) addr)[j], data[j]); - } - flash_lock(); - - // Update the write index - log_state.write_index = logging_next_index(log_state.write_index); - EXIT_CRITICAL(); - - log_state.rate_limit_log_count++; - } else { - fault_occurred(FAULT_LOGGING_RATE_LIMIT); - } -} - -uint8_t logging_read(uint8_t *buffer) { - uint8_t ret = 0U; - if ((log_arr[log_state.read_index].id != 0xFFFFU) && (log_state.read_index != log_state.write_index)) { - // Read the log - (void) memcpy(buffer, &log_arr[log_state.read_index], sizeof(log_t)); - - // Update the read index - log_state.read_index = logging_next_index(log_state.read_index); - - ret = sizeof(log_t); - } - return ret; -} - -#else - -void logging_init(void) { } -void logging_tick(void) { } -void logging_init_read_index(void) { } -void logging_find_read_index(uint16_t last_id) { UNUSED(last_id); } -void log(const char* msg) { UNUSED(msg); } -uint8_t logging_read(uint8_t *buffer) { - UNUSED(buffer); - return 0; -} - -#endif diff --git a/board/drivers/logging_definitions.h b/board/drivers/logging_definitions.h deleted file mode 100644 index 9c1bc02e..00000000 --- a/board/drivers/logging_definitions.h +++ /dev/null @@ -1,9 +0,0 @@ - -// Flash is writable in 32-byte lines, this struct is designed to fit in two lines. -// This also matches the USB transfer size. -typedef struct __attribute__((packed)) log_t { - uint16_t id; - timestamp_t timestamp; - uint32_t uptime; - char msg[50]; -} log_t; diff --git a/board/drivers/rtc.h b/board/drivers/rtc.h index 231d88f2..df121e3e 100644 --- a/board/drivers/rtc.h +++ b/board/drivers/rtc.h @@ -1,8 +1,15 @@ - -#include "rtc_definitions.h" - #define YEAR_OFFSET 2000U +typedef struct __attribute__((packed)) timestamp_t { + uint16_t year; + uint8_t month; + uint8_t day; + uint8_t weekday; + uint8_t hour; + uint8_t minute; + uint8_t second; +} timestamp_t; + uint8_t to_bcd(uint16_t value){ return (((value / 10U) & 0x0FU) << 4U) | ((value % 10U) & 0x0FU); } @@ -43,6 +50,14 @@ void rtc_set_time(timestamp_t time){ timestamp_t rtc_get_time(void){ timestamp_t result; + // Init with zero values in case there is no RTC running + result.year = 0U; + result.month = 0U; + result.day = 0U; + result.weekday = 0U; + result.hour = 0U; + result.minute = 0U; + result.second = 0U; // Wait until the register sync flag is set while((RTC->ISR & RTC_ISR_RSF) == 0){} diff --git a/board/drivers/rtc_definitions.h b/board/drivers/rtc_definitions.h deleted file mode 100644 index d308eb74..00000000 --- a/board/drivers/rtc_definitions.h +++ /dev/null @@ -1,9 +0,0 @@ -typedef struct __attribute__((packed)) timestamp_t { - uint16_t year; - uint8_t month; - uint8_t day; - uint8_t weekday; - uint8_t hour; - uint8_t minute; - uint8_t second; -} timestamp_t; diff --git a/board/fake_stm.h b/board/fake_stm.h index e6709c78..b73a4e89 100644 --- a/board/fake_stm.h +++ b/board/fake_stm.h @@ -2,10 +2,8 @@ #include #include #include -#include #include "utils.h" -#include "drivers/rtc_definitions.h" #define CANFD #define ALLOW_DEBUG @@ -33,64 +31,3 @@ uint32_t microsecond_timer_get(void); uint32_t microsecond_timer_get(void) { return MICROSECOND_TIMER->CNT; } - -// Register functions -void register_set_bits(volatile uint32_t *addr, uint32_t val) {} - -// RTC -timestamp_t rtc_get_time() { - timestamp_t result; - result.year = 1996; - result.month = 4; - result.day = 23; - result.weekday = 2; - result.hour = 4; - result.minute = 20; - result.second = 20; - return result; -} - -// Logging and flash -uint8_t fake_logging_bank[0x40000] __attribute__ ((aligned (4))); -#define LOGGING_FLASH_BASE_A (&fake_logging_bank[0]) -#define LOGGING_FLASH_BASE_B (&fake_logging_bank[0x20000]) -#define LOGGING_FLASH_SECTOR_A 5 -#define LOGGING_FLASH_SECTOR_B 6 -#define LOGGING_FLASH_SECTOR_SIZE 0x20000U - -bool flash_locked = true; -void flash_unlock(void) { - flash_locked = false; -} -void flash_lock(void) { - flash_locked = true; -} - -void *memset(void *str, int c, unsigned int n); - -bool flash_erase_sector(uint8_t sector) { - if (flash_locked) { - return false; - } - - switch (sector) { - case LOGGING_FLASH_SECTOR_A: - memset(LOGGING_FLASH_BASE_A, 0xFF, sizeof(fake_logging_bank)/2); - return true; - case LOGGING_FLASH_SECTOR_B: - memset(LOGGING_FLASH_BASE_B, 0xFF, sizeof(fake_logging_bank)/2); - return true; - default: - return false; - } -} - -void flash_write_word(void *prog_ptr, uint32_t data) { - if (flash_locked || prog_ptr < (void *) LOGGING_FLASH_BASE_A || prog_ptr >= (void *) (LOGGING_FLASH_BASE_A + sizeof(fake_logging_bank))) { - return; - } - - *(uint32_t *)prog_ptr = data; -} - -void flush_write_buffer(void) {} \ No newline at end of file diff --git a/board/faults.h b/board/faults.h index a741ea1c..6c6bef47 100644 --- a/board/faults.h +++ b/board/faults.h @@ -30,7 +30,6 @@ #define FAULT_INTERRUPT_RATE_UART_7 (1U << 24) #define FAULT_SIREN_MALFUNCTION (1U << 25) #define FAULT_HEARTBEAT_LOOP_WATCHDOG (1U << 26) -#define FAULT_LOGGING_RATE_LIMIT (1U << 27) // Permanent faults #define PERMANENT_FAULTS 0U diff --git a/board/flasher.h b/board/flasher.h index 7a124cfd..495d9f16 100644 --- a/board/flasher.h +++ b/board/flasher.h @@ -1,5 +1,6 @@ // flasher state variables uint32_t *prog_ptr = NULL; +bool unlocked = false; void spi_init(void); @@ -32,12 +33,13 @@ int comms_control_handler(ControlPacket_t *req, uint8_t *resp) { resp[1] = 0xff; } current_board->set_led(LED_GREEN, 1); + unlocked = true; prog_ptr = (uint32_t *)APP_START_ADDRESS; break; // **** 0xb2: erase sector case 0xb2: sec = req->param1; - if (flash_erase_sector(sec)) { + if (flash_erase_sector(sec, unlocked)) { resp[1] = 0xff; } break; diff --git a/board/main.c b/board/main.c index 8b6706e9..3f8cec18 100644 --- a/board/main.c +++ b/board/main.c @@ -6,7 +6,6 @@ #include "drivers/gmlan_alt.h" #include "drivers/kline_init.h" #include "drivers/simple_watchdog.h" -#include "drivers/logging.h" #include "early_init.h" #include "provision.h" @@ -185,9 +184,6 @@ void tick_handler(void) { // unless we are in power saving mode current_board->set_led(LED_BLUE, (uptime_cnt & 1U) && (power_save_status == POWER_SAVE_STATUS_ENABLED)); - // tick drivers at 1Hz - logging_tick(); - const bool recent_heartbeat = heartbeat_counter == 0U; const bool harness_inserted = (harness.status != previous_harness_status) && (harness.status != HARNESS_STATUS_NC); const bool just_bootkicked = current_board->board_tick(check_started(), usb_enumerated, recent_heartbeat, harness_inserted); @@ -196,15 +192,15 @@ void tick_handler(void) { // log device boot time const bool som_running = current_board->read_som_gpio(); if (just_bootkicked && !som_running) { - log("bootkick"); + print("bootkick\n"); waiting_to_boot = true; } if (waiting_to_boot) { if (som_running) { - log("device booted"); + print("device booted\n"); waiting_to_boot = false; } else if (waiting_to_boot_count == 45U) { - log("not booted after 45s"); + print("not booted after 45s\n"); } else { } @@ -352,7 +348,6 @@ int main(void) { current_board->set_led(LED_RED, true); current_board->set_led(LED_GREEN, true); adc_init(); - logging_init(); // print hello print("\n\n\n************************ MAIN START ************************\n"); @@ -372,8 +367,6 @@ int main(void) { // panda has an FPU, let's use it! enable_fpu(); - log("main start"); - if (current_board->has_lin) { // enable LIN uart_init(&uart_ring_lin1, 10400); diff --git a/board/main_comms.h b/board/main_comms.h index faa18b84..cf58cd0a 100644 --- a/board/main_comms.h +++ b/board/main_comms.h @@ -471,18 +471,6 @@ int comms_control_handler(ControlPacket_t *req, uint8_t *resp) { UNUSED(ret); } break; - // *** 0xfd: read logs - case 0xfd: - if (req->param1 == 1U) { - logging_init_read_index(); - } - - if (req->param2 != 0xFFFFU) { - logging_find_read_index(req->param2); - } - - resp_len = logging_read(resp); - break; default: print("NO HANDLER "); puth(req->request); diff --git a/board/stm32fx/llflash.h b/board/stm32fx/llflash.h index 52f62848..61adcd45 100644 --- a/board/stm32fx/llflash.h +++ b/board/stm32fx/llflash.h @@ -7,44 +7,22 @@ void flash_unlock(void) { FLASH->KEYR = 0xCDEF89AB; } -void flash_lock(void) { - FLASH->CR |= FLASH_CR_LOCK; -} - -bool flash_erase_sector(uint16_t sector) { -#ifdef BOOTSTUB +bool flash_erase_sector(uint8_t sector, bool unlocked) { // don't erase the bootloader(sector 0) - uint16_t min_sector = 1U; - uint16_t max_sector = 11U; -#else - uint16_t min_sector = LOGGING_FLASH_SECTOR_A; - uint16_t max_sector = LOGGING_FLASH_SECTOR_B; -#endif - - bool ret = false; - if ((sector >= min_sector) && (sector <= max_sector) && (!flash_is_locked())) { + if (sector != 0 && sector < 12 && unlocked) { FLASH->CR = (sector << 3) | FLASH_CR_SER; FLASH->CR |= FLASH_CR_STRT; - while ((FLASH->SR & FLASH_SR_BSY) != 0U); - ret = true; + while (FLASH->SR & FLASH_SR_BSY); + return true; } - return ret; + return false; } -void flash_write_word(uint32_t *prog_ptr, uint32_t data) { - #ifndef BOOTSTUB - // don't write to any region besides the logging region - if ((prog_ptr >= (uint32_t *)LOGGING_FLASH_BASE_A) && (prog_ptr < (uint32_t *)(LOGGING_FLASH_BASE_B + LOGGING_FLASH_SECTOR_SIZE))) { - #endif - - uint32_t *pp = prog_ptr; - FLASH->CR = FLASH_CR_PSIZE_1 | FLASH_CR_PG; - *pp = data; - while ((FLASH->SR & FLASH_SR_BSY) != 0U); - - #ifndef BOOTSTUB - } - #endif +void flash_write_word(void *prog_ptr, uint32_t data) { + uint32_t *pp = prog_ptr; + FLASH->CR = FLASH_CR_PSIZE_1 | FLASH_CR_PG; + *pp = data; + while (FLASH->SR & FLASH_SR_BSY); } void flush_write_buffer(void) { } diff --git a/board/stm32fx/stm32fx_config.h b/board/stm32fx/stm32fx_config.h index dd026e98..b4701192 100644 --- a/board/stm32fx/stm32fx_config.h +++ b/board/stm32fx/stm32fx_config.h @@ -38,12 +38,6 @@ #define PROVISION_CHUNK_ADDRESS 0x1FFF79E0U #define DEVICE_SERIAL_NUMBER_ADDRESS 0x1FFF79C0U -#define LOGGING_FLASH_SECTOR_A 10U -#define LOGGING_FLASH_SECTOR_B 11U -#define LOGGING_FLASH_BASE_A 0x080C0000U -#define LOGGING_FLASH_BASE_B 0x080E0000U -#define LOGGING_FLASH_SECTOR_SIZE 0x20000U - #include "can_definitions.h" #include "comms_definitions.h" @@ -71,7 +65,6 @@ #include "stm32fx/board.h" #include "stm32fx/clock.h" #include "drivers/watchdog.h" -#include "stm32fx/llflash.h" #if !defined(PEDAL) || defined(BOOTSTUB) #include "drivers/spi.h" @@ -87,7 +80,9 @@ #include "stm32fx/llexti.h" #endif -#ifndef BOOTSTUB +#ifdef BOOTSTUB + #include "stm32fx/llflash.h" +#else #include "stm32fx/llbxcan.h" #endif diff --git a/board/stm32h7/llflash.h b/board/stm32h7/llflash.h index 800d9414..b95011a9 100644 --- a/board/stm32h7/llflash.h +++ b/board/stm32h7/llflash.h @@ -7,49 +7,27 @@ void flash_unlock(void) { FLASH->KEYR1 = 0xCDEF89AB; } -void flash_lock(void) { - FLASH->CR1 |= FLASH_CR_LOCK; -} - -bool flash_erase_sector(uint16_t sector) { - #ifdef BOOTSTUB - // don't erase the bootloader(sector 0) - uint16_t min_sector = 1U; - uint16_t max_sector = 7U; - #else - uint16_t min_sector = LOGGING_FLASH_SECTOR_A; - uint16_t max_sector = LOGGING_FLASH_SECTOR_B; - #endif - - bool ret = false; - if ((sector >= min_sector) && (sector <= max_sector) && (!flash_is_locked())) { +bool flash_erase_sector(uint8_t sector, bool unlocked) { + // don't erase the bootloader(sector 0) + if (sector != 0 && sector < 8 && unlocked) { FLASH->CR1 = (sector << 8) | FLASH_CR_SER; FLASH->CR1 |= FLASH_CR_START; - while ((FLASH->SR1 & FLASH_SR_QW) != 0U); - ret = true; + while (FLASH->SR1 & FLASH_SR_QW); + return true; } - return ret; + return false; } -void flash_write_word(uint32_t *prog_ptr, uint32_t data) { - #ifndef BOOTSTUB - // don't write to any region besides the logging region - if ((prog_ptr >= (uint32_t *)LOGGING_FLASH_BASE_A) && (prog_ptr < (uint32_t *)(LOGGING_FLASH_BASE_B + LOGGING_FLASH_SECTOR_SIZE))) { - #endif - - uint32_t *pp = prog_ptr; - FLASH->CR1 |= FLASH_CR_PG; - *pp = data; - while ((FLASH->SR1 & FLASH_SR_QW) != 0U); - - #ifndef BOOTSTUB - } - #endif +void flash_write_word(void *prog_ptr, uint32_t data) { + uint32_t *pp = prog_ptr; + FLASH->CR1 |= FLASH_CR_PG; + *pp = data; + while (FLASH->SR1 & FLASH_SR_QW); } void flush_write_buffer(void) { - if ((FLASH->SR1 & FLASH_SR_WBNE) != 0U) { + if (FLASH->SR1 & FLASH_SR_WBNE) { FLASH->CR1 |= FLASH_CR_FW; - while ((FLASH->SR1 & FLASH_CR_FW) != 0U); + while (FLASH->SR1 & FLASH_CR_FW); } } diff --git a/board/stm32h7/stm32h7_config.h b/board/stm32h7/stm32h7_config.h index f00b5794..a7d54274 100644 --- a/board/stm32h7/stm32h7_config.h +++ b/board/stm32h7/stm32h7_config.h @@ -46,12 +46,6 @@ separate IRQs for RX and TX. #define PROVISION_CHUNK_ADDRESS 0x080FFFE0U #define DEVICE_SERIAL_NUMBER_ADDRESS 0x080FFFC0U -#define LOGGING_FLASH_SECTOR_A 5U -#define LOGGING_FLASH_SECTOR_B 6U -#define LOGGING_FLASH_BASE_A 0x080A0000U -#define LOGGING_FLASH_BASE_B 0x080C0000U -#define LOGGING_FLASH_SECTOR_SIZE 0x20000U - #include "can_definitions.h" #include "comms_definitions.h" @@ -73,7 +67,6 @@ separate IRQs for RX and TX. #include "stm32h7/interrupt_handlers.h" #include "drivers/timers.h" #include "drivers/watchdog.h" -#include "stm32h7/llflash.h" #if !defined(BOOTSTUB) #include "drivers/uart.h" @@ -87,7 +80,9 @@ separate IRQs for RX and TX. #include "stm32h7/llexti.h" #endif -#ifndef BOOTSTUB +#ifdef BOOTSTUB + #include "stm32h7/llflash.h" +#else #include "stm32h7/llfdcan.h" #endif diff --git a/python/__init__.py b/python/__init__.py index 91523e8f..bfa37684 100644 --- a/python/__init__.py +++ b/python/__init__.py @@ -106,24 +106,6 @@ ensure_health_packet_version = partial(ensure_version, "health", "HEALTH_PACKET_ -def parse_timestamp(dat): - a = struct.unpack("HBBBBBB", dat) - if a[0] == 0: - return None - - try: - return datetime.datetime(a[0], a[1], a[2], a[4], a[5], a[6]) - except ValueError: - return None - -def unpack_log(dat): - return { - 'id': struct.unpack("H", dat[:2])[0], - 'timestamp': parse_timestamp(dat[2:10]), - 'uptime': struct.unpack("I", dat[10:14])[0], - 'msg': bytes(dat[14:]).decode('utf-8', 'ignore').strip('\x00'), - } - class ALTERNATIVE_EXPERIENCE: DEFAULT = 0 DISABLE_DISENGAGE_ON_GAS = 1 @@ -966,7 +948,8 @@ class Panda: def get_datetime(self): dat = self._handle.controlRead(Panda.REQUEST_IN, 0xa0, 0, 0, 8) - return parse_timestamp(dat) + a = struct.unpack("HBBBBBB", dat) + return datetime.datetime(a[0], a[1], a[2], a[4], a[5], a[6]) # ****************** Timer ***************** def get_microsecond_timer(self): @@ -1003,15 +986,3 @@ class Panda: def force_relay_drive(self, intercept_relay_drive, ignition_relay_drive): self._handle.controlWrite(Panda.REQUEST_OUT, 0xc5, (int(intercept_relay_drive) | int(ignition_relay_drive) << 1), 0, b'') - - # ****************** Logging ***************** - def get_logs(self, last_id=None, get_all=False): - assert (last_id is None) or (0 <= last_id < 0xFFFF) - - logs = [] - dat = self._handle.controlRead(Panda.REQUEST_IN, 0xfd, 1 if get_all else 0, last_id if last_id is not None else 0xFFFF, 0x40) - while len(dat) > 0: - if len(dat) == 0x40: - logs.append(unpack_log(dat)) - dat = self._handle.controlRead(Panda.REQUEST_IN, 0xfd, 0, 0xFFFF, 0x40) - return logs diff --git a/tests/hitl/1_program.py b/tests/hitl/1_program.py index d4e6e4fd..d4b08f0f 100644 --- a/tests/hitl/1_program.py +++ b/tests/hitl/1_program.py @@ -10,7 +10,6 @@ def check_signature(p): assert p.up_to_date() -@pytest.mark.expected_logs(1) def test_dfu(p): app_mcu_type = p.get_mcu_type() dfu_serial = p.get_dfu_serial() @@ -31,7 +30,6 @@ def test_dfu(p): # TODO: make more comprehensive bootstub tests and run on a few production ones + current # TODO: also test release-signed app @pytest.mark.execution_timeout(30) -@pytest.mark.expected_logs(1, 2) def test_known_bootstub(p): """ Test that compiled app can work with known production bootstub @@ -78,13 +76,11 @@ def test_known_bootstub(p): assert not p.bootstub @pytest.mark.execution_timeout(25) -@pytest.mark.expected_logs(1) def test_recover(p): assert p.recover(timeout=30) check_signature(p) @pytest.mark.execution_timeout(25) -@pytest.mark.expected_logs(3) def test_flash(p): # test flash from bootstub serial = p._serial diff --git a/tests/hitl/2_health.py b/tests/hitl/2_health.py index fd39cc0f..acb993f5 100644 --- a/tests/hitl/2_health.py +++ b/tests/hitl/2_health.py @@ -5,7 +5,7 @@ from panda import Panda from panda import PandaJungle from panda.tests.hitl.conftest import PandaGroup -@pytest.mark.expected_logs(1) + def test_ignition(p, panda_jungle): # Set harness orientation to #2, since the ignition line is on the wrong SBU bus :/ panda_jungle.set_harness_orientation(PandaJungle.HARNESS_ORIENTATION_2) @@ -71,7 +71,6 @@ def test_voltage(p): assert ((voltage > 11000) and (voltage < 13000)) time.sleep(0.1) -@pytest.mark.expected_logs(1) def test_hw_type(p): """ hw type should be same in bootstub as application @@ -124,17 +123,3 @@ def test_microsecond_timer(p): time_diff = (end_time - start_time) / 1e6 assert 0.98 < time_diff < 1.02, f"Timer not running at the correct speed! (got {time_diff:.2f}s instead of 1.0s)" - -@pytest.mark.skip("logging is disabled") -@pytest.mark.expected_logs(1) -def test_logging(p): - p.reset() - - logs = p.get_logs(True) - assert len(logs) > 0 - assert len(p.get_logs()) == 0 - - # we assume the start log is relatively recent - start_logs = list(filter(lambda x: x['msg'] == 'main start', logs[-5:])) - assert len(start_logs) > 0 - assert start_logs[0]['uptime'] < 2 diff --git a/tests/hitl/5_spi.py b/tests/hitl/5_spi.py index d67f7c4e..f9a4e28d 100644 --- a/tests/hitl/5_spi.py +++ b/tests/hitl/5_spi.py @@ -11,7 +11,6 @@ pytestmark = [ ] @pytest.mark.skip("doesn't work, bootloader seems to ignore commands once it sees junk") -@pytest.mark.expected_logs(0) def test_dfu_with_spam(p): dfu_serial = p.get_dfu_serial() @@ -38,7 +37,6 @@ class TestSpi: assert spy.call_count == 2 mocker.stop(spy) - @pytest.mark.expected_logs(2) def test_protocol_version_check(self, p): for bootstub in (False, True): p.reset(enter_bootstub=bootstub) @@ -50,7 +48,6 @@ class TestSpi: with pytest.raises(PandaProtocolMismatch): Panda(p._serial) - @pytest.mark.expected_logs(2) def test_protocol_version_data(self, p): for bootstub in (False, True): p.reset(enter_bootstub=bootstub) @@ -96,11 +93,11 @@ class TestSpi: for _ in range(10): ep = random.randint(4, 20) with pytest.raises(PandaSpiNackResponse): - p._handle.bulkRead(ep, random.randint(1, 1000), timeout=35) + p._handle.bulkRead(ep, random.randint(1, 1000), timeout=50) self._ping(mocker, p) with pytest.raises(PandaSpiNackResponse): - p._handle.bulkWrite(ep, b"abc", timeout=35) + p._handle.bulkWrite(ep, b"abc", timeout=50) self._ping(mocker, p) diff --git a/tests/hitl/conftest.py b/tests/hitl/conftest.py index 8d6030c4..eb8d3005 100644 --- a/tests/hitl/conftest.py +++ b/tests/hitl/conftest.py @@ -86,9 +86,6 @@ def pytest_configure(config): config.addinivalue_line( "markers", "panda_expect_can_error: mark test to ignore CAN health errors" ) - config.addinivalue_line( - "markers", "expected_logs(amount, ...): mark test to expect a certain amount of panda logs" - ) @pytest.hookimpl(tryfirst=True) def pytest_collection_modifyitems(items): @@ -145,10 +142,6 @@ def func_fixture_panda(request, module_panda): # TODO: reset is slow (2+ seconds) p.reset() - #logs = p.get_logs() - #last_log_id = logs[-1]['id'] if len(logs) > 0 else 0 - assert len(p.get_logs()) == 0 - # ensure FW hasn't changed assert p.up_to_date() @@ -175,23 +168,6 @@ def func_fixture_panda(request, module_panda): assert p.health()['faults'] == 0 assert p.health()['fault_status'] == 0 - # Make sure that there are no unexpected logs - """ - min_expected_logs = 0 - max_expected_logs = 0 - mark = request.node.get_closest_marker('expected_logs') - if mark: - assert len(mark.args) > 0, "Missing expected logs argument in mark" - min_expected_logs = mark.args[0] - max_expected_logs = mark.args[1] if len(mark.args) > 1 else min_expected_logs - - logs.extend(p.get_logs(True)) - log_id = logs[-1]['id'] if len(logs) > 0 else last_log_id - - assert min_expected_logs <= ((log_id - last_log_id) % 0xFFFE) <= max_expected_logs, f"Unexpected amount of logs. Last 5: {logs[-5:]}" - """ - assert len(p.get_logs()) == 0 - # Check for SPI errors #assert p.health()['spi_checksum_error_count'] == 0 diff --git a/tests/libpanda/SConscript b/tests/libpanda/SConscript index 15e12081..265fac9d 100644 --- a/tests/libpanda/SConscript +++ b/tests/libpanda/SConscript @@ -15,7 +15,6 @@ env = Environment( '-std=gnu11', '-Wfatal-errors', '-Wno-pointer-to-int-cast', - '-DENABLE_LOGGING', ], CPPPATH=[".", "../../board/"], ) diff --git a/tests/libpanda/libpanda_py.py b/tests/libpanda/libpanda_py.py index e8f063bf..0afc1fe6 100644 --- a/tests/libpanda/libpanda_py.py +++ b/tests/libpanda/libpanda_py.py @@ -54,34 +54,6 @@ void comms_can_reset(void); uint32_t can_slots_empty(can_ring *q); """) -ffi.cdef(""" - typedef struct timestamp_t { - uint16_t year; - uint8_t month; - uint8_t day; - uint8_t weekday; - uint8_t hour; - uint8_t minute; - uint8_t second; - } timestamp_t; - - typedef struct { - uint16_t id; - timestamp_t timestamp; - uint32_t uptime; - char msg[50]; - } log_t; - - extern uint32_t *logging_bank; - extern uint32_t logging_bank_size; - extern uint32_t logging_rate_limit; - - void logging_init(void); - void logging_tick(void); - void log(const char* msg); - uint8_t logging_read(uint8_t *buffer); -""") - setup_safety_helpers(ffi) class CANPacket: @@ -108,14 +80,6 @@ class Panda(PandaSafety, Protocol): def safety_fwd_hook(self, bus_num: int, addr: int) -> int: ... def set_safety_hooks(self, mode: int, param: int) -> int: ... - # logging - def logging_init(self) -> None: ... - def logging_tick(self) -> None: ... - def log(self, msg: bytearray) -> None: ... - def logging_read(self, buffer: bytearray) -> int: ... - logging_bank: bytearray - logging_bank_size: int - logging_rate_limit: int libpanda: Panda = ffi.dlopen(libpanda_fn) diff --git a/tests/libpanda/panda.c b/tests/libpanda/panda.c index 050e102a..8efb6de4 100644 --- a/tests/libpanda/panda.c +++ b/tests/libpanda/panda.c @@ -19,13 +19,6 @@ void can_tx_comms_resume_spi(void) { }; #include "safety.h" #include "main_declarations.h" #include "drivers/can_common.h" -#include "drivers/logging.h" - -// Board -const board fake_board = { - .has_rtc_battery = true, -}; -const board *current_board = &fake_board; can_ring *rx_q = &can_rx_q; can_ring *txgmlan_q = &can_txgmlan_q; @@ -33,10 +26,6 @@ can_ring *tx1_q = &can_tx1_q; can_ring *tx2_q = &can_tx2_q; can_ring *tx3_q = &can_tx3_q; -uint32_t *logging_bank = (uint32_t *) fake_logging_bank; -uint32_t logging_bank_size = sizeof(fake_logging_bank); -uint32_t logging_rate_limit = LOGGING_MAX_LOGS_PER_MINUTE; - #include "comms_definitions.h" #include "can_comms.h" diff --git a/tests/logging/test.sh b/tests/logging/test.sh deleted file mode 100755 index 9e084772..00000000 --- a/tests/logging/test.sh +++ /dev/null @@ -1,4 +0,0 @@ -#!/usr/bin/env bash -set -e - -python -m unittest discover . diff --git a/tests/logging/test_logging.py b/tests/logging/test_logging.py deleted file mode 100755 index dc24f8b2..00000000 --- a/tests/logging/test_logging.py +++ /dev/null @@ -1,77 +0,0 @@ -#!/usr/bin/env python3 - -import random -import unittest -import datetime - -from panda import unpack_log -from panda.tests.libpanda import libpanda_py - -lpp = libpanda_py.libpanda - -class TestLogging(unittest.TestCase): - def setUp(self): - # Clear buffer and setup state - for i in range(lpp.logging_bank_size // 4): - lpp.logging_bank[i] = 0xFFFFFFFF - lpp.logging_init() - - def _get_logs(self): - logs = [] - while True: - log = libpanda_py.ffi.new("uint8_t[64]") - if lpp.logging_read(log) == 0: - break - logs.append(log) - return logs - - def _log(self, msg): - lpp.log(libpanda_py.ffi.new("char[]", msg.encode("utf-8"))) - - def test_random_buffer_init(self): - for i in range(lpp.logging_bank_size // 4): - lpp.logging_bank[i] = random.randint(0, 0xFFFFFFFF) - - lpp.logging_init() - - for i in range(lpp.logging_bank_size // 4): - assert lpp.logging_bank[i] == 0xFFFFFFFF - self.assertEqual(lpp.logging_read(libpanda_py.ffi.new("uint8_t[64]")), 0) - - def test_rate_limit(self): - for _ in range(lpp.logging_rate_limit + 5): - self._log("test") - self.assertEqual(len(self._get_logs()), lpp.logging_rate_limit) - self.assertEqual(len(self._get_logs()), 0) - - for _ in range(62): - lpp.logging_tick() - - for _ in range(lpp.logging_rate_limit + 5): - self._log("test") - - self.assertEqual(len(self._get_logs()), lpp.logging_rate_limit) - self.assertEqual(len(self._get_logs()), 0) - - def test_logging(self): - msg = "testing 123" - self._log(msg) - logs = self._get_logs() - self.assertEqual(len(logs), 1) - log = unpack_log(bytes(logs[0])) - self.assertEqual(log['msg'], msg) - self.assertEqual(log['uptime'], 0) - self.assertEqual(log['id'], 1) - self.assertEqual(log['timestamp'], datetime.datetime(1996, 4, 23, 4, 20, 20)) - - def test_bank_overflow(self): - for i in range(1, 10000): - self._log("test") - - if i % 5 == 0: - lpp.logging_init() - expected_messages = (i % 2048) + (2048 if i >= 2048 else 0) - self.assertEqual(len(self._get_logs()), expected_messages) - -if __name__ == "__main__": - unittest.main() \ No newline at end of file diff --git a/tests/print_logs.py b/tests/print_logs.py deleted file mode 100755 index dedcdedd..00000000 --- a/tests/print_logs.py +++ /dev/null @@ -1,8 +0,0 @@ -#!/usr/bin/env python3 - -from panda import Panda - -if __name__ == "__main__": - p = Panda() - for l in p.get_logs(): - print(f"{l['id']:<6d} {l['timestamp']} {l['uptime']:6d} - {l['msg']}")