diff --git a/docs/现场网络诊断.md b/docs/现场网络诊断.md index d984911..b0f26e7 100644 --- a/docs/现场网络诊断.md +++ b/docs/现场网络诊断.md @@ -21,7 +21,7 @@ python3 tools/read_usb_log.py --port /dev/cu.usbmodemXXXX --reconnect 也可以使用现有串口终端打开这个 USB CDC 口:115200、8N1、无流控、UTF-8。同一端口同时只用一个读取程序。没有新增端口时,先检查数据线和 Mac 的 USB 设备枚举;实际板上的 USB 数据连接、CDC 描述符和 Mac 驱动识别仍需上板确认。 -日志通过约 8 KB 的有界队列交给独立低优先级 USB 转发任务。业务日志入队使用零等待;USB 写失败时关闭并重新打开 CDC。队列拥塞或写失败会丢弃 USB 副本并累计计数,在线提示每约 5 秒报告一次。电脑接收时间不等于设备事件时间;断线前 SDK 已接受但未送到电脑的数据也无法保证补回,不支持历史日志回放。 +日志保存在约 8 KB 的固定缓冲池中,通过只传递 4 字节缓冲区索引的有界队列交给独立低优先级 USB 转发任务,避免整条日志超过 SDK 的队列消息尺寸限制。业务日志入队使用零等待;USB 写失败时关闭并重新打开 CDC。队列拥塞或写失败会丢弃 USB 副本并累计计数,在线提示每约 5 秒报告一次。电脑接收时间不等于设备事件时间;断线前 SDK 已接受但未送到电脑的数据也无法保证补回,不支持历史日志回放。 转发范围是 `custom_app` 目标内编译的 `printf`,包括这次新增的诊断、VAD、WSS 和播放器日志。预编译库、内核、基带和启动前日志不经过本转发。单次格式化最多 511 字节,超长记录会明确加 `[TRUNCATED]`,并在 UTF-8 字符边界截断。日志不写设备 Flash、不上传服务器。 diff --git a/ql-application/threadx/interface/custom_app/field_log.c b/ql-application/threadx/interface/custom_app/field_log.c index 4ff0e1f..e034d19 100644 --- a/ql-application/threadx/interface/custom_app/field_log.c +++ b/ql-application/threadx/interface/custom_app/field_log.c @@ -13,6 +13,10 @@ extern int printf(const char *format, ...); #define LOG_RECORD_BYTES 512 #define LOG_QUEUE_DEPTH 16 struct log_record { unsigned int length; char text[LOG_RECORD_BYTES]; }; +/* Queue only a 32-bit slot index; full records exceed this SDK's queue + * message-size limit. Slots remain owned until the worker finishes writing. */ +static struct log_record log_pool[LOG_QUEUE_DEPTH]; +static unsigned char slot_used[LOG_QUEUE_DEPTH]; static ql_queue_t usb_queue; static ql_task_t usb_task; static volatile int ready; @@ -25,6 +29,24 @@ static void note_drop(void) ql_rtos_task_sched_unlock(); } +static unsigned int reserve_slot(void) +{ + unsigned int slot; + ql_rtos_task_sched_lock(); + for (slot = 0; slot < LOG_QUEUE_DEPTH; ++slot) { + if (!slot_used[slot]) { slot_used[slot] = 1; break; } + } + ql_rtos_task_sched_unlock(); + return slot; +} + +static void release_slot(unsigned int slot) +{ + ql_rtos_task_sched_lock(); + slot_used[slot] = 0; + ql_rtos_task_sched_unlock(); +} + int field_log_printf(const char *format, ...) { struct log_record record; @@ -43,9 +65,18 @@ int field_log_printf(const char *format, ...) } record.length = (unsigned int)strlen(record.text); ret = printf("%s", record.text); - if (ready && record.length && - ql_rtos_queue_release(usb_queue, sizeof(record), (u8 *)&record, QL_NO_WAIT) != 0) - note_drop(); + if (ready && record.length) { + unsigned int slot = reserve_slot(); + if (slot == LOG_QUEUE_DEPTH) { + note_drop(); + } else { + log_pool[slot] = record; + if (ql_rtos_queue_release(usb_queue, sizeof(slot), (u8 *)&slot, QL_NO_WAIT) != 0) { + release_slot(slot); + note_drop(); + } + } + } return ret; } @@ -64,7 +95,7 @@ static int usb_write_all(const char *text, int length) static void usb_worker(void *arg) { - struct log_record record; + unsigned int slot; int opened = 0; unsigned long last_notice = 0, reported = 0; (void)arg; @@ -78,8 +109,11 @@ static void usb_worker(void *arg) } if (!opened) { ql_rtos_task_sleep_ms(1000); continue; } } - if (ql_rtos_queue_wait(usb_queue, (u8 *)&record, sizeof(record), 1000) == 0) { - if (usb_write_all(record.text, record.length) != 0) { + if (ql_rtos_queue_wait(usb_queue, (u8 *)&slot, sizeof(slot), 1000) == 0 && + slot < LOG_QUEUE_DEPTH) { + int result = usb_write_all(log_pool[slot].text, log_pool[slot].length); + release_slot(slot); + if (result != 0) { note_drop(); ql_uart_close(QL_USB_CDC_PORT); opened = 0; @@ -106,7 +140,7 @@ int field_log_init(void) { int ret; if (ready) return 0; - ret = ql_rtos_queue_create(&usb_queue, sizeof(struct log_record), LOG_QUEUE_DEPTH); + ret = ql_rtos_queue_create(&usb_queue, sizeof(unsigned int), LOG_QUEUE_DEPTH); if (ret != 0) { printf("[USB日志] 队列创建失败=%d;仅保留UART日志\r\n", ret); return ret; } ret = ql_rtos_task_create(&usb_task, 4096, 130, "usb_log", usb_worker, NULL); if (ret != 0) { diff --git a/tools/test_net_diag.py b/tools/test_net_diag.py index 7ddb5e0..d951f27 100644 --- a/tools/test_net_diag.py +++ b/tools/test_net_diag.py @@ -185,20 +185,29 @@ static char sent_text[4096]; QlOSStatus ql_rtos_task_sched_lock(void) { return 0; } QlOSStatus ql_rtos_task_sched_unlock(void) { return 0; } QlOSStatus ql_rtos_queue_create(ql_queue_t *q, u32 size, u32 count) { - assert(size == sizeof(struct log_record) && size % 4 == 0 && count == 16); + /* Model the target rejecting oversized messages (old code used 516). */ + if (size > 64) return -6743; + assert(size == 4 && count == 16); *q = (void *)1; return queue_mode == 1 ? -1 : 0; } QlOSStatus ql_rtos_queue_delete(ql_queue_t q) { assert(q); ++queue_deletes; return 0; } QlOSStatus ql_rtos_queue_release(ql_queue_t q, u32 size, u8 *record, u32 timeout) { - assert(q && size == sizeof(struct log_record) && timeout == 0); - last_record = *(struct log_record *)record; return queue_mode == 2 ? -1 : 0; + unsigned int slot = *(unsigned int *)record; + assert(q && size == 4 && timeout == 0 && slot < LOG_QUEUE_DEPTH && slot_used[slot]); + last_record = log_pool[slot]; + if (queue_mode == 2) return -1; + if (queue_mode != 3) release_slot(slot); /* Simulate a completed consumer. */ + return 0; } QlOSStatus ql_rtos_queue_wait(ql_queue_t q, u8 *record, u32 size, u32 timeout) { (void)q; (void)size; (void)timeout; if (worker_run) { if (++worker_reads > 1) longjmp(usb_exit, 1); - strcpy(((struct log_record *)record)->text, "test"); - ((struct log_record *)record)->length = 4; return 0; + unsigned int slot = reserve_slot(); + assert(size == 4 && slot < LOG_QUEUE_DEPTH); + strcpy(log_pool[slot].text, "test"); + log_pool[slot].length = 4; + *(unsigned int *)record = slot; return 0; } return -1; } @@ -231,14 +240,32 @@ int main(void) { queue_mode = 2; field_log_printf("queue full\n"); assert(dropped == 1); queue_mode = 0; memset(large, 'A', 1000); large[1000] = 0; field_log_printf("%s", large); assert(strstr(last_record.text, "[TRUNCATED]") && last_record.length < 512); + { + unsigned int i; + ql_queue_t oversized; + assert(ql_rtos_queue_create(&oversized, 516, 16) == -6743); + for (i = 0; i < LOG_QUEUE_DEPTH; ++i) assert(!slot_used[i]); + queue_mode = 3; + for (i = 0; i < LOG_QUEUE_DEPTH; ++i) field_log_printf("held %u", i); + for (i = 0; i < LOG_QUEUE_DEPTH; ++i) { + char expected[32]; + snprintf(expected, sizeof(expected), "held %u", i); + assert(slot_used[i] && strcmp(log_pool[i].text, expected) == 0); + } + field_log_printf("pool full"); assert(dropped == 2); + for (i = 0; i < LOG_QUEUE_DEPTH; ++i) release_slot(i); + queue_mode = 0; + field_log_printf("recovered"); assert(strcmp(last_record.text, "recovered") == 0); + } write_mode = 0; assert(usb_write_all("abcdef", 6) == 0 && writes == 1 && strcmp(sent_text, "abcdef") == 0); sent_text[0] = 0; writes = 0; write_mode = 1; assert(usb_write_all("abcdef", 6) == 0 && writes == 2 && strcmp(sent_text, "abcdef") == 0); write_mode = 2; assert(usb_write_all("abcdef", 6) == -1); worker_run = 1; write_mode = 3; writes = 0; sent_text[0] = 0; if (!setjmp(usb_exit)) usb_worker(NULL); - assert(open_count == 2 && close_count == 1 && dropped == 2); - puts("PASS: USB init rollback, no-wait queue, mirror, truncation, writes, disconnect/reopen"); + assert(open_count == 2 && close_count == 1 && dropped == 3); + assert(!slot_used[0]); + puts("PASS: USB 4-byte queue, SDK size rejection, pool exhaustion/recovery, init rollback, no-wait, truncation, disconnect/reopen"); return 0; } '''