mawei/panda-meb
1
0
Fork 0
mirror of https://github.com/infiniteCable2/panda.git synced 2026-02-18 17:23:52 +08:00
Code Issues Packages Projects Releases Wiki Activity

Remove flash logging (#1674)

Browse Source 
* Revert "Disable flash logging (#1667)"

This reverts commit 62db60595b.

* Revert "Faster log retrieval (#1484)"

This reverts commit 694aae9c26.

* Revert "Flash bounds checking outside of bootstub (#1459)"

This reverts commit 054344de6b.

* Revert "Logging (#1445)"

This reverts commit 0cc91a7f7b.

* cleanup

* cleanup
This commit is contained in:
Adeeb Shihadeh
2023-09-30 12:49:46 -07:00
committed by GitHub
parent 6d0ffd96ab
commit b6e37f25b6
26 changed files with 59 additions and 619 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
.github/workflows/test.yaml vendored
View File

@@ -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

2
__init__.py
View File

@@ -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)

208
board/drivers/logging.h
View File

@@ -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

9
board/drivers/logging_definitions.h
View File

@@ -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;

21
board/drivers/rtc.h
View File

@@ -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){}

9
board/drivers/rtc_definitions.h
View File

@@ -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;

63
board/fake_stm.h
View File

@@ -2,10 +2,8 @@
#include <stdio.h>
#include <stdint.h>
#include <stdlib.h>
#include <stdbool.h>
#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) {}

1
board/faults.h
View File

@@ -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

4
board/flasher.h
View File

@@ -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;

13
board/main.c
View File

@@ -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);

12
board/main_comms.h
View File

@@ -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);

42
board/stm32fx/llflash.h
View File

@@ -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) { }

11
board/stm32fx/stm32fx_config.h
View File

@@ -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

48
board/stm32h7/llflash.h
View File

@@ -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);
}
}

11
board/stm32h7/stm32h7_config.h
View File

@@ -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

33
python/__init__.py
View File

@@ -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

4
tests/hitl/1_program.py
View File

@@ -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

17
tests/hitl/2_health.py
View File

@@ -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

7
tests/hitl/5_spi.py
View File

@@ -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)

24
tests/hitl/conftest.py
View File

@@ -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

1
tests/libpanda/SConscript
View File

@@ -15,7 +15,6 @@ env = Environment(
'-std=gnu11',
'-Wfatal-errors',
'-Wno-pointer-to-int-cast',
'-DENABLE_LOGGING',
],
CPPPATH=[".", "../../board/"],
)

36
tests/libpanda/libpanda_py.py
View File

@@ -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)

11
tests/libpanda/panda.c
View File

@@ -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"

4
tests/logging/test.sh
View File

@@ -1,4 +0,0 @@
#!/usr/bin/env bash
set -e
python -m unittest discover .

77
tests/logging/test_logging.py
View File

@@ -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()

8
tests/print_logs.py
View File

@@ -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']}")