fix(lftpd): 对端行为不再打 [ERR]——新增 lftpd_peer 级别并划清级别边界

现象:抓自检台账基线那次 FTP 会话一结束,设备就打 `[ERR] [FTP] error reading next command`,
本次 `@test` 直接 FAIL(Forbidden 含 `[ERR]`)。查下去发现 lftpd 把**全部**异常路径一律按
error 级打,其中九处其实由外部输入决定:客户端关窗口、连上就走、PASV 后不建数据连接、
运维改 IP 触发监听重建。两条代价:① 任何人"连 21 端口一下就断开"就能把一次启动测试打成
FAIL;② 同样的动作可以**无限制造固件级 ERROR 日志**——日志面与门禁面都可被外部驱动,
工业现场过不了审。

**做法**:`private/lftpd_log.h` 新增 `lftpd_log_peer()`(info 级,带 `[FTP]` 前缀),而不是
就地改成 `DBG_INFO`——让"谁才算真故障"在读代码时一目了然,也防止后来者顺手把对端行为升回
error。降级的九处:控制通道被对端关闭(原 `error reading next command`,改为
`control channel closed by peer (ret=%d)`,措辞原先把正常收尾写成故障、误导过排查方向)、
发送 220 前对端已走、`listener rebuilt`(网络重建,原因由 accept 层自己记)、四处
`data accept failed`(PASV 后没来数据连接)、`accept timeout`。

**刻意留在 error 的**:create/bind/listen/取端口失败、写通道失败、文件打开失败、
`DOWNLOAD/UPLOAD FAILED`(对端中途退出确实让一次传输没走完 = 数据完整性事件,
`../问题记录/CH395F_Trap_Records.md` 的中止家族要靠这些锚点定位)、
`data listener disarmed`(控制连接还活着而我方数据监听已不在服役 = 本侧异常,就地注明)。

**实测划清的边界**:客户端**干净收尾**(发 `QUIT` 或 FIN 半关)现在整条链路没有任何 `[ERR]`;
但 **RST 硬拆**(`SO_LINGER` 清零 / 进程被杀 / 拔线)仍会留一条 `[ERR][NET] sockN TIMEOUT`——
那是 net 层的套接字超时锚点,网络自愈架构判据要读它,不在本次降级范围。所以"采集窗口内别跑
`data listener disarmed`(控制连接还活着而我方数据监听已不在服役 = 本侧异常,就地注明)。

**真机验证**:`@build` 0 错 0 警告;`@test --require-selftest-pass --device-ip` →
  **PASS**
(基线 29 条 → 本次无新增;`net init: OK` 726 ms);专门写了 RST 复现脚本(登录后 `SO_LINGER`
清零直接关)→ 串口得到 `[FTP] control channel closed by peer (ret=-1)`,**不再是 `[ERR]` 行**;
同一份日志里 QUIT 收尾的那次会话完全没有错误行。

体量:`Code` 213,236 → **213,264 B(+28)**、`RO` 18,580 → **18,652 B(+72)**(措辞变长),
同一份日志里 QUIT 收尾的那次会话完全没有错误行。
`ZI` 131,500、`RW_IRAM1` 75,264 B 57.4% / `RW_CCM` 57,376 B 87.9% 全不变)。数字联动照做:
两份 `data/` 快照、`ram_baseline --update/--write`、`check_mem_numbers --write`、FLASH
  配图
常量重算重生成(桶合计 = 231,916 与 `Code+RO` 相符;越界复查 0)、报告 §1.3/§5.1/§5.4 与
部署文档 §3.3 同步。

口径落文:新增 `docs/架构设计/STM32F4-Base存储架构说明.md` §10.3「FTP 日志级别划分:对端行为
vs 固件故障」(含两类的判据表与边界),并更新 `docs/测试说明/自动化测试流程.md` 的采集窗口警示。
顺手把 `private/lftpd_log.h` 工作区的 CRLF 混用归一回 LF(仓库里 blob 本来就是 LF,diff 无影响)。

门禁:`doc-links --all --sections-strict` 146 文档 0 问题、`id-check --strict` 增量拦截通过
(可判定 82.82%)、`mem-numbers` / `mem-budget` / `layer-deps` 全绿;改动文件字节卫生 BOM 无 /
CR 0 / U+FFFD 0 / 无行尾空格。未推送。
This commit is contained in:
2026-10-22 22:31:09 +08:00
parent af5bad5609
commit 4c21cff753
14 changed files with 118 additions and 63 deletions
+13 -7
View File
@@ -368,7 +368,8 @@ static int cmd_list(lftpd_client_t *client, const char *arg)
send_simple_response(client->socket, 150, STATUS_150);
int data_sock = lftpd_inet_accept_timeout(client->data_socket, 5000);
if (data_sock < 0) {
lftpd_log_error("%s accept failed, sk=%d", __func__, client->data_socket);
lftpd_log_peer("%s data accept failed (peer gone?), sk=%d",
__func__, client->data_socket);
send_simple_response(client->socket, 425, STATUS_425);
lftpd_inet_close(client->data_socket);
client->data_socket = -1;
@@ -400,7 +401,8 @@ static int cmd_nlst(lftpd_client_t *client, const char *arg)
send_simple_response(client->socket, 150, STATUS_150);
int data_sock = lftpd_inet_accept_timeout(client->data_socket, 5000);
if (data_sock < 0) {
lftpd_log_error("%s accept failed, sk=%d", __func__, client->data_socket);
lftpd_log_peer("%s data accept failed (peer gone?), sk=%d",
__func__, client->data_socket);
send_simple_response(client->socket, 425, STATUS_425);
lftpd_inet_close(client->data_socket);
client->data_socket = -1;
@@ -526,7 +528,8 @@ static int cmd_retr(lftpd_client_t *client, const char *arg)
send_simple_response(client->socket, 150, STATUS_150);
int data_sock = lftpd_inet_accept_timeout(client->data_socket, 5000);
if (data_sock < 0) {
lftpd_log_error("%s accept failed, sk=%d", __func__, client->data_socket);
lftpd_log_peer("%s data accept failed (peer gone?), sk=%d",
__func__, client->data_socket);
send_simple_response(client->socket, 425, STATUS_425);
lftpd_inet_close(client->data_socket);
client->data_socket = -1;
@@ -593,7 +596,8 @@ static int cmd_stor(lftpd_client_t *client, const char *arg)
send_simple_response(client->socket, 150, STATUS_150);
int data_sock = lftpd_inet_accept_timeout(client->data_socket, 5000);
if (data_sock < 0) {
lftpd_log_error("%s accept failed, sk=%d", __func__, client->data_socket);
lftpd_log_peer("%s data accept failed (peer gone?), sk=%d",
__func__, client->data_socket);
send_simple_response(client->socket, 425, STATUS_425);
lftpd_inet_close(client->data_socket);
client->data_socket = -1;
@@ -658,7 +662,7 @@ static int handle_control_channel(lftpd_client_t *client)
{
int err = send_simple_response(client->socket, 220, STATUS_220);
if (err != 0) {
lftpd_log_error("error sending welcome message");
lftpd_log_peer("peer gone before welcome acked");
goto cleanup;
}
@@ -668,7 +672,9 @@ static int handle_control_channel(lftpd_client_t *client)
int line_len = lftpd_inet_read_line(client->socket, read_buffer,
sizeof(read_buffer));
if (line_len != 0) {
lftpd_log_error("error reading next command");
/* 绝大多数是客户端正常收尾(关窗口 / QUIT 前先断了 TCP);
* 真读错也由返回值区分得出来,留 ret=%d 便于排障 */
lftpd_log_peer("control channel closed by peer (ret=%d)", line_len);
goto cleanup;
}
@@ -786,7 +792,7 @@ int lftpd_start(const char *directory, int port, lftpd_t *lftpd)
int client_socket = lftpd_inet_accept(lftpd->server_socket);
if (client_socket < 0) {
lftpd_log_error("error accepting client socket");
lftpd_log_peer("listener rebuilt (reason logged by accept layer)");
lftpd_inet_close(lftpd->server_socket);
lftpd->server_socket = -1; /* 监听器已不可用(网络重建):下轮重建 */
continue;
+6 -2
View File
@@ -88,7 +88,8 @@ int lftpd_inet_accept(int socket)
return s;
}
if (net_get_generation() != gen) {
DBG_ERROR("network re-init: abort accept, relisten");
/* 运维改 IP 的正常后果,不是缺陷 → info(级别划分见存储架构说明 §10.3) */
DBG_INFO("network re-init: abort accept, relisten");
return -1;
}
lftpd_task_wd_beat(); /* 看门狗:自旋轮次喂心跳(无限等待,可能长时间无客户端) */
@@ -110,6 +111,8 @@ int lftpd_inet_accept_timeout(int socket, int timeout_ms)
* 认"监听器在服役(LISTENING)或待重建且 RX 有残留(closed-with-data 救回窗)",
* 与 :7003 的 N-32 P1 同型修复 */
if (net_listener_armed(socket) == 0) {
/* **故意留 error**:控制连接还活着、我方数据监听却已不在服役 →
* 这是本侧异常,不是对端行为 */
DBG_ERROR("data listener disarmed, accept aborted");
return -1;
}
@@ -118,7 +121,8 @@ int lftpd_inet_accept_timeout(int socket, int timeout_ms)
elapsed += 100;
}
DBG_ERROR("accept timeout (%dms)", timeout_ms);
/* 客户端连上控制通道却没来建数据连接(中止/被防火墙拦)= 对端行为 → info */
DBG_INFO("accept timeout (%dms) - peer never opened data channel", timeout_ms);
return -1;
}
+15
View File
@@ -4,4 +4,19 @@
#define lftpd_log_error(format, ...) DBG_ERROR("[FTP] " format, ##__VA_ARGS__)
#define lftpd_log_info(format, ...) DBG_INFO("[FTP] " format, ##__VA_ARGS__)
/*
* 对端行为级别(既不是缺陷,也不该长得像缺陷)——
* 控制连接被对端关闭 / 客户端连上就走 / PASV 之后不来数据连接 / 网络重建导致
* 监听重建,这些都是**外部输入决定的正常收尾**。它们原先记 error 级,代价实测:
* ① 本仓 @test 的 Forbidden 标记含 `[ERR]`(它同时是四个 Fault 崩溃日志的前缀),
* 于是"FileZilla 关了个窗口"就能把一次启动测试判 FAIL;② 任何人对着 21 端口
* 连一下就走,就能无限制造固件级 ERROR 日志(日志面 + 门禁面都能被外部驱动)。
* 所以这一类降为 info,并单独起一个名字,让"谁是真故障"在读代码时就一目了然。
* 完整划分表 → docs/架构设计/STM32F4-Base存储架构说明.md §10.3。
*
* ⚠ **传输未完成不在这一级**:`DOWNLOAD/UPLOAD FAILED` 仍记 error——对端中途退出
* 确实让一次传输没走完,那是数据完整性事件,值得留痕。
*/
#define lftpd_log_peer(format, ...) DBG_INFO("[FTP] " format, ##__VA_ARGS__)
#define lftpd_log_debug(format, ...)