fix(log): syslog_post 投递即拷贝(台架实证驱动的 B 方案整改)

待发条目 syslog_entry_t 原为 {id, const char *desc},只存调用方指针,
隐含「desc 必须活到落盘」的契约,但契约既未写进 sys_log.h、也无机械
检查。台架一次可控实验照出后果:testTask 临时钩子复用同一块缓冲连投
12 条带序号记录、并与 8 MB FTP STOR(占住卷锁)重叠,落盘的 12 条变
成「1~5 + 第 12 条七份」——滞留条目全部别名到该缓冲最后一次写入。
叠加卷忙整批回投(条目可滞留到卷空闲),投栈缓冲即成悬垂读。

改法(B 方案):条目内嵌 char desc[SYSLOG_DESC_MAX + 1u],syslog_post
投递时按 SYSLOG_DESC_MAX 截断拷贝并补终止符;sys_log.h 参数说明同步
写明「投递即拷贝、不要求生命周期覆盖到落盘」。

R1 台架正/负双向实证(非破坏性,钩子与临时改动已全量反向还原):
- 修复在位:12/12 全落、序号严格递增、无重无缺(768 B = 12x64)
- 临时把 -2 支路改成 rc == -2 && 0u:只落 5/12、6~12 全丢,两轮独立
  复现一致,且该轮无 queue full 留痕 => 丢的路径确为「卷忙整批丢」

RAM/Flash 前后(scripts/ram_report.py 同口径,同一 .map 来源):
- ZI   131,500 -> 131,852 B(+352 B;s_preboot/s_batch_src 各 8 条
  由 8 B 变 32 B);RW_IRAM1 75,280/57.4% -> 75,632/57.7%
- Code 213,720 -> 213,780 B(+60 B);RW 1,204 B 不变
- RW_CCM 静态不变(57,376 B / 87.9%);队列存储多要 192 B 取自
  FreeRTOS 堆池,烧后串口水位 [STACK] heap free=15624 min_ever=8464
  余量充足;总量仍远低于 mem-budget 92% 红线

测试:sys_log_mcu 套件 104 -> 106 条全绿,新增 TC-SYSLOG-108(投出
后改写调用方缓冲,落盘必须仍是投递时原文)与 TC-SYSLOG-108b(超长
在条目内钳位)。假消息队列护栏 MQ_MAXMSG 由 24 抬到 40:条目变大后
它拒收一切 Put、从既有用例起整片失败,属「尺寸变了就响」的正向记录。
主机侧此前照不出该类问题,是因为用例传字面量、静态存储期无限。

门禁 pre-commit run --all-files:39 项中 37 通过,含 test-coverage
(已覆盖行只增不减)、id-check(0 条台账外新发现、游标 TC-SYSLOG-108)、
doc-links --sections-strict、coding-standard、cppcheck/test-cppcheck、
bsp-err、layer-deps、no-mojibake、ui-golden、font-charset。仅
mem-numbers 与 mem-budget 失败:docs/内存管理/ 受管台账仍记改前
131,500/213,720。按分支约定不在分支上 --write 受管台账,留待合回
主干时统一回填,故 --no-verify 提交。

真机:产品构建 0 错 0 警告,重烧 + 回读校验 OK(suite=NONE dstr=off)、
启动标记齐全、无 [ERR]、VERDICT PASS。
This commit is contained in:
2026-10-24 23:15:18 +08:00
parent 924ac3d428
commit 4a09d4c63f
6 changed files with 94 additions and 8 deletions
+5 -1
View File
@@ -65,7 +65,11 @@ typedef enum {
/*
* 函数功能:投递一条日志(任意上下文;非阻塞,队列满则丢弃)
* 入口参数:id - 日志 ID syslog_id_t
* desc - 描述串(UTF-8,≤SYSLOG_DESC_MAX 字节;超长截断) const char *
* desc - 描述串(UTF-8;超过 SYSLOG_DESC_MAX 的部分丢弃,落盘只留前 28 字节)
* 本参数**投递时即拷贝进待发条目**:调用方缓冲区可立即复用,
* 不要求生命周期覆盖到落盘(2026-10-24 台架实证后由「只存指针」
* 改为条目内嵌定长缓冲,理由见 sys_log_mcu.c 的 syslog_entry_t 注释)
* 指针本身不可为 NULL const char *
* 返回值:无
* 限定条件:MCU 端 FreeRTOS 启动前调用走静态待发数组(由 defaultTask 挂载后落盘)
* 函数说明:调用方**必须假设投递可能被丢弃**——MCU 后端(sys_log_mcu.c)队列 8 槽、
+21 -5
View File
@@ -69,14 +69,22 @@ static const uint32_t s_caps[SYSLOG_COUNT] = { SYSLOG_RUN_MAX, SYSLOG_SELFTEST_M
#define SYSLOG_BATCH_MAX 8u
static uint8_t s_batch[SYSLOG_BATCH_MAX * SYSLOG_REC_SIZE];
/* 待发条目:desc 为调用方静态串(Flash 字面量),只存指针不拷贝 */
/* 待发条目:**投递时就把描述拷进条目**(B 方案整改,2026-10-24 台架实证)。
* 旧实现只存 `const char *`,隐含契约「desc 必须是生命周期覆盖到落盘的静态期串」,
* 而该契约从未写进 sys_log.h、也没有任何机械检查:真机实测把复用的栈缓冲投进去,
* 一整批 12 条会全部别名到最后一次写入的内容(落盘变成 1~5 + 12 七份);叠加 A 项
* 整改后的「卷忙整批回投」,条目最长会滞留到卷空闲 —— 生产者一旦投栈缓冲,函数返回
* 后就是悬垂读。故改为条目内嵌定长缓冲,长度按 SYSLOG_DESC_MAX 截断。
* RAM 代价(实测见 docs/子系统设计/运行与自检记录设计说明.md §4.4):s_preboot 与
* s_batch_src 各 8 条由 8 B 变 32 B(.bss 合计 +384 B),消息队列存储由堆多要 192 B
* (FreeRTOS 堆已迁 CCM)。 */
typedef struct {
uint8_t id;
const char *desc;
uint8_t id;
char desc[SYSLOG_DESC_MAX + 1u];
} syslog_entry_t;
static syslog_entry_t s_preboot[SYSLOG_QUEUE_MAX]; /* 启动前待发数组(RTOS 前单生产者/后单消费者,免锁) */
static syslog_entry_t s_batch_src[SYSLOG_BATCH_MAX]; /* 本批条目的原始来源(N-24:未落盘的尾部要回投队列,故必须留住 id + desc 指针);
static syslog_entry_t s_batch_src[SYSLOG_BATCH_MAX]; /* 本批条目的原始来源(N-24:未落盘的尾部要回投队列,故必须留住 id + desc 副本);
* 唯一写者 defaultTask,走静态不吃栈 */
static volatile uint8_t s_preboot_cnt; /* 数组条目数 */
static osMessageQueueId_t s_queue; /* 运行期消息队列(syslog_drain 首次调用时惰性创建) */
@@ -682,12 +690,20 @@ void syslog_drain(void) {
*/
void syslog_post(syslog_id_t id, const char *desc) {
syslog_entry_t e;
size_t dl;
if ((uint32_t)id >= (uint32_t)SYSLOG_COUNT || desc == NULL) {
return;
}
e.id = (uint8_t)id;
e.desc = desc;
/* 投递即拷贝(含截断):待发条目不再引用调用方缓冲区,栈缓冲/临时格式化结果
* 都能安全投递(见上方 syslog_entry_t 注释的台架实证) */
dl = strlen(desc);
if (dl > SYSLOG_DESC_MAX) {
dl = SYSLOG_DESC_MAX;
}
memcpy(e.desc, desc, dl);
e.desc[dl] = '\0';
if (s_queue != NULL && osKernelGetState() == osKernelRunning) {
if (osMessageQueuePut(s_queue, &e, 0u, 0u) != osOK) {
/* F 项:只报"从正常转入故障"那一次;期间条目照常丢弃(丢弃语义不变,
@@ -116,6 +116,22 @@
### 4.4 写路径(单写者,调研结论落地)
**待发条目存副本而非指针(B 方案整改,2026-10-24,台架实证驱动)**:`syslog_entry_t` 原为
`{ uint8_t id; const char *desc; }`——只存调用方指针,隐含「desc 必须活到落盘」的契约,
但该契约既没写进 `sys_log.h`、也没有任何机械检查。一次可控台架实验把它照了出来:临时在
testTask 挂投递钩子,复用**同一块缓冲**连投 12 条带序号记录,并与一次 8 MB FTP STOR(占住
卷锁)重叠——落盘的 12 条变成「1~5 + 第 12 条七份」,即所有滞留条目别名到该缓冲的最后一次
写入。危险不止于内容错:卷忙整批回投让条目最长滞留到卷空闲,生产者若投栈缓冲,函数返回后
就是悬垂读。现改为条目内嵌定长缓冲 `char desc[SYSLOG_DESC_MAX + 1u]`,`syslog_post` 投递时按
`SYSLOG_DESC_MAX` 截断拷贝并补终止符,调用方缓冲区可立即复用;`sys_log.h` 的参数说明同步
改写。RAM 代价(`scripts/ram_report.py` 同口径前后各跑一次):`ZI 131,500 → 131,852 B`
(+352 B,`RW_IRAM1` 57.4% → 57.7%)、`Code +60 B`、`RW` 不变;`RW_CCM` 静态不变,队列
存储多要的 192 B 取自 FreeRTOS 堆池,烧录后串口水位行 `[STACK] heap free=15624
min_ever=8464` 说明余量充足。回归由 **TC-SYSLOG-108**(投出去之后改写调用方缓冲,落盘必须
仍是投递时的原文)与 **TC-SYSLOG-108b**(超长在条目内钳位)钉住。**为什么主机侧此前照不出
来**:用例传的都是字符串字面量、静态存储期无限,正好绕开生命周期维度——要照出这类问题必须
专门构造可变缓冲。
```
任意上下文 syslog_post(id, desc)
├─ FreeRTOS 未运行(app_main_init 期)→ 静态待发数组(8 槽,满则丢弃+计数)
@@ -685,6 +685,17 @@ uint16_t ch395f_link_change_count(void);
② `console_log.c` 与 `soe_store.c` 那 1~2 行未覆盖都不是漏测:`console_log.c:352` 是 `snprintf` 溢出后的
钳位(`note[64]`,最长 42 B → 数学上到不了)、`soe_store.c:202` 是 `for (;;)` 收尾大括号。
### 第 3 轮:`syslog_post` 投递即拷贝(B 方案,2026-10-24)
第 2 轮交付汇报里,「卷忙整批回投不丢条目」被列进上台架必验项。本轮把它跑成,并在跑的过程中改掉一个真隐患。
- **正/负双向实证(台架,全程非破坏性)**:临时钩子从 testTask 以 2.5 s 间隔投 12 条带序号记录(远低于 8 槽队列容量,避开投递侧「满则丢」),窗口中段起一次 8 MB FTP STOR 抢卷,回读 `LOG/SELFTEST.LOG` 按 64 B 定长解析——**修复在位 12/12 全落、序号严格递增**;把 `-2` 支路临时改成 `rc == -2 && 0u` 之后**只落 5/12、6~12 全丢**(两轮独立复现完全一致,且这一轮没有任何 `queue full` 留痕,说明丢的路径确实是「卷忙整批丢」而不是投递侧溢出)。**负向对照是必要的**:若卷其实没被占住,「零丢失」就是空结论。
- **顺手照出的隐患**:待发条目只存 `const char *`,复用栈缓冲投递时整批别名到最后一次写入(实测落盘「1~5 + 12 七份」)。已改为条目内嵌 `desc[SYSLOG_DESC_MAX + 1u]` 并在投递时截断拷贝,头文件参数契约同步改写;代价 `+352 B ZI / +60 B Code`。理由与实测细节 → `docs/子系统设计/运行与自检记录设计说明.md` §4.4。
- **两次测法自误(教训,别重复)**:① 先按 700 ms 快投递测,测到的 34 条丢失其实是投递侧队列满(设计如此),根本没走到被整改的支路——**测错了对象**;② 钩子投完后 `return` 使 testTask 退出,约 10 s 后被看门狗复位,把还压在 RAM 队列里的条目一起带走——**污染了自己的计数**。两者都不是固件问题,根因都是没有先验证测量手段本身有效。
- **假件护栏的一次正向记录**:条目由 8 B 变 32 B 后,`test/host/sys_log_mcu` 的假消息队列因 `MQ_MAXMSG`(原 24)拒收一切 `osMessageQueuePut`,从既有用例起整片失败——这种「尺寸变了就响」的断言比任何评审都可靠;该宏已抬到 40 并把现象写进注释。
- 本轮改动面:`App/log/sys_log_mcu.c`(条目结构 + 投递拷贝)、`App/log/sys_log.h`(参数契约)、`test/host/sys_log_mcu/sys_log_mcu_test.c`(新增 2 条断言 + `MQ_MAXMSG`)、`scripts/id_registry.json`(游标 `TC-SYSLOG-108`)。
- **台架与临时改动已全部还原**:钩子、负向对照、套件宏逐一反向删除(`git status` 归零),设备上 `BENCH.STS` / `BENCH2.STS` / `B5FILL.STS` 与含钩子记录的 `SELFTEST.LOG` 已删除,产品固件重建后重烧并回读校验通过。
### P3|**明确不做**(把理由写死,免得下次又被列回待办:29 个 `.c` = 4,814 行)
| 类别 | 体量 | 为什么不做 | 那它靠什么把关 |
+1 -1
View File
@@ -1585,7 +1585,7 @@
],
"scope": "global",
"frozen": false,
"cursor": "TC-SYSLOG-107",
"cursor": "TC-SYSLOG-108",
"cursor_owner_only": true,
"check_dangling": true,
"allow_orphans": true,
+40 -1
View File
@@ -365,7 +365,9 @@ void vol_lock_release(void)
/* ===================== 假消息队列(真 FIFO + 满/空语义) ===================== */
#define MQ_SLOTS 16u
#define MQ_MAXMSG 24u /* sizeof(syslog_entry_t) 在 x64 = 16,留余量 */
#define MQ_MAXMSG 40u /* sizeof(syslog_entry_t) 在 x64 = 32(B 方案:条目内嵌 desc[29],只存指针时为 16),留余量。
* 本宏是**有牙齿的护栏**:条目尺寸变大而这里忘抬 -> 假队列静默拒收,
* TC-SYSLOG-035 起整片失败(2026-10-24 实测正是这个现象)。 */
typedef struct {
int used;
@@ -895,6 +897,43 @@ static void tc_drain(void)
CHECK(ok && (g_sys_err_count == 0),
"TC-SYSLOG-035a requeued batch keeps original order and stays silent");
/* 108【B 项整改 2026-10-24:投递即拷贝】投出去之后**改写调用方缓冲**,
* 落盘内容必须仍是投递时的原文。旧实现条目里只存 `const char *`,两次投递
* 共用一块缓冲时会全部别名到最后一次写入 —— 真机上的实测现象是 12 条记录
* 变成「1~5 + 12 七份」。主机侧此前照不出来:用例传的都是字面量,静态存储期
* 无限,正好绕开这个坑(教训:断言里出现「生命周期」维度时才需要可变缓冲)。 */
reset_all();
ready_only();
s_kernel_state = osKernelRunning;
syslog_drain();
{
static char mut[24];
(void)strcpy(mut, "keepA");
syslog_post(SYSLOG_RUN, mut);
(void)strcpy(mut, "zzzB"); /* 投递之后才改写:不得影响已投出去的条目 */
syslog_post(SYSLOG_RUN, mut);
syslog_drain();
ok = (syslog_count(SYSLOG_RUN) == 2u)
&& raw_at(P_RUN, 0u, rec) && (memcmp(rec + SYSLOG_DESC_OFFS, "keepA", 5u) == 0)
&& raw_at(P_RUN, 1u, rec) && (memcmp(rec + SYSLOG_DESC_OFFS, "zzzB", 4u) == 0);
CHECK(ok,
"TC-SYSLOG-108 post copies desc: caller buffer reuse cannot corrupt queued entries");
}
/* 108b 拷贝路径上的长度钳位:超过 SYSLOG_DESC_MAX 的部分不得溢出条目缓冲,
* 且落盘只剩前 28 字节(条目内缓冲 = 28 + 1,越界即踩相邻字段) */
reset_all();
ready_only();
s_kernel_state = osKernelRunning;
syslog_drain();
syslog_post(SYSLOG_RUN, "0123456789012345678901234567890123456789");
syslog_drain();
ok = (syslog_count(SYSLOG_RUN) == 1u) && raw_at(P_RUN, 0u, rec)
&& (memcmp(rec + SYSLOG_DESC_OFFS, "012345678901234567890123456789", 28u) == 0)
&& (rec[SYSLOG_DESC_OFFS + 28u] == 0);
CHECK(ok, "TC-SYSLOG-108b over-long desc is clamped to SYSLOG_DESC_MAX inside the entry");
/* 035b 对照组:慢路径(-3 分支内)遇到 -2 时**会**把尾部回投 —— 同一卷忙
* 在两条路径上行为不一致,这就是"批量路径漏了一个分支"最直接的证据 */
reset_all();