test(b6): 台架 @test 闭环复测收口 + 启动行门控修复 + PC 104 主站

B6 台架 @test 闭环复测(B4/B5 验收窗口)完成,DoD 全判据过。

门控修复(首跑 FAIL 实锤的 B5 遗留竞态):
- 现象:protect task start 锚点行字节级交错损坏
  (st[art: cycle=220ms elm=70,两次开机同形复现)
- 根因:启动行在控制台写者注册前打印走无锁裸发,与
  defaultTask 启动日志交错——违反 2026-10-10 门控纪律
  (控制台单写者日志设计说明.md §3.4,adcTask 同款先例)
- 修复:启动锚点行改 dbg_console_writer_ready() 首拍补打

台架与工具:
- .serialtest/config.json:Required 增 protect task start /
  i104 listening on 2404 / [STACK] protect|iec104|heap
- test/host/iec104_master.py:纯标准库 104 主站客户端
  (STARTDT→总召四组+actterm→C_SE 两段写触发 YX15/16 变位
  COT=3→恢复复归→YK11 两段正答→C_RD 读回),往返 18/18
  PASS(d3107f3 与 B7+fix 两版固件)
- 复测 @test PASS:锚点完好 +577ms、9/9 Required、零 [ERR]、
  回读一致;protect free_min 1220(59%)、iec104 2136(83%)、
  新 56KB 堆 min_ever=10000(N-33 抬栈背书就绪)

证据与文档回填:
- boot_log_data 四份快照(含缺陷复现 MISS 件)+ README 登记
- 保护规划 §7 B6 行(B5 台架遗留闭环);控制台单写者 §3.4
  纪律示例 + §11 变更记录;IEC104 §7/§8 主站工具就绪;
  W1 卡 B6 ✅ + N-33 背书 + B7 台架腿注;登记簿 N-33
- 内存台账:+16 B 构建后 ram_baseline/check_mem_numbers 回填

验证:@build 0 错 0 警(Code=205516);ci_local 全绿
(L0 30 钩子 + L0.5 13 套件 826 断言)。
This commit is contained in:
2026-10-12 16:31:33 +08:00
parent 1fe163ba7b
commit dafcf8098b
17 changed files with 706 additions and 15 deletions
+1 -1
View File
@@ -7,7 +7,7 @@
"fw_marker": "fw build: ",
"readback_cmd": ".venv\\Scripts\\python.exe .dsh\\skills\\stlink-flash\\scripts\\stlink_flash.py cmp {hex}",
"required": "App init OK;Network Init;net init: OK",
"required": "App init OK;Network Init;net init: OK;protect task start;i104: listening on 2404;[STACK] protect;[STACK] iec104;[STACK] heap",
"forbidden": "FAIL;ERROR;HardFault;[ERR]",
"boot_marker": "reset cause:",
"max_boot_count": 1,
+13 -3
View File
@@ -22,6 +22,7 @@
#include "dbg_log.h"
#include "adc_health.h"
#include "console_log.h" /* dbg_console_writer_ready():启动锚点行门控(B6) */
#include "prot_elm.h"
#include "prot_set.h"
#include "task_watchdog.h"
@@ -69,15 +70,24 @@ static void s_log_active_edge(uint32_t active) {
* 每拍喂看门狗(TASK_WD_PROTECT,产品 required_mask 0x1F7)。
*/
void protect_task(void *argument) {
(void)argument;
uint8_t start_logged = 0u; /* 启动锚点行留痕(writer-ready 门控,B6) */
DBG_INFO("protect task start: cycle=%ums elm=%u",
(unsigned)PROTECT_TASK_CYCLE_MS, (unsigned)PE_COUNT);
(void)argument;
for (;;) {
uint32_t now = osKernelGetTickCount();
uint32_t hf = adc_health_flags();
/* 启动锚点行:控制台写者注册后首拍补打(2026-10-10 门控纪律,adcTask
* 首帧同款)。写者注册前 con_append 走无锁裸发,与 defaultTask 启动日志
* 逐字节交错——B6 台架实证:本行曾损坏为 "st[art: cycle=220ms elm=70"
* 致 @test 锚点 MISS(控制台单写者日志设计说明.md §3.4)。 */
if ((start_logged == 0u) && (dbg_console_writer_ready() != 0u)) {
DBG_INFO("protect task start: cycle=%ums elm=%u",
(unsigned)PROTECT_TASK_CYCLE_MS, (unsigned)PE_COUNT);
start_logged = 1u;
}
if ((hf & PROT_HF_LOCK_MASK) != 0u) {
/* L5-4:测量链不可信 → 复位元件(本任务上下文,直接 init 合法)
* 并跳过判据;stall 自愈后下一拍自动恢复 */
+3 -3
View File
@@ -52,9 +52,9 @@ graph LR
| 序 | 任务 | DoD(可验证验收判据) | 硬依赖 | 资源 | 写范围 | 状态 | 出处 |
|---|---|---|---|---|---|---|---|
| **B6** | **台架 `@test` 闭环复测(B4/B5 验收窗口)** | `@test` PASS:`protect task start` 锚点 ×1;`[STACK] protect`/`iec104` 水位行在且 free 达标;新堆 min_ever 记录、无 `HEAP_LOW_WATER_B` 告警;PC 客户端 2404 总召/变位往返日志;采样闭锁不误报 | — | 🔴 | `.serialtest/config.json`(无新固件代码) | 🟦 | 保护规划 §7 变更记录"遗留";`../测试说明/自动化测试流程.md` |
| **N-33** | **栈余量收口**(defaultTask 余 1080 B < 30% 线 / timeSyncTask 余 784 B < ISR 底线,2026-10-12 实测;**既有债非 B4/B5 引入**;链 = dhara GC→控制台回显尾→`(Cycle)`) | `stack_report.py` 9 任务 0 FAIL + `@build` 0/0;若抬栈:台账 §6 登记 + `@test` 复测 PASS | B6(min_ever 背书,AGENTS 抬栈门禁) | 🟢(瘦链调研)+ 🔴(复测腿) | `Src/freertos.c`(USER CODE)/ 瘦链目标文件 | ⬜ | 2026-10-12 `stack_report.py` 实测 |
| **B7** | **定值持久化 + 遥控软压板(P4)** | 主机单测:定值存/取往返、损坏→all-or-nothing 拒绝、YK12 两段式转真执行;`@build` 0/0;**台架腿**:104 C_SE 写 → 断电重启 → 定值保持;写+seal 原子化(B5 竞态窗口关闭,回填保护规划 §3.5) | —(代码);验证腿 🔴 | 🟢 + 🔴 | `App/algo/prot_set.*`、`App/cfg/`、`App/protocol/iec104/iec104_pts.c`(定值段)、`App/task/iec104_serv.c` | 🟦 代码腿完成(2026-10-12:prot_set 63 + iec104 94 断言全绿、`@build` 0/0;`/prot_set.bin` 原子持久化 + YK12 转真 + 竞态收口已落地);**台架腿待窗口 🔴**(与 B6 同窗跑:C_SE 写→断电重启→定值保持 + YK12→YX 联动) | 保护规划 §3.5 L5-1、§5;`../子系统设计/IEC104上行设计说明.md` §3.3 |
| **B6** | **台架 `@test` 闭环复测(B4/B5 验收窗口)** | `@test` PASS:`protect task start` 锚点 ×1;`[STACK] protect`/`iec104` 水位行在且 free 达标;新堆 min_ever 记录、无 `HEAP_LOW_WATER_B` 告警;PC 客户端 2404 总召/变位往返日志;采样闭锁不误报 | — | 🔴 | `.serialtest/config.json`(无新固件代码) | ✅ 完成(2026-10-12,**待销项删行**):首跑 FAIL 暴露 protectTask 启动行违反写者门控纪律(B5 台架腿缺口实锤,缺陷快照留档)→ 启动行 writer-ready 首拍补打修复(+16 B 固件代码,经用户认可随修)→ 复测 PASS 全判据;104 往返 18/18(两版固件);证据 `../测试说明/boot_log_data/`(20261012_B6_* 四份快照) | 保护规划 §7 变更记录"遗留";`../测试说明/自动化测试流程.md` |
| **N-33** | **栈余量收口**(defaultTask 余 1080 B < 30% 线 / timeSyncTask 余 784 B < ISR 底线,2026-10-12 实测;**既有债非 B4/B5 引入**;链 = dhara GC→控制台回显尾→`(Cycle)`) | `stack_report.py` 9 任务 0 FAIL + `@build` 0/0;若抬栈:台账 §6 登记 + `@test` 复测 PASS | B6 ✅(min_ever=10000 已背书 2026-10-12,AGENTS 抬栈门禁) | 🟢(瘦链调研)+ 🔴(复测腿) | `Src/freertos.c`(USER CODE)/ 瘦链目标文件 | ⬜ | 2026-10-12 `stack_report.py` 实测 |
| **B7** | **定值持久化 + 遥控软压板(P4)** | 主机单测:定值存/取往返、损坏→all-or-nothing 拒绝、YK12 两段式转真执行;`@build` 0/0;**台架腿**:104 C_SE 写 → 断电重启 → 定值保持;写+seal 原子化(B5 竞态窗口关闭,回填保护规划 §3.5) | —(代码);验证腿 🔴 | 🟢 + 🔴 | `App/algo/prot_set.*`、`App/cfg/`、`App/protocol/iec104/iec104_pts.c`(定值段)、`App/task/iec104_serv.c` | 🟦 代码腿完成(2026-10-12:prot_set 63 + iec104 94 断言全绿、`@build` 0/0;`/prot_set.bin` 原子持久化 + YK12 转真 + 竞态收口已落地);**台架腿待窗口 🔴**(C_SE 两段写路径已随 B6 窗 2026-10-12 验证:104 往返 18/18;剩余 = 断电重启→定值保持 + YK12→YX 联动) | 保护规划 §3.5 L5-1、§5;`../子系统设计/IEC104上行设计说明.md` §3.3 |
| **B8** | **频率测量算法 + 过频/低频保护(P2 剩余)** | 频率测量主机单测(45~55 Hz 扫描,精度判据写入文档)+ OF/UF 实例单测;`@build` 0/0;心跳行显示频率值。OV/UV/3U0 实例 B5 起已在跑,注入判据归 B10 | — | 🟢 | `App/algo/phasor.*`(或新 `freq.*`)、`App/algo/prot_elm.*`、`App/algo/prot_set.*`(定值行) | ⬜ | 保护规划 §3.3 L3-5、保护规划 §7 P2 |
| **B9** | **动作记录 + 时标 SOE(L4)** | SOE 记录编解码主机单测 + iec104 单测(M_SP_TB_1);`@build` 0/0;protectTask 静态链不变(动作路径无 NAND I/O,记录走队列异步);**台架腿**:动作边沿 → `/log` 记录可见。出口跳闸仍否定确认(R7 口径不变) | —(代码);验证腿 🔴 | 🟢 + 🔴 | `App/log/`、`App/protocol/iec104/iec104_asdu.*` + `iec104_pts.c`(YX 时标段)、`App/task/protect_task.c` | ⬜ | 保护规划 §3.4 L4、保护规划 §7 P4;`../子系统设计/IEC104上行设计说明.md` §3.2 注 |
| **B10** | **标准源注入 + 第三方 104 主站往返(送检窗口)** | 标准源注入:L1-5 标定复核 / L1-7 等周波 / P1 过流·过负荷 / P2 电压 + 频率类判据全通过;第三方主站总召/周期/变位/遥控全流程(`../子系统设计/IEC104上行设计说明.md` §7/§8 核对单);证据归档 | M1 + M2 | 🟡 | —(窗口内缺陷修复走 Expedite 类) | ⬜ | 保护规划 §7 P1/P2 验收;`../子系统设计/IEC104上行设计说明.md` §7/§8 |
+1 -1
View File
@@ -49,5 +49,5 @@
| N-27 | **内存优化簇**:LVGL 池 + UI 两份缓冲 54,146 B 仍在 SRAM1,CCM 只剩 ≈8,160 B(2026-10-12 B5 堆扩容 48→56 KB 后) | R-2 后半段(迁 CCM)被堵死 → 后续功能预算看不清 | **三件套 ✅ 2026-10-12 落地**(`ram_baseline.py` 四模式 + `ram_baseline.tsv` 趋势 + `docs/内存管理/RAM预算台账.md` + `mem-budget` 钩子 92% 门禁)→ **W3** 再做 R-9(`LV_MEM_SIZE` 40→16 KB,池水位门禁数据已具备)→ R-2 后半;R-3/R-4/R-5/R-6 逐项评估(R-6 前置已满足) | **W3** | 报告 R-2 剩余/R-3~R-6/R-9/§5.5 |
| N-28 | Flash 死代码评估簇:剩余 ≈10 KB(`box_shadow` 3,246 / `draw_sw_img` 2,960 / `bin_decoder` 1,972 / `image_decoder` 952 / `triangle` 930)+ 双精度 `dadd` 等 ≈1 KB;uvprojx 仍挂 201 个空 LVGL TU(F-1/F-2/F-3 已闭环,省的是编译时长) | 编译时长 + 文档噪音 | 逐项实测再关;⚠ `mask`/`mask_rect`/`grad` 是文字与矩形绘制必经路径,**不可盲关** | W4 | 报告 F-4/F-5/F-6 |
| N-29 | **仓库膨胀**:`.git` 149 MB + 图片 36.3 MB | clone/备份慢,且持续恶化 | 降采样 / 拆 submodule / LFS 三选一 **+ 一次 `git filter-repo` 历史重写**。**已决策(2026-10-11):暂不处理、登记观察**——推送/协作前重评(届时未推送提交更少、重写代价最低) | **W7** | 报告 D-1 |
| N-33 | **栈余量收口:defaultTask / timeSyncTask `stack_report` FAIL**(2026-10-12 复测:defaultTask 静态 3016 B/余 1080 B < 30% 线,链含 dhara GC→控制台回显→`(Cycle)`;timeSyncTask 静态 1264 B/余 784 B < ISR 底线 1024 B)——**既有债,非 B4/B5 引入** | 深链 + ISR 嵌套场景栈溢出风险(保护链稳定性相关) | 抬栈(需 B6 min_ever 背书)或瘦链(控制台回显尾 / Error_Handler 环),详表见 `W1-采集保护收尾.md` | **W1** | 2026-10-12 `stack_report.py` 实测 |
| N-33 | **栈余量收口:defaultTask / timeSyncTask `stack_report` FAIL**(2026-10-12 复测:defaultTask 静态 3016 B/余 1080 B < 30% 线,链含 dhara GC→控制台回显→`(Cycle)`;timeSyncTask 静态 1264 B/余 784 B < ISR 底线 1024 B)——**既有债,非 B4/B5 引入** | 深链 + ISR 嵌套场景栈溢出风险(保护链稳定性相关) | 抬栈(**B6 min_ever 已背书 2026-10-12**:台架实测 heap free=17936 / min_ever=10000 > 3072 告警线,证据 `../测试说明/boot_log_data/20261012_B6_prod_boot_log.txt`)或瘦链(控制台回显尾 / Error_Handler 环),详表见 `W1-采集保护收尾.md` | **W1** | 2026-10-12 `stack_report.py` 实测 |
| U 簇 | UI 标准化:无令牌层/组件库/页注册表(手写 `case` 仍在),**27 页**未落地;golden 未挂 pre-commit、字符集差集检查仍是约定 | 新增一页成本仍是 8 处手工改动 | 按 `../问题记录/项目审查与优化建议报告.md` §6.5:U4 残余(两脚本入门禁,可逢窗口顺带)→ U1 令牌层 → U2/U3 → 页面落地;U4 golden 可直接当 U1 验收工具。**已确认(2026-10-11):本轮不排期**,等功能主线出结果后按产品需求启动 | W6 | 报告 U1~U5 |
@@ -36,10 +36,10 @@
<!-- MEM_SNAPSHOT:BEGIN generated by scripts/check_mem_numbers.py -->
| 区域 | 用量 | 容量 | 占比 |
|---|---|---|---|
| ER_IROM1 | 223,544 B (218.30 KB) | 1,048,576 B (1024 KB) | 21.3% |
| ER_IROM1 | 223,560 B (218.32 KB) | 1,048,576 B (1024 KB) | 21.3% |
| RW_IRAM1 | 96,096 B (93.84 KB) | 131,072 B (128 KB) | 73.3% |
| RW_CCM | 57,376 B (56.03 KB) | 65,280 B (64 KB) | 87.9% |
| **Flash (ROM 合计)** | **224,580 B (219.3 KB)** | 1,048,576 B (1024 KB) | **21.4%** |
| **Flash (ROM 合计)** | **224,596 B (219.3 KB)** | 1,048,576 B (1024 KB) | **21.4%** |
<!-- MEM_SNAPSHOT:END -->
各区的容量与常量来源:
+1 -1
View File
@@ -15,7 +15,7 @@
<!-- MEM_BUDGET:BEGIN generated by scripts/ram_baseline.py -->
| 区域 | 用量 | 容量 | 占比 | 门禁(≤92%) |
|---|---|---|---|---|
| ER_IROM1 (Flash) | 223,544 B | 1,048,576 B | 21.3% | 参考 |
| ER_IROM1 (Flash) | 223,560 B | 1,048,576 B | 21.3% | 参考 |
| RW_CCM | 57,376 B | 65,280 B | 87.9% | PASS |
| UNINIT_CCM | 48 B | 256 B | 18.8% | 参考 |
| RW_IRAM1 | 96,096 B | 131,072 B | 73.3% | PASS |
@@ -152,7 +152,7 @@
|---|---|
| L0.5 | `test/host/iec104/`:APCI 重组/坏帧、STARTDT 握手、总召全流程(含 RBT/分片/预算)、COV、k/w 窗、t1/t2/t3(假时基)、遥控两段式与 PN、YK12 软压板两段转真 + 置脏(B7)、定值两段写 + set_sealed 后 selfcheck、C_RD(含本地项不可寻址)、C_CS(含闰年)、错地址/错类型 EVI;`test/host/prot_set/`:blob 往返 + 损坏整表拒绝(all-or-nothing)|
| L0 | `iec104-unit-test` 钩子 + cppcheck/coding-standard |
| 台架 | `@test` 锚点(104 服务启动/监听行);主站工具(lib60870 或等效)总召+遥测+遥控往返,随 B4 收尾 |
| 台架 | `@test` 锚点(104 服务启动/监听行);**PC 主站客户端 `test/host/iec104_master.py`(纯标准库,B6 2026-10-12 就绪)**:STARTDT/总召四组+actterm/C_SE 定值两段写→YX15·16 变位(COT=3)/恢复复归/YK11 两段正答/C_RD 读回,台架往返 **18/18 PASS**(证据 `../测试说明/boot_log_data/20261012_B6_iec104_roundtrip_log.txt`);lib60870 级第三方全流程归 B10 |
## 8. V0.1 限制与待办(如实登记)
@@ -161,7 +161,7 @@
3. YK1~4/13/14 否定确认——出口硬件确认后(R7)转真执行(YK12 已于 B7 转真)。
4. 遥测死区 10.0 码值为拟定值,L1-5 标定后按工程量死区(点表 8020H 段)复核。
5. 多主站/双链路冗余不做(单连接语义)。
6. 主站侧验证工具与送检环境未就绪——台架只做到"第三方 104 主站可总召"级。
6. 主站侧验证工具 = `test/host/iec104_master.py`(B6 2026-10-12 就绪,台架往返 18/18,覆盖总召/变位/遥控/定值);**第三方送检环境仍未就绪**——lib60870 级第三方全流程归 B10。
7. **后连优先未实现**(V0.1 = 首到优先):单连接 socket 连接态无法 accept,
旧会话结束前新主站接入被拒;后连优先需 net 层(CH395F 单连接模型)支持,
真需要冗余切换时随 net 扩展立项。
@@ -114,7 +114,7 @@ flowchart LR
| 写者未注册(内核启动 → attach) | **约定只有 `defaultTask` 记日志** | 遵守约定 → 无并发;**其他任务此时记日志 → 逐字节交错**(裸发无互斥) |
| 写者已注册(稳态) | 任务上下文唯一调用者 = 写者 | 任务上下文零竞争;残余窗口 = ISR 直发撞写者发送中(丢失、不挂死,§7) |
**纪律(2026-10-10 固化)**:周期 / 常驻任务**不得**在写者注册前记日志——用 `dbg_console_writer_ready()`(§5)门控自身日志(`adcTask` 的首帧与 10 s 心跳即按此门控)。内核前代码仍可直接裸发(单线程,无并发)。
**纪律(2026-10-10 固化)**:周期 / 常驻任务**不得**在写者注册前记日志——用 `dbg_console_writer_ready()`(§5)门控自身日志(`adcTask` 的首帧与 10 s 心跳、`protectTask` 的启动锚点行即按此门控——后者 2026-10-12 B6 台架实证:B5 接线时启动行未门控,注册前裸发被交错损坏致 `@test` 锚点 MISS,见 §11 变更记录)。内核前代码仍可直接裸发(单线程,无并发)。
## 4. 详细设计
@@ -307,6 +307,7 @@ sequenceDiagram
| 2026-10-02 | **ORE 僵尸通道喂狗节奏保护**(台架 gen-288):round-3 的"单次 drain 预算 250ms"只限单次调用——ORE 锁存在外设软复位后**毫秒级重锁**(PA10 悬空 + RX 使能),背靠背 drain 每轮再耗 100ms 块超时 → 主循环周期拉到 450~500ms → 100ms 节流的喂狗抽样间隙超过 IWDG 最坏容限 1.7s → 停喂 → 误复位(且心跳位全员健康、无 stall 日志,纯**节奏性饥饿**,非死等)。修复:发送故障后立即结束本轮 drain 并进入 300ms 发送冷却(冷却期内 drain 直接让位主循环),保证喂狗节奏 ≤ ~300ms |
| 2026-10-02 | **round 8b 加固**:发送超时判据改用 DWT `CYCCNT`(时间源无关)。原 `HAL_UART_Transmit` 的 `HAL_GetTick() - Tickstart` 依赖 TIM7 的 `uwTick`,TIM7 一旦停摆超时永不成立 → 写者死等 TXE → 唯一喂狗者停摆 → IWDG 复位。裸发送与缓冲满等待两处均换成 DWT 周期计数硬上界(DWT 使能失败时退回旧 HAL 行为);另加 `huart1.Instance == NULL` 短路,防早期/断言路径解引用 NULL |
| 2026-10-10 | **新增 `dbg_console_writer_ready()` + 未注册期纪律固化**:裸发为寄存器级轮询(无 `gState`)→ 未注册期多任务并发**逐字节交错**(台架 `adcTask` 首帧日志与 `[NAND_FTL]` 行交错实证)。新增 `dbg_console_writer_ready()` 供周期任务门控;`adcTask` 首帧/心跳日志据此门控(§3.4 / §4.4) |
| 2026-10-12 | **纪律盲区台架实证(B6)**:`protectTask`(B5 接线,台架腿当时未跑)启动锚点行在写者注册前裸发 → 与 defaultTask 启动日志**逐字节交错**(`st[art: cycle=220ms elm=70`,两次开机同形复现 = 启动调度确定性的竞态,非 USB 噪声)→ `@test` 锚点 MISS。修复 = 启动行改 `dbg_console_writer_ready()` 首拍补打(adcTask 首帧同款),`@build` 0/0 + `@test` PASS 复验(锚点完好 +577 ms)。§3.4 纪律示例更新 |
## 12. ORE 僵尸通道(2026-10-02 台架实证)
@@ -0,0 +1,134 @@
[+0ms] [----/--/-- --:--:--][APP] boot: syslog init OK
[+0ms] [----/--/-- --:--:--][APP] fw build: Oct 12 2026 14:02:47 suite=NONE dstr=off
[+0ms] [----/--/-- --:--:--][APP] reset cause: software (NVIC_SystemReset) (CSR=0x14000000)
[+0ms] PREVRUN seg=2 seq=1933208002 t=1832883
[+14ms] TICKRUN uw=1832923 n=1832923 duw=40
[+14ms] [----/--/-- --:--:--][RTC] sd2506_init: OK
[+14ms] [----/--/-- --:--:--][APP] SD2506 init: OK (ret=0)
[+25ms] [2026-10-12 07:21:28][CLK] sys_clock_init: RTC initial time 2026-10-12 07:21:28
[+35ms] [2026-10-12 07:21:28][CLK] sys_clock_init: wall clock base = unix 1791789688, base_tick=139
[+35ms] [2026-10-12 07:21:28][APP] RS485 init: OK (UART4, DE=PA15)
[+57ms] [2026-10-12 07:21:28][NAND] Resetting NAND...
[+77ms] [2026-10-12 07:21:28][NAND] Reading NAND ID...
[+77ms] [2026-10-12 07:21:28][NAND] NAND ID: MID=0xC8, DID=0x52
[+77ms] [2026-10-12 07:21:28][NAND] Scanning bad blocks...
[+212ms] [2026-10-12 07:21:28][NAND] BBT scan: 0 bad blocks found
[+223ms] [2026-10-12 07:21:28][NAND] Enabling ECC...
[+223ms] [2026-10-12 07:21:28][NAND] Unlocking block protection...
[+233ms] [2026-10-12 07:21:28][NAND] Locating BBT pool...
[+233ms] [2026-10-12 07:21:28][NAND] Loading persisted BBT...
[+244ms] [2026-10-12 07:21:28][NAND] NAND init OK
[+244ms] [2026-10-12 07:21:28][APP] NAND init: OK
[+244ms] [2026-10-12 07:21:28][ADC] Init OK
[+254ms] [2026-10-12 07:21:28][APP] ADC init: OK
[+254ms] [2026-10-12 07:21:28][APP] ADC input layer init: OK
[+264ms] [2026-10-12 07:21:28][APP] phasor layer init: OK (inst=5)
[+264ms] [2026-10-12 07:21:28][APP] protection init: OK (set=32 elm=7)
[+275ms] [2026-10-12 07:21:28][APP] SD2506 ID: 2512153425482405
[+285ms] [2026-10-12 07:21:28][APP] SD2506 time: 2026-10-12 07:21:28 (week 4)
[+285ms] [2026-10-12 07:21:28][APP] SD2506 temp: 31 C
[+285ms] [2026-10-12 07:21:28][APP] SD2506 battery: 3.07 V
[+296ms] [2026-10-12 07:21:28][APP] App init OK
[+307ms] [2026-10-12 07:21:28][NAND_FTL] Initializing NAND FTL...
[+327ms] [2026-10-12 07:21:28][NAND_FTL] Map resumed: 14094/97504 sectors used
[+338ms] [2026-10-12 07:21:28][NAND_FTL] Map head=17696 tail=130306 epoch=2
[+338ms] [2026-10-12 07:21:28][NAND_FTL] NAND FTL ready (capacity: 97504 pages = 190 MB)
[+410ms] [2026-10-12 07:21:28] [FS] FATFS mounted
[+473ms] [2026-10-12 07:21:28][SYSLOG] runlog boot entry: power on
[+483ms] [2026-10-12 07:21:28][CFG] register: section 'network' (4 keys)
[+483ms] [2026-10-12 07:21:28][CFG] register: section 'ftp' (3 keys)
[+493ms] [2026-10-12 07:21:28][CFG] load: OK (523B, heap free 18088B)
[+493ms] [2026-10-12 07:21:28][NET_CFG] load: OK ip=192.168.1.100
[+525ms] [2026-10-12 07:21:28][ADC_TASK] first: UA=11428 UB=983 UC=827 UN=11453 IA=11451 IB=902 IC=975 IN=880 T=880
[+535ms] [2026-10-12 07:21:28][ADC_TASK] phasor(first) C01-IA-F1: Re=-1 Im=-1 rms=1 (x0.1)
[+535ms] [2026-10-12 07:21:28][ADC_TASK] phasor(first) C02-UA-F1: Re=-1 Im=0 rms=1 (x0.1)
[+545ms] [2026-10-12 07:21:28][ADC_TASK] phasor(first) C03-UN-F1: Re=0 Im=-1 rms=1 (x0.1)
[+556ms] [2026-10-12 07:21:28][ADC_TASK] phasor(first) C04-IA-F2: Re=1 Im=-1 rms=1 (x0.1)
[+556ms] [2026-10-12 07:21:28][ADC_TASK] phasor(first) C05-IA-F5: Re=2 Im=2 rms=3 (x0.1)
[+567ms] [2026-10-12 07:21:28][NET_TASK] === Network Init ===
[+577ms] [2026-10-12 07:21:28][PROT] protect task start: cycle=20ms elm=7
[+577ms] [2026-10-12 07:21:28][NET] ch395f ver=0x4A fun_para=0x08
[+588ms] [2026-10-12 07:21:28][NET_TASK] net init: OK
[+588ms] [2026-10-12 07:21:28][NET_TASK] MAC: 3C:AB:72:53:2B:12
[+588ms] [2026-10-12 07:21:28][NET_TASK] IP_INF: IP=192.168.1.100 GW=192.168.1.1 MASK=255.255.255.0
[+598ms] MISS start snap=0x000001E7 req=0x000001F7 t=717
[+609ms] [2026-10-12 07:21:28][WD] [WD] armed: timeout ~2498ms (worst ~1701ms), miss_tol=800ms
[+619ms] [2026-10-12 07:21:28][UI_TASK] UI task: started, wait net ready
[+2551ms] [2026-10-12 07:21:30][NET_TASK] PHY: 100M FULL
[+2561ms] [2026-10-12 07:21:30][NET_TASK] netTask: started (single-socket mode)
[+2602ms] [2026-10-12 07:21:30] [FTP] using factory default password
[+2633ms] [2026-10-12 07:21:30][TIME_SYNC] time_sync: TCP listen on :8888 (sock=0)
[+2665ms] [2026-10-12 07:21:30][I104] i104: listening on 2404
[+2665ms] [2026-10-12 07:21:30] [FTP] waiting for connection...
[+2675ms] [2026-10-12 07:21:30][UI_TASK] UI task: net ready, init port
[+2675ms] [2026-10-12 07:21:30][UI_TASK] UI task: ui_port_init enter
[+2686ms] [2026-10-12 07:21:30][UI_PORT] theme: mono dark_bg=true applied
[+2697ms] [2026-10-12 07:21:30][UI_TASK] UI port init: OK
[+2697ms] [2026-10-12 07:21:30][UI_TASK] UI task: ui_menu_init enter
[+2697ms] [2026-10-12 07:21:30][UI_MENU] menu build start: total=39448 free=37004 big=37004
[+2707ms] [2026-10-12 07:21:30][UI_MENU_VIEW] view init: root frame w=66 h=107
[+2717ms] [2026-10-12 07:21:30][UI_MENU] menu build done: total=39332 free=36140 big=36128 used=3192
[+2728ms] [2026-10-12 07:21:30][UI_TASK] UI menu init: OK
[+2728ms] [2026-10-12 07:21:30][UI_STANDBY] standby: ready (idle=60000ms)
[+2738ms] [2026-10-12 07:21:30][UI_TASK] UI standby: ready (idle=60s)
[+2791ms] [2026-10-12 07:21:30][UI_TASK] UI net sink: started (port 7003)
[+2791ms] MISS start snap=0x000001E7 req=0x000001F7 t=2906
[+2791ms] [PROF] t=2911 uic=0 uip=0 uipn=0 uil=0 uiw=0 uis=0 uisn=0 adc=2496 adcm=2006 adcn=0 gl=0
[+2801ms] [PROF2] t=2911 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+4911ms] [PROF] t=5025 uic=208 uip=19870 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=4610 adcm=2006 adcn=0 gl=0
[+4921ms] [PROF2] t=5025 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+5324ms] [2026-10-12 07:21:33] [STACK] default peak_used=2152/4096 free_min=1944 (47%)
[+5335ms] [2026-10-12 07:21:33] [STACK] net peak_used=1092/3840 free_min=2748 (71%)
[+5346ms] [2026-10-12 07:21:33] [STACK] ftp peak_used=740/4096 free_min=3356 (81%)
[+5346ms] [2026-10-12 07:21:33] [STACK] ui peak_used=4016/16384 free_min=12368 (75%)
[+5356ms] [2026-10-12 07:21:33] [STACK] timesync peak_used=616/2048 free_min=1432 (69%)
[+5356ms] [2026-10-12 07:21:33] [STACK] adc peak_used=952/2560 free_min=1608 (62%)
[+5366ms] [2026-10-12 07:21:33] [STACK] iec104 peak_used=424/2560 free_min=2136 (83%)
[+5377ms] [2026-10-12 07:21:33] [STACK] protect peak_used=596/2048 free_min=1452 (70%)
[+5387ms] [2026-10-12 07:21:33] [STACK] heap free=17936 min_ever=10000
[+6935ms] [PROF] t=7053 uic=403 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=6638 adcm=2006 adcn=0 gl=0
[+6946ms] [PROF2] t=7053 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+8951ms] [PROF] t=9069 uic=603 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=8654 adcm=2006 adcn=0 gl=0
[+8961ms] [PROF2] t=9069 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+10306ms] [2026-10-12 07:21:38][ADC_TASK] frames=10001 idle=0 skip=32 seq=10006 frst_err=0 ring=9969 adc1_rc=0 adc1_err=0 adc1_seq=10004 adc1_gap=32 adc1_hw=0 tgap=1
[+10317ms] [2026-10-12 07:21:38][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=1 (x0.1)
[+10327ms] [2026-10-12 07:21:38][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=1 rms=1 (x0.1)
[+10327ms] [2026-10-12 07:21:38][ADC_TASK] phasor(hb) C03-UN-F1: Re=2 Im=2 rms=3 (x0.1)
[+10337ms] [2026-10-12 07:21:38][ADC_TASK] phasor(hb) C04-IA-F2: Re=-2 Im=-2 rms=3 (x0.1)
[+10337ms] [2026-10-12 07:21:38][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=-1 rms=1 (x0.1)
[+10348ms] [2026-10-12 07:21:38][PROT] elm UV-UA asserted=1 picked=1
[+10957ms] [PROF] t=11070 uic=797 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=10655 adcm=2006 adcn=0 gl=0
[+10968ms] [PROF2] t=11070 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+11371ms] [2026-10-12 07:21:39] [STACK] default peak_used=2152/4096 free_min=1944 (47%)
[+11382ms] [2026-10-12 07:21:39] [STACK] net peak_used=1092/3840 free_min=2748 (71%)
[+11382ms] [2026-10-12 07:21:39] [STACK] ftp peak_used=740/4096 free_min=3356 (81%)
[+11392ms] [2026-10-12 07:21:39] [STACK] ui peak_used=4016/16384 free_min=12368 (75%)
[+11403ms] [2026-10-12 07:21:39] [STACK] timesync peak_used=616/2048 free_min=1432 (69%)
[+11403ms] [2026-10-12 07:21:39] [STACK] adc peak_used=952/2560 free_min=1608 (62%)
[+11413ms] [2026-10-12 07:21:39] [STACK] iec104 peak_used=424/2560 free_min=2136 (83%)
[+11424ms] [2026-10-12 07:21:39] [STACK] protect peak_used=828/2048 free_min=1220 (59%)
[+11434ms] [2026-10-12 07:21:39] [STACK] heap free=17936 min_ever=10000
[+12987ms] [PROF] t=13099 uic=992 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=12684 adcm=2006 adcn=0 gl=0
[+12997ms] [PROF2] t=13099 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+15001ms] [PROF] t=15116 uic=1192 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=14701 adcm=2006 adcn=0 gl=0
[+15012ms] [PROF2] t=15116 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+17022ms] [PROF] t=17133 uic=1392 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=16718 adcm=2006 adcn=0 gl=0
[+17032ms] [PROF2] t=17133 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+19034ms] [PROF] t=19150 uic=1592 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=18735 adcm=2006 adcn=0 gl=0
[+19044ms] [PROF2] t=19150 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+20307ms] [2026-10-12 07:21:48][ADC_TASK] frames=20001 idle=0 skip=35 seq=20006 frst_err=0 ring=19966 adc1_rc=0 adc1_err=0 adc1_seq=20004 adc1_gap=35 adc1_hw=0 tgap=1
[+20318ms] [2026-10-12 07:21:48][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=-1 rms=2 (x0.1)
[+20318ms] [2026-10-12 07:21:48][ADC_TASK] phasor(hb) C02-UA-F1: Re=1 Im=-2 rms=2 (x0.1)
[+20328ms] [2026-10-12 07:21:48][ADC_TASK] phasor(hb) C03-UN-F1: Re=2 Im=-1 rms=2 (x0.1)
[+20339ms] [2026-10-12 07:21:48][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=1 rms=1 (x0.1)
[+20339ms] [2026-10-12 07:21:48][ADC_TASK] phasor(hb) C05-IA-F5: Re=2 Im=0 rms=2 (x0.1)
[+21054ms] [PROF] t=21164 uic=1787 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=1 uisn=0 adc=20749 adcm=2006 adcn=0 gl=0
[+21064ms] [PROF2] t=21164 defd=135261 defs=7 netp=16 netn=0 adcp=9 adcq=0 gl=0
[+23067ms] [PROF] t=23181 uic=1987 uip=73696 uipn=9997 uil=9950 uiw=10351 uis=64 uisn=0 adc=22766 adcm=2006 adcn=0 gl=0
[+23077ms] [PROF2] t=23181 defd=135261 defs=7 netp=63 netn=0 adcp=9 adcq=0 gl=0
[+25080ms] [PROF] t=25198 uic=2187 uip=73696 uipn=9996 uil=9958 uiw=10351 uis=64 uisn=0 adc=24783 adcm=2006 adcn=0 gl=0
[+25091ms] [PROF2] t=25198 defd=135261 defs=7 netp=63 netn=0 adcp=9 adcq=0 gl=0
[+27100ms] [PROF] t=27215 uic=2387 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=64 uisn=0 adc=26800 adcm=2006 adcn=0 gl=0
[+27110ms] [PROF2] t=27215 defd=135261 defs=7 netp=63 netn=0 adcp=9 adcq=0 gl=0
[+29114ms] [PROF] t=29232 uic=2587 uip=73696 uipn=9996 uil=9999 uiw=10351 uis=64 uisn=0 adc=28817 adcm=2006 adcn=0 gl=0
[+29125ms] [PROF2] t=29232 defd=135261 defs=7 netp=63 netn=0 adcp=9 adcq=0 gl=0
@@ -0,0 +1,134 @@
[+0ms] [----/--/-- --:--:--][APP] boot: syslog init OK
[+0ms] [----/--/-- --:--:--][APP] fw build: Oct 12 2026 14:49:47 suite=NONE dstr=off
[+11ms] [----/--/-- --:--:--][APP] reset cause: software (NVIC_SystemReset) (CSR=0x14000000)
[+11ms] PREVRUN seg=2 seq=1932941145 t=2452628
[+26ms] TICKRUN uw=2452643 n=2452643 duw=15
[+26ms] [----/--/-- --:--:--][RTC] sd2506_init: OK
[+26ms] [----/--/-- --:--:--][APP] SD2506 init: OK (ret=0)
[+37ms] [2026-10-12 06:50:17][CLK] sys_clock_init: RTC initial time 2026-10-12 06:50:17
[+47ms] [2026-10-12 06:50:17][CLK] sys_clock_init: wall clock base = unix 1791787817, base_tick=139
[+47ms] [2026-10-12 06:50:17][APP] RS485 init: OK (UART4, DE=PA15)
[+68ms] [2026-10-12 06:50:17][NAND] Resetting NAND...
[+79ms] [2026-10-12 06:50:17][NAND] Reading NAND ID...
[+89ms] [2026-10-12 06:50:17][NAND] NAND ID: MID=0xC8, DID=0x52
[+89ms] [2026-10-12 06:50:17][NAND] Scanning bad blocks...
[+224ms] [2026-10-12 06:50:17][NAND] BBT scan: 0 bad blocks found
[+224ms] [2026-10-12 06:50:17][NAND] Enabling ECC...
[+235ms] [2026-10-12 06:50:17][NAND] Unlocking block protection...
[+245ms] [2026-10-12 06:50:17][NAND] Locating BBT pool...
[+245ms] [2026-10-12 06:50:17][NAND] Loading persisted BBT...
[+256ms] [2026-10-12 06:50:17][NAND] NAND init OK
[+256ms] [2026-10-12 06:50:17][APP] NAND init: OK
[+256ms] [2026-10-12 06:50:17][ADC] Init OK
[+256ms] [2026-10-12 06:50:17][APP] ADC init: OK
[+266ms] [2026-10-12 06:50:17][APP] ADC input layer init: OK
[+266ms] [2026-10-12 06:50:17][APP] phasor layer init: OK (inst=5)
[+277ms] [2026-10-12 06:50:17][APP] protection init: OK (set=31 elm=7)
[+287ms] [2026-10-12 06:50:17][APP] SD2506 ID: 2512153425482405
[+287ms] [2026-10-12 06:50:17][APP] SD2506 time: 2026-10-12 06:50:17 (week 4)
[+298ms] [2026-10-12 06:50:17][APP] SD2506 temp: 29 C
[+298ms] [2026-10-12 06:50:17][APP] SD2506 battery: 3.09 V
[+308ms] [2026-10-12 06:50:17][APP] App init OK
[+308ms] [2026-10-12 06:50:17][PROT] protect task st[art: cycle=220ms elm=70
[+319ms] 26-10-12 06:50:17][NAND_FTL] Initializing NAND FTL...
[+340ms] [2026-10-12 06:50:17][NAND_FTL] Map resumed: 14094/97504 sectors used
[+350ms] [2026-10-12 06:50:17][NAND_FTL] Map head=17600 tail=130216 epoch=2
[+350ms] [2026-10-12 06:50:17][NAND_FTL] NAND FTL ready (capacity: 97504 pages = 190 MB)
[+433ms] [2026-10-12 06:50:17] [FS] FATFS mounted
[+485ms] [2026-10-12 06:50:17][SYSLOG] runlog boot entry: power on
[+485ms] [2026-10-12 06:50:17][CFG] register: section 'network' (4 keys)
[+495ms] [2026-10-12 06:50:17][CFG] register: section 'ftp' (3 keys)
[+506ms] [2026-10-12 06:50:17][CFG] load: OK (523B, heap free 18088B)
[+506ms] [2026-10-12 06:50:17][NET_CFG] load: OK ip=192.168.1.100
[+537ms] [2026-10-12 06:50:17][ADC_TASK] first: UA=11428 UB=972 UC=825 UN=11454 IA=11451 IB=927 IC=971 IN=878 T=889
[+537ms] [2026-10-12 06:50:17][ADC_TASK] phasor(first) C01-IA-F1: Re=-1 Im=-2 rms=2 (x0.1)
[+548ms] [2026-10-12 06:50:17][ADC_TASK] phasor(first) C02-UA-F1: Re=2 Im=-1 rms=2 (x0.1)
[+559ms] [2026-10-12 06:50:17][ADC_TASK] phasor(first) C03-UN-F1: Re=-1 Im=1 rms=1 (x0.1)
[+569ms] [2026-10-12 06:50:17][ADC_TASK] phasor(first) C04-IA-F2: Re=3 Im=0 rms=3 (x0.1)
[+569ms] [2026-10-12 06:50:17][ADC_TASK] phasor(first) C05-IA-F5: Re=1 Im=-2 rms=2 (x0.1)
[+579ms] [2026-10-12 06:50:17][NET_TASK] === Network Init ===
[+579ms] [2026-10-12 06:50:17][NET] ch395f ver=0x4A fun_para=0x08
[+590ms] [2026-10-12 06:50:17][NET_TASK] net init: OK
[+590ms] [2026-10-12 06:50:17][NET_TASK] MAC: 3C:AB:72:53:2B:12
[+600ms] [2026-10-12 06:50:17][NET_TASK] IP_INF: IP=192.168.1.100 GW=192.168.1.1 MASK=255.255.255.0
[+600ms] MISS start snap=0x000001E7 req=0x000001F7 t=710
[+611ms] [2026-10-12 06:50:17][WD] [WD] armed: timeout ~2498ms (worst ~1701ms), miss_tol=800ms
[+621ms] [2026-10-12 06:50:17][UI_TASK] UI task: started, wait net ready
[+2605ms] [2026-10-12 06:50:19][NET_TASK] PHY: 100M FULL
[+2625ms] [2026-10-12 06:50:19][NET_TASK] netTask: started (single-socket mode)
[+2657ms] [2026-10-12 06:50:19] [FTP] using factory default password
[+2689ms] [2026-10-12 06:50:19][TIME_SYNC] time_sync: TCP listen on :8888 (sock=0)
[+2720ms] [2026-10-12 06:50:19][I104] i104: listening on 2404
[+2731ms] [2026-10-12 06:50:19] [FTP] waiting for connection...
[+2731ms] [2026-10-12 06:50:19][UI_TASK] UI task: net ready, init port
[+2741ms] [2026-10-12 06:50:19][UI_TASK] UI task: ui_port_init enter
[+2741ms] [2026-10-12 06:50:19][UI_PORT] theme: mono dark_bg=true applied
[+2752ms] [2026-10-12 06:50:19][UI_TASK] UI port init: OK
[+2752ms] [2026-10-12 06:50:19][UI_TASK] UI task: ui_menu_init enter
[+2762ms] [2026-10-12 06:50:19][UI_MENU] menu build start: total=39448 free=37004 big=37004
[+2772ms] [2026-10-12 06:50:19][UI_MENU_VIEW] view init: root frame w=66 h=107
[+2783ms] [2026-10-12 06:50:19][UI_MENU] menu build done: total=39332 free=36140 big=36128 used=3192
[+2783ms] [2026-10-12 06:50:19][UI_TASK] UI menu init: OK
[+2793ms] [2026-10-12 06:50:19][UI_STANDBY] standby: ready (idle=60000ms)
[+2793ms] [2026-10-12 06:50:19][UI_TASK] UI standby: ready (idle=60s)
[+2845ms] [2026-10-12 06:50:19][UI_TASK] UI net sink: started (port 7003)
[+2855ms] MISS start snap=0x000001E7 req=0x000001F7 t=2954
[+2855ms] [PROF] t=2959 uic=0 uip=0 uipn=0 uil=0 uiw=0 uis=0 uisn=0 adc=2545 adcm=2017 adcn=0 gl=0
[+2866ms] [PROF2] t=2959 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+4920ms] [PROF] t=5022 uic=203 uip=20322 uipn=8996 uil=9999 uiw=10487 uis=1 uisn=0 adc=4608 adcm=2017 adcn=0 gl=0
[+4930ms] [PROF2] t=5022 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+5334ms] [2026-10-12 06:50:22] [STACK] default peak_used=2164/4096 free_min=1932 (47%)
[+5345ms] [2026-10-12 06:50:22] [STACK] net peak_used=1092/3840 free_min=2748 (71%)
[+5345ms] [2026-10-12 06:50:22] [STACK] ftp peak_used=740/4096 free_min=3356 (81%)
[+5355ms] [2026-10-12 06:50:22] [STACK] ui peak_used=4052/16384 free_min=12332 (75%)
[+5365ms] [2026-10-12 06:50:22] [STACK] timesync peak_used=616/2048 free_min=1432 (69%)
[+5365ms] [2026-10-12 06:50:22] [STACK] adc peak_used=952/2560 free_min=1608 (62%)
[+5376ms] [2026-10-12 06:50:22] [STACK] iec104 peak_used=424/2560 free_min=2136 (83%)
[+5387ms] [2026-10-12 06:50:22] [STACK] protect peak_used=456/2048 free_min=1592 (77%)
[+5387ms] [2026-10-12 06:50:22] [STACK] heap free=17936 min_ever=10000
[+6946ms] [PROF] t=7050 uic=398 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=6636 adcm=2017 adcn=0 gl=0
[+6956ms] [PROF2] t=7050 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+8965ms] [PROF] t=9066 uic=598 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=8652 adcm=2017 adcn=0 gl=0
[+8976ms] [PROF2] t=9066 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+10311ms] [2026-10-12 06:50:27][ADC_TASK] frames=10001 idle=0 skip=32 seq=10006 frst_err=0 ring=9969 adc1_rc=0 adc1_err=0 adc1_seq=10004 adc1_gap=32 adc1_hw=0 tgap=1
[+10322ms] [2026-10-12 06:50:27][ADC_TASK] phasor(hb) C01-IA-F1: Re=2 Im=2 rms=3 (x0.1)
[+10332ms] [2026-10-12 06:50:27][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=1 rms=1 (x0.1)
[+10343ms] [2026-10-12 06:50:27][ADC_TASK] phasor(hb) C03-UN-F1: Re=-1 Im=0 rms=2 (x0.1)
[+10343ms] [2026-10-12 06:50:27][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=2 rms=2 (x0.1)
[+10353ms] [2026-10-12 06:50:27][ADC_TASK] phasor(hb) C05-IA-F5: Re=1 Im=3 rms=3 (x0.1)
[+10364ms] [2026-10-12 06:50:27][PROT] elm UV-UA asserted=1 picked=1
[+10962ms] [PROF] t=11068 uic=792 uip=73724 uipn=9995 uil=9958 uiw=10487 uis=1 uisn=0 adc=10654 adcm=2017 adcn=0 gl=0
[+10972ms] [PROF2] t=11068 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+11384ms] [2026-10-12 06:50:28] [STACK] default peak_used=2164/4096 free_min=1932 (47%)
[+11384ms] [2026-10-12 06:50:28] [STACK] net peak_used=1092/3840 free_min=2748 (71%)
[+11394ms] [2026-10-12 06:50:28] [STACK] ftp peak_used=740/4096 free_min=3356 (81%)
[+11405ms] [2026-10-12 06:50:28] [STACK] ui peak_used=4052/16384 free_min=12332 (75%)
[+11405ms] [2026-10-12 06:50:28] [STACK] timesync peak_used=616/2048 free_min=1432 (69%)
[+11415ms] [2026-10-12 06:50:28] [STACK] adc peak_used=952/2560 free_min=1608 (62%)
[+11425ms] [2026-10-12 06:50:28] [STACK] iec104 peak_used=424/2560 free_min=2136 (83%)
[+11425ms] [2026-10-12 06:50:28] [STACK] protect peak_used=828/2048 free_min=1220 (59%)
[+11436ms] [2026-10-12 06:50:28] [STACK] heap free=17936 min_ever=10000
[+12998ms] [PROF] t=13097 uic=987 uip=73724 uipn=9995 uil=9995 uiw=10487 uis=1 uisn=0 adc=12683 adcm=2017 adcn=0 gl=0
[+12998ms] [PROF2] t=13097 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+15007ms] [PROF] t=15114 uic=1187 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=14700 adcm=2017 adcn=0 gl=0
[+15017ms] [PROF2] t=15114 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+17033ms] [PROF] t=17131 uic=1387 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=16717 adcm=2017 adcn=0 gl=0
[+17033ms] [PROF2] t=17131 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+19048ms] [PROF] t=19148 uic=1587 uip=73724 uipn=10003 uil=9999 uiw=10487 uis=1 uisn=0 adc=18734 adcm=2017 adcn=0 gl=0
[+19058ms] [PROF2] t=19148 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+20309ms] [2026-10-12 06:50:37][ADC_TASK] frames=20001 idle=0 skip=42 seq=20006 frst_err=0 ring=19959 adc1_rc=0 adc1_err=0 adc1_seq=20004 adc1_gap=42 adc1_hw=0 tgap=1
[+20320ms] [2026-10-12 06:50:37][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=1 rms=1 (x0.1)
[+20330ms] [2026-10-12 06:50:37][ADC_TASK] phasor(hb) C02-UA-F1: Re=3 Im=0 rms=3 (x0.1)
[+20340ms] [2026-10-12 06:50:37][ADC_TASK] phasor(hb) C03-UN-F1: Re=-1 Im=0 rms=1 (x0.1)
[+20351ms] [2026-10-12 06:50:37][ADC_TASK] phasor(hb) C04-IA-F2: Re=-2 Im=-1 rms=2 (x0.1)
[+20351ms] [2026-10-12 06:50:37][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1)
[+21065ms] [PROF] t=21163 uic=1782 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=20749 adcm=2017 adcn=0 gl=0
[+21065ms] [PROF2] t=21163 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+23076ms] [PROF] t=23180 uic=1982 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=22766 adcm=2017 adcn=0 gl=0
[+23086ms] [PROF2] t=23180 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+25093ms] [PROF] t=25197 uic=2182 uip=73724 uipn=9995 uil=9995 uiw=10487 uis=1 uisn=0 adc=24783 adcm=2017 adcn=0 gl=0
[+25104ms] [PROF2] t=25197 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+27113ms] [PROF] t=27214 uic=2382 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=26800 adcm=2017 adcn=0 gl=0
[+27123ms] [PROF2] t=27214 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
[+29129ms] [PROF] t=29231 uic=2582 uip=73724 uipn=9995 uil=9999 uiw=10487 uis=1 uisn=0 adc=28817 adcm=2017 adcn=0 gl=0
[+29140ms] [PROF2] t=29231 defd=135841 defs=7 netp=0 netn=0 adcp=9 adcq=0 gl=0
@@ -29,6 +29,10 @@
| 2026-10-10 | `prod_adc_l1` / 开机 + 30 s 空载 | `adc` **584/2048(71%)**(+56 B,L1 层 adc_input_poll/raw 上链);`default` 2164/4096(47%);heap free=15088 min_ever=7152 | `20261010_prod_adc_l1_boot_log.txt` |
| 2026-10-11 | `prod_phasor` / 开机 + 30 s 空载(L2 台架闭环) | `adc` **928/2048(54%)**(+344 B,压环 + `phasor_run` + `log_phasors` 上链);`default` 2152/4096(47%);heap free=15088 min_ever=7152 | `20261011_prod_phasor_boot_log.txt` |
| 2026-10-11 | `prod_adc_health` / 开机 + 30 s 空载(L1-6 + 抬栈 640 words) | `adc` **952/2560(62%)**(静态最坏链 1080 B,`adc_health_report`→`syslog_post` 回显尾);`default` 2152/4096(47%);heap free=14576 **min_ever=6640**(抬栈 -512 B,符合预算) | `20261011_prod_adc_health_boot_log.txt` |
| 2026-10-12 | `prod`(HEAD d3107f3,B4/B5 验收窗口 B6)/ 开机 + 30 s 空载 | **首采**:`iec104` 424/2560(83%);`protect` 828/2048(59%,free_min 1220);新 56 KB 堆 heap free=17936 **min_ever=10000**(>3072 告警线,无 `[HEAP]` 告警);⚠ **@test FAIL(缺陷证据快照)**:`protect task start` 锚点行字节级交错损坏(`st[art: cycle=220ms elm=70`,两次开机同形复现)= protectTask 违反控制台写者注册前门控纪律(`控制台单写者日志设计说明.md` §3.4),其余 8 Required / 零 `[ERR]` / 锚点×1 / 回读一致全过;**缺陷已修**(启动行改 writer-ready 首拍补打),修复后 PASS 见下行 | `20261012_B6_prod_boot_log_PROTECT_MISS.txt` |
| 2026-10-12 | `prod`(B7 `1fe163b` + B6 门控修复)/ 开机 + 30 s 空载(**B6 复测 PASS**) | `protect` 828/2048(59%,free_min 1220);`iec104` 424/2560(83%);heap free=17936 **min_ever=10000**(**N-33 抬栈 min_ever 背书就绪**);锚点行完好 `cycle=20ms elm=7`(+577 ms,写者 attach 后首拍);零 `[ERR]`、采样闭锁不误报 | `20261012_B6_prod_boot_log.txt` |
| 2026-10-12 | 同 MISS 固件(d3107f3)/ **PC 主站 2404 往返**(`test/host/iec104_master.py`) | STARTDT/总召四组+actterm/C_SE 两段写触发 YX15·16 变位(COT=3)/恢复复归/YK11 两段正答/C_RD 读回 10.000 → **18/18 PASS**(104 链与锚点缺陷无关,验收窗口固件本身上先行闭环) | `20261012_B6_iec104_roundtrip_pre-fix_log.txt` |
| 2026-10-12 | 同 PASS 固件(B7+fix)/ **PC 主站 2404 往返**(复测) | 同上全链 18/18 PASS——B7 `set_sealed`+持久化写路径下 C_SE→YX 联动仍成立(B5 遗留"104 YX 联动"腿闭环) | `20261012_B6_iec104_roundtrip_log.txt` |
## 4. 关联
@@ -607,3 +607,4 @@ B0 产品定义 ✅(2026-10-10 已确认,见 §1.5)
| 2026-10-11 | **P1/P2 软件侧:定值模型 + 保护元件框架** | 新增 `App/algo/prot_set.c/h`(**定值模型**:Q10 定点与参考 2^10 口径一致;31 项元数据表**通讯地址逐项对照参考 `Comm/Pub/Const_CommSetPara.c`**——过流 Ⅰ/Ⅱ/Ⅲ = 0x8856~0x8861、过负荷 = 0x8871~0x8874、零序过压 = 0x888E~0x8890、过压/欠压沿用告警段 0x8027~0x802A;范围校验 + 整表装载 all-or-nothing + **sum32 正/反码封存自检闭锁**(参考 `dwTagSum/dwTagSumN` 模式,L5-1);⚠ 默认值/范围为**拟定**,参考 EEPROM 出厂表不在本仓库,待对照修订)+ `App/algo/prot_elm.c/h`(**元件框架**:通用"越限 + 返回系数滞回 + 定时限"核,数据驱动实例表 7 行 = OC1/OC2/OC3/OL(IA)+ OV/UV(UA)+ 3U0(UN);`prot_elm_eval()` 纯判据可主机单测,`prot_elm_run()` 为 phasor→测量薄适配(相量未就绪整拍跳过);定值闭锁 → 全元件复位)。主机单测 `test/host/prot_set/`(30 用例)+ `test/host/prot_elm/`(27 用例:1.01× 启动 / 100 ms 到点 / 滞回保持与释放 / 欠量方向 / 投退 / 闭锁联动 / 时基回绕)全绿,钩子 `prot-set-unit-test` / `prot-elm-unit-test` 登记。`@build` 0 错 0 警(**未接线 → 链接器整对象移除,零 Flash/RAM 足迹**);板端接线随 protectTask 立项(栈预算 + IWDG 门禁),标准源注入验收随其后。§3.3 L3-1/3/4/6 置 🔶、L3-2/5 注明框架就绪待通道/频率算法;§3.5 L5-1/2/4 置 🔶;§5.4 落实进度注 |
| 2026-10-12 | **B5 板端接线:protectTask 立项落地** | 新增 `App/task/protect_task.c/h`(**纯编排**,判据仍在 `App/algo/`):20 ms 节拍三件事——① **L5-4 采样故障闭锁**:`adc_health_flags()` 电平位(TPAFE/STM32 stall + 序号倒退)命中 → `prot_elm_init()` 复位 + 本拍不 eval(stall 自愈自动恢复;锁存类事件位不闭锁——非"当前测量不可信");② **L5-1 定值校验和巡检**(每拍 `prot_set_selfcheck()`,31 项 sum32 开销可忽略;⚠ 与 104 定值写的竞态窗口 µs 级、同次写 seal 即清锁,如实登记,P4 定值持久化收口);③ `prot_elm_run()` + 动作位图边沿日志(`[PROT]`,V0.1 无出口 → 动作 = 遥信 + 日志)。**线程契约收口**:`prot_elm_request_reset()`(单字标志,任意上下文)——104 YK11 在 iec104Task 落请求、下一拍 eval 头部消费,杜绝与 protectTask eval 竞态(`iec104_pts.c` 改走此口);定值/元件初始化移入 `app_main_init`(内核前,phasor_init 之后)。**门禁(E-59 同款)**:`TASK_WD_PROTECT = 8` 入 `wd_required_mask()` 两分支(产品 `0xF7`→`0x1F7`、HW 层 `0xF5`→`0x1F5`,看门狗单测 39 断言同步);栈 **512 words**,`stack_report.py` 实测静态最坏链 **872 B / 余 1176 B / 57%**;**FreeRTOS 堆 48→56 KB**(`.ioc` L1 参数 + `FreeRTOSConfig.h` 同步,CCM 75.3%→87.9% < 92% 门禁,`RAM预算台账.md` §6 登记配额 48→56 KB)。任务手写于 `Src/freertos.c` USER CODE 区(Normal,V0.1 无出口不需 AboveNormal;§2.2 表已注"1 ms/高"为 P2 瞬时值口径)。单测 +1(TC-PE-010 复归请求:不当拍生效、下一拍消费,滞回保持区可区分复位与否)→ prot_elm 28 用例全绿。`@build` 0 错 0 警(Code=204348,ZI +8,196 = 堆 +8 KB);台架 `@test`(PROT 锚点 + `[STACK] protect` 水位 + 104 YX 联动)待做。§3.3 L3-1/3 注板端落地、§3.5 L5-4 置 ✅、§7 P1 里程碑更新 |
| 2026-10-12 | **B7 定值持久化 + 全局软压板 + 竞态收口(W1 任务卡)** | **定值模型增项** `PS_GLOBAL_EN`(全局软压板,枚举尾追加,编号不回收);**原子写**:`prot_set_set_sealed()` 影子区拷贝→改→重封→**单字交换活跃区**(双缓冲 +124 B 静态),`prot_set_selfcheck()` 改 seqlock 式复核(封存和两读不一致 = 提交撞见 → 本轮跳过)——B5 登记的"104 写 vs 巡检"µs 级误锁窗口就此消除(§3.5 L5-1 注收口)。**持久化**:新增 `App/cfg/prot_set_store.c/h`(双端注册 + 模拟器豁免点名)——blob = magic`PSET`+版本+计数+值区+sum32 正/反码对(144 B),`/prot_set.bin` 走 `cfg_store_write_atomic`(临时文件+rename,掉电安全);**写路径** = C_SE/YK12 执行段置脏 → iec104Task `dirty_peek` 投递 `SYS_EVT_PROT_SET_SAVE`(事件位 bit7)→ defaultTask(配置引擎属主)落盘,写失败脏回置 = 下轮重试;**装载** = storage_bring_up 在 STORAGE_READY 前整表原子 parse(损坏/越界/版本换代 → 拒绝保出厂默认 + 自检留痕 `prot set corrupt`;文件缺失 = 首启正常静默)。**YK12 转真**:`iec104_pts.c` 两段式(选择段校验 DPC、执行段 set_sealed),protectTask 下一拍读退出态 → 复位元件 + 停判据(`global plate OUT/IN` 边沿日志);本地定值项 `comm_addr=0` 显式不可寻址(防 IOA=0 误命中)。单测:prot_set 63 断言(+33:软压板/原子写/脏握手/blob 往返/坏 magic/截断/坏版本/**伪造自洽越界**对抗样本)、iec104 94 断言(+7:YK12 两段转真/置脏/本地项 C_RD EVI)。`@build` 0 错 0 警(Code=205500 +1152 B,ZI +280 = 双缓冲+blob 缓冲,`ram_baseline` 已刷)。台架腿(104 C_SE 写→断电重启→定值保持 + YK12 联动 YX)待窗口 🔴 |
| 2026-10-12 | **B6 台架 `@test` 闭环复测(B4/B5 验收窗口,W1 任务卡)** | 首跑(HEAD `d3107f3`)**FAIL**:`protect task start` 锚点行字节级交错损坏(`st[art: cycle=220ms elm=70`,两次开机同形复现)= protectTask 启动行违反控制台写者注册前门控纪律(B5 台架腿未跑故未暴露,机理与实证见 `docs/子系统设计/控制台单写者日志设计说明.md` §11 2026-10-12 行);其余 8 Required / 零 `[ERR]` / 锚点×1 / 回读一致全过。**修复** = 启动锚点行改 `dbg_console_writer_ready()` 首拍补打(adcTask 首帧门控同款,+16 B)。**复测 PASS**(B7 `1fe163b`+fix):锚点行完好(+577 ms,attach 后);**首采水位** `protect` 828/2048(free_min 1220,59%)、`iec104` 424/2560(83%)、新 56 KB 堆 free=17936 **min_ever=10000**(>3072 告警线零告警,**N-33 抬栈 min_ever 背书就绪**);采样闭锁不误报。**PC 主站往返**:新增 `test/host/iec104_master.py`(纯标准库主站客户端)STARTDT→总召四组+actterm→C_SE 两段写临时压低 OC1 定值**确定性**触发 YX15·16 变位(COT=3)→恢复复归→YK11 两段正答→C_RD 读回 10.000,**18/18 PASS**(`d3107f3` 与 B7+fix 两版固件各一轮),串口侧 `[I104] accepted`/`[PROT] elm OC1-IA` 边沿/YK11 复位→UV-UA +10 s 重返联一致。证据 `docs/测试说明/boot_log_data/20261012_B6_*`(含缺陷复现 MISS 快照)。B5 行"台架 `@test` 待做"遗留**闭环**;B7 台架腿的 C_SE 写路径已随本窗验证(断电重启保持 + YK12→YX 仍待窗) |
+1 -1
View File
@@ -1,2 +1,2 @@
date code ro rw zi er_irom1 er_pct iram1 iram1_pct ccm ccm_pct top_rwzi
2026-10-12 205500 18044 1036 152484 223544 21.3 96096 73.3 57376 87.9 heap_4.o=57376;lv_mem_core_builtin.o=40960;lftpd.o=7884;ui_net_sink.o=6766;ui_port.o=6420;nand_ftl.o=6216;console_log.o=4120;ch395f.o=4106;default_task.o=2736;sys_log_mcu.o=1924
2026-10-12 205516 18044 1036 152484 223560 21.3 96096 73.3 57376 87.9 heap_4.o=57376;lv_mem_core_builtin.o=40960;lftpd.o=7884;ui_net_sink.o=6766;ui_port.o=6420;nand_ftl.o=6216;console_log.o=4120;ch395f.o=4106;default_task.o=2736;sys_log_mcu.o=1924
1 date code ro rw zi er_irom1 er_pct iram1 iram1_pct ccm ccm_pct top_rwzi
2 2026-10-12 205500 205516 18044 1036 152484 223544 223560 21.3 96096 73.3 57376 87.9 heap_4.o=57376;lv_mem_core_builtin.o=40960;lftpd.o=7884;ui_net_sink.o=6766;ui_port.o=6420;nand_ftl.o=6216;console_log.o=4120;ch395f.o=4106;default_task.o=2736;sys_log_mcu.o=1924
+1
View File
@@ -22,6 +22,7 @@
| `ftp_speed_test.py` | FTP 传输速度测试 |
| `ftp_capture.py` | FTP 流量抓取 |
| `ftp_regression.py` | FTP 回归套件 |
| `iec104_master.py` | **IEC 60870-5-104 主站客户端(B6)**:连设备 :2404 跑 STARTDT → 总召(actcon/四组背景扫描/actterm)→ 经 C_SE 两段写临时压低 OC1 定值确定性触发 YX16 变位(COT=3)→ 恢复 → YK11 两段式 → C_RD 读回;纯标准库,输出纯 ASCII 可直接重定向归档为台架证据(判据 exit 0/1/2) |
### 时间 / 时延
+406
View File
@@ -0,0 +1,406 @@
#!/usr/bin/env python3
# -*- coding: utf-8 -*-
"""B6 bench leg: IEC 60870-5-104 master client (GI + COV round-trip).
Task card: docs/任务规划/W1-采集保护收尾.md (B6 DoD); protocol baseline:
docs/子系统设计/IEC104上行设计说明.md §3/§4. Constants mirror
App/protocol/iec104/iec104_asdu.h / iec104_link.h.
Flow:
1. TCP connect device :2404, STARTDT act/con (enter RUN).
2. General interrogation C_IC_NA_1 (QOI=20): expect actcon, background
scan (YX double-point group SQ=1 -> YX single-point group SQ=1 ->
YC group SQ=1 -> frequency single point), actterm.
3. Deterministic COV trigger: bench analog inputs are floating (phasor
rms is 0..0.3 raw-code noise only; the standard source belongs to
B10), so we use the two-step C_SE_NC_1 write to temporarily lower
the OC1 current setting (comm addr 0x8858, default 10.0 A) to
0.05 A -> protectTask (20 ms cadence) asserts OC1 -> YX16/YX15
spontaneous (COT=3) uplink. This is exactly the "104 YX linkage"
leg left open by B5. Then restore 10.0 A -> YX16 returns.
4. YK11 (0x600A) two-step select/execute -> positive actcon (reset
request consumed asynchronously by protectTask, B5 contract).
5. C_RD read back 0x8858 ~= 10.0 (restore confirmation).
Exit codes: 0 = all checks PASS; 1 = any check FAIL; 2 = connect or
protocol error. Output is pure ASCII (redirect stdout to archive the
round-trip log as bench evidence).
Usage: python iec104_master.py [--ip 192.168.1.100] [--port 2404]
[--addr 0x8858] [--low 0.05]
[--restore 10.0]
"""
import argparse
import collections
import socket
import struct
import sys
import time
# ---- constants (mirror iec104_asdu.h / iec104_link.h) -----------------------
U_STARTDT_ACT, U_STARTDT_CON = 0x07, 0x0B
U_TESTFR_ACT, U_TESTFR_CON = 0x43, 0x83
T_M_SP_NA_1, T_M_DP_NA_1, T_M_ME_NC_1 = 1, 3, 13
T_C_SE_NC_1, T_C_DC_NA_1 = 50, 52
T_C_IC_NA_1, T_C_RD_NA_1 = 100, 102
COT_BG, COT_SPONT, COT_INIT, COT_REQ = 2, 3, 4, 5
COT_ACT, COT_ACTCON, COT_ACTTERM = 6, 7, 8
COT_PN = 0x40 # COT high byte bit6: negative confirm
RQT_GROUP1 = 20
CA = 1 # common address fixed to 1 in V0.1
SCAN_COTS = (COT_BG, COT_INIT)
YX_NAMES = {15: "YX15 fault-total", 16: "YX16 OC-I", 17: "YX17 OC-II",
18: "YX18 OC-III", 23: "YX23 overload", 31: "YX31 prot-block"}
T0 = time.time()
def log(msg):
print("[%9.3fs] %s" % (time.time() - T0, msg), flush=True)
def hexs(b):
return " ".join("%02X" % x for x in b)
# ---- APCI / ASDU builders ----------------------------------------------------
def u_frame(code):
return bytes([0x68, 0x04, code, 0x00, 0x00, 0x00])
def s_frame(vr):
return bytes([0x68, 0x04, 0x01, 0x00, (vr << 1) & 0xFE, (vr >> 7) & 0x7F])
def i_frame(vs, vr, body):
ctrl = bytes([(vs << 1) & 0xFE, (vs >> 7) & 0x7F,
(vr << 1) & 0xFE, (vr >> 7) & 0x7F])
return bytes([0x68, len(body) + 4]) + ctrl + body
def put_ioa(ioa):
return bytes([ioa & 0xFF, (ioa >> 8) & 0xFF, (ioa >> 16) & 0xFF])
def get_ioa(b, off=0):
return b[off] | (b[off + 1] << 8) | (b[off + 2] << 16)
def asdu(type_id, vsq, cot, cot_hi, ioa=None, payload=b""):
h = bytes([type_id, vsq, cot & 0x3F, cot_hi, CA & 0xFF, (CA >> 8) & 0xFF])
if ioa is not None:
h += put_ioa(ioa)
return h + payload
class Master(object):
"""Minimal 104 master. k/w/t are covered by "S after every recv batch"
(far faster than t1=15s / t2=10s), so no timers are needed here."""
def __init__(self, ip, port):
self.sock = socket.create_connection((ip, port), timeout=10)
self.sock.settimeout(1.0)
self.rx = b""
self.vs = 0
self.vr = 0
self.vr_dirty = False
self.events = collections.deque() # (kind, detail) tuples
self.yx = {} # ioa -> (val, iv)
self.yc = {} # ioa -> (val, qds)
# ---- send ----
def _send(self, data, tag):
log("TX %s %s" % (tag, hexs(data)))
self.sock.sendall(data)
def send_i(self, body, tag):
self._send(i_frame(self.vs, self.vr, body), tag)
self.vs = (self.vs + 1) & 0x7FFF
def _send_s(self):
if self.vr_dirty:
self._send(s_frame(self.vr), "S N(R)=%d" % self.vr)
self.vr_dirty = False
# ---- receive pump ----
def pump_until(self, deadline):
"""Pump RX until deadline (non-blocking semantics for wait_event)."""
while time.time() < deadline:
try:
chunk = self.sock.recv(512)
except socket.timeout:
self._send_s()
continue
if not chunk:
raise RuntimeError("peer closed (EOF)")
self.rx += chunk
while len(self.rx) >= 2 and self.rx[0] == 0x68:
ln = self.rx[1]
if ln < 4 or ln > 253:
raise RuntimeError("bad APDU length %d" % ln)
if len(self.rx) < 2 + ln:
break
apdu, self.rx = self.rx[:2 + ln], self.rx[2 + ln:]
self._handle(apdu)
if self.rx and self.rx[0] != 0x68:
raise RuntimeError("stream desync at 0x%02X" % self.rx[0])
self._send_s()
def wait_event(self, pred, timeout):
deadline = time.time() + timeout
while True:
for i, e in enumerate(self.events):
if pred(e):
return self.events[i]
if time.time() >= deadline:
return None
self.pump_until(min(deadline, time.time() + 1.0))
# ---- frame handling ----
def _handle(self, apdu):
c = apdu[2:6]
b0, b1, b2, b3 = c[0], c[1], c[2], c[3]
if (b0 & 0x01) == 0: # I format
ns = (b0 >> 1) | ((b1 & 0x7F) << 7)
nr = (b2 >> 1) | ((b3 & 0x7F) << 7)
if ns != self.vr:
raise RuntimeError("N(S)=%d out of order (expect %d)"
% (ns, self.vr))
self.vr = (self.vr + 1) & 0x7FFF
self.vr_dirty = True
self._asdu(apdu[6:], nr)
elif (b0 & 0x03) == 0x01: # S format
nr = (b2 >> 1) | ((b3 & 0x7F) << 7)
log("RX S N(R)=%d" % nr)
else: # U format
if b0 == U_STARTDT_CON:
log("RX U STARTDT con")
self.events.append(("startdt_con", None))
elif b0 == U_TESTFR_ACT:
self._send(u_frame(U_TESTFR_CON), "U TESTFR con")
elif b0 == U_TESTFR_CON:
log("RX U TESTFR con")
else:
log("RX U code=0x%02X" % b0)
def _asdu(self, a, nr):
if len(a) < 6:
raise RuntimeError("short ASDU")
type_id, vsq, cot, cot_hi = a[0], a[1], a[2], a[3]
pn = (cot_hi & COT_PN) != 0
sq = (vsq & 0x80) != 0
n = vsq & 0x7F
obj = a[6:]
if type_id in (T_M_SP_NA_1, T_M_DP_NA_1):
pts = []
if sq:
base = get_ioa(obj)
for i in range(n):
pts.append((base + i, obj[3 + i]))
else:
off = 0
for _ in range(n):
pts.append((get_ioa(obj, off), obj[off + 3]))
off += 4
for ioa, raw in pts:
val = (raw & 0x03) if type_id == T_M_DP_NA_1 else (raw & 0x01)
iv = (raw & 0x80) != 0
self.yx[ioa] = (val, iv)
self.events.append(("yx", (ioa, val, iv, cot)))
if ioa in YX_NAMES or cot == COT_SPONT:
log("RX I %s ioa=%d val=%d iv=%d cot=%d [N(R)=%d]"
% ("M_DP" if type_id == T_M_DP_NA_1 else "M_SP",
ioa, val, 1 if iv else 0, cot, nr))
elif type_id == T_M_ME_NC_1:
pts = []
if sq:
base = get_ioa(obj)
for i in range(n):
v = struct.unpack_from("<f", obj, 3 + i * 5)[0]
pts.append((base + i, v, obj[3 + i * 5 + 4]))
else:
off = 0
for _ in range(n):
v = struct.unpack_from("<f", obj, off + 3)[0]
pts.append((get_ioa(obj, off), v, obj[off + 3 + 4]))
off += 8
for ioa, v, qds in pts:
self.yc[ioa] = (v, qds)
self.events.append(("yc", (ioa, v, qds, cot)))
if cot != COT_BG and cot != COT_INIT:
log("RX I M_ME_NC ioa=0x%04X val=%.3f qds=0x%02X cot=%d"
% (ioa, v, qds, cot))
else:
self.events.append(("asdu", (type_id, cot, pn, bytes(obj))))
log("RX I type=%d cot=%d%s body=%s"
% (type_id, cot, " PN" if pn else "", hexs(obj)))
def close(self):
try:
self.sock.settimeout(2.0)
self.sock.close()
except Exception:
pass
# ---- test flow ----------------------------------------------------------------
class Checks(object):
def __init__(self):
self.items = []
def add(self, name, ok, detail=""):
self.items.append((name, bool(ok), detail))
log("CHECK %-28s %s %s" % (name, "PASS" if ok else "FAIL", detail))
def actcon_of(type_id, want_pn=None):
return lambda e: (e[0] == "asdu" and e[1][0] == type_id
and e[1][1] == COT_ACTCON
and (want_pn is None or e[1][2] == want_pn))
def main():
ap = argparse.ArgumentParser(description=__doc__.splitlines()[0])
ap.add_argument("--ip", default="192.168.1.100")
ap.add_argument("--port", type=int, default=2404)
ap.add_argument("--addr", default="0x8858",
help="setpoint comm addr to drive COV (OC1 current)")
ap.add_argument("--low", type=float, default=0.05,
help="temporary low OC1 setting (A) to force pickup")
ap.add_argument("--restore", type=float, default=10.0,
help="OC1 default setting to restore (A)")
args = ap.parse_args()
addr = int(args.addr, 0)
ck = Checks()
log("iec104 master client -> %s:%d (COV trigger: write 0x%X %.2f then "
"restore %.2f)" % (args.ip, args.port, addr, args.low, args.restore))
try:
m = Master(args.ip, args.port)
except Exception as e:
log("CONNECT FAIL: %r" % (e,))
return 2
rc = 2
try:
# 1. STARTDT
m._send(u_frame(U_STARTDT_ACT), "U STARTDT act")
ck.add("startdt_con", m.wait_event(
lambda e: e[0] == "startdt_con", 5.0) is not None)
# 2. first general interrogation
m.send_i(asdu(T_C_IC_NA_1, 1, COT_ACT, 0, ioa=0,
payload=bytes([RQT_GROUP1])),
"I C_IC act (QOI=20)")
ck.add("gi_actcon", m.wait_event(actcon_of(T_C_IC_NA_1, False),
5.0) is not None)
def scan_yx(ioa):
return lambda e: (e[0] == "yx" and e[1][0] == ioa
and e[1][3] in SCAN_COTS)
ck.add("scan_yx_dp(ioa4)", m.wait_event(scan_yx(4), 10.0) is not None)
ck.add("scan_yx_sp(ioa16)", m.wait_event(scan_yx(16), 10.0) is not None)
ck.add("scan_yc(ioa0x4018)", m.wait_event(
lambda e: (e[0] == "yc" and e[1][0] == 0x4018
and e[1][3] in SCAN_COTS), 10.0) is not None)
ck.add("scan_freq(ioa0x401D)", m.wait_event(
lambda e: (e[0] == "yc" and e[1][0] == 0x401D
and e[1][3] in SCAN_COTS), 10.0) is not None)
ck.add("gi_actterm", m.wait_event(
lambda e: (e[0] == "asdu" and e[1][0] == T_C_IC_NA_1
and e[1][1] == COT_ACTTERM), 10.0) is not None)
v16 = m.yx.get(16)
ck.add("baseline_yx16_off", v16 is not None and v16 == (0, False),
"yx16=%r" % (v16,))
# 3. COV up: lower OC1 setting (two-step C_SE_NC_1)
def se(select):
pl = struct.pack("<f", args.low) + bytes([0x80 if select else 0x00])
return asdu(T_C_SE_NC_1, 1, COT_ACT, 0, ioa=addr, payload=pl)
m.send_i(se(True), "I C_SE select 0x%X = %.3f" % (addr, args.low))
ck.add("se_select_con", m.wait_event(actcon_of(T_C_SE_NC_1, False),
5.0) is not None)
m.send_i(se(False), "I C_SE execute 0x%X = %.3f" % (addr, args.low))
ck.add("se_execute_con", m.wait_event(actcon_of(T_C_SE_NC_1, False),
5.0) is not None)
m.events.clear() # drop any echo/ack noise before COV watch
def spont(ioa, val):
return lambda e: (e[0] == "yx" and e[1][0] == ioa
and e[1][1] == val and e[1][3] == COT_SPONT)
ck.add("spont_yx16_ON", m.wait_event(spont(16, 1), 8.0) is not None)
ck.add("spont_yx15_ON", m.wait_event(spont(15, 1), 3.0) is not None)
# 4. COV down: restore OC1 default setting
def se_restore(select):
pl = struct.pack("<f", args.restore) + bytes([0x80 if select else 0x00])
return asdu(T_C_SE_NC_1, 1, COT_ACT, 0, ioa=addr, payload=pl)
m.send_i(se_restore(True), "I C_SE select 0x%X = %.3f (restore)"
% (addr, args.restore))
ck.add("se_restore_select_con",
m.wait_event(actcon_of(T_C_SE_NC_1, False), 5.0) is not None)
m.send_i(se_restore(False), "I C_SE execute 0x%X = %.3f (restore)"
% (addr, args.restore))
ck.add("se_restore_execute_con",
m.wait_event(actcon_of(T_C_SE_NC_1, False), 5.0) is not None)
m.events.clear()
got_spont_off = m.wait_event(spont(16, 0), 5.0) is not None
if got_spont_off:
ck.add("yx16_OFF", True, "via spontaneous COT=3")
else:
# floating-input chatter may have returned YX16 before the
# restore write; fall back to a second GI background scan.
log("no spont OFF within 5s -> second GI background scan")
m.send_i(asdu(T_C_IC_NA_1, 1, COT_ACT, 0, ioa=0,
payload=bytes([RQT_GROUP1])),
"I C_IC act #2 (QOI=20)")
ok_term = m.wait_event(
lambda e: (e[0] == "asdu" and e[1][0] == T_C_IC_NA_1
and e[1][1] == COT_ACTTERM), 15.0) is not None
ck.add("yx16_OFF", ok_term and m.yx.get(16) == (0, False),
"via 2nd GI scan, yx16=%r" % (m.yx.get(16),))
# 5. YK11 two-step (positive confirm; reset consumed by protectTask)
m.send_i(asdu(T_C_DC_NA_1, 1, COT_ACT, 0, ioa=0x600A,
payload=bytes([0x82])), "I C_DC YK11 select (QDC=82H)")
ck.add("yk11_select_con", m.wait_event(actcon_of(T_C_DC_NA_1, False),
5.0) is not None)
m.send_i(asdu(T_C_DC_NA_1, 1, COT_ACT, 0, ioa=0x600A,
payload=bytes([0x02])), "I C_DC YK11 execute (QDC=02H)")
ck.add("yk11_execute_con", m.wait_event(actcon_of(T_C_DC_NA_1, False),
5.0) is not None)
# 6. C_RD read back the restored setpoint
m.send_i(asdu(T_C_RD_NA_1, 1, COT_REQ, 0, ioa=addr),
"I C_RD 0x%X" % addr)
e = m.wait_event(lambda e: (e[0] == "yc" and e[1][0] == addr
and e[1][3] == COT_REQ), 5.0)
ck.add("rd_setpoint_10.0",
e is not None and abs(e[1][1] - args.restore) < 0.1,
"read=%.3f" % (e[1][1],) if e else "no response")
m.close()
rc = 0 if all(ok for _, ok, _ in ck.items) else 1
except Exception as e:
log("PROTOCOL ERROR: %r" % (e,))
rc = 2
n_ok = sum(1 for _, ok, _ in ck.items)
log("SUMMARY: %d/%d checks PASS -> %s"
% (n_ok, len(ck.items), "PASS" if rc == 0 else ("FAIL" if rc == 1 else "ERROR")))
return rc
if __name__ == "__main__":
sys.exit(main())