fix: improve field diagnostics and mirror logs to USB CDC

docs/现场网络诊断.md

@@ -2,41 +2,88 @@
 
 GPIO84 原报警/留言按键改为诊断键。释放时按住超过 50 ms、少于 3 秒，开启主动模式。超过或等于 3 秒不执行动作。重复短按只打印已开启，不创建重复任务；重启恢复关闭。该按键不再报警、留言、播放提示音或停止音频。
 
-设备处于定时休眠、OTA 或关机流程时不响应开启。开启之后遇到这些状态，暂停采样和新探测，已有探测可能继续到返回。没有新增常亮、常唤醒或自动重启操作；主动网络流量本身仍可能影响空闲态和耗电。
+设备处于定时休眠、OTA 或关机流程时不响应开启。开启之后遇到这些状态，暂停采样和新探测。TCP 等待期间每不超过 200 ms 检查一次取消；SDK 的域名解析是同步调用，必须等待返回才能取消，未修改全局 DNS 超时设置。原有休眠和定位流程保留。
 
-## 查看日志
+## Mac 直接读取 USB 日志
 
-使用原有固件日志串口，终端设置 UTF-8，保存完整串口输出。搜索 `[现场诊断]` 可筛出诊断行。时间为开机毫秒（目标平台计数会回绕），不是北京时间。日志不写 Flash、不上传服务器；断网时电脑仍可留存串口日志。
+刷入这版固件后，用支持数据传输的 USB 线连接设备与 Mac。固件通过 `QL_USB_CDC_PORT` 输出 UTF-8 纯文本，并保留 UART 输出。没有使用基带 DIAG 二进制日志端口。
 
-- 每约 2 秒：注册状态、PDP 数据连接、MQTT、WSS，及 LTE 信号原始字段。
-- 每约 10 秒：SINR 原始值、LTE 驻留小区 CID/PCI/EARFCN 和 MCC/MNC。标记小区变化。
-- 主动探测：依次 Ping `223.5.5.5` 和当前业务域名 `banban.api.talkingq.com`，每目标 1 个 32 字节载荷，ICMP 超时 2000 ms；整轮完成后等待 10 秒。域名解析和 SDK 调度可能增加耗时，非严格周期。
-- 即时事件：数据连接回调、当前 WSS 的建立/断开；注册/PDP 的采样变化、不可用和恢复。
-- 每次探测后：本次开机的已发送、收到、未回应、未回应率和执行异常数量。超时连续次数遇到收到回应时清零。未获得有效发包统计的 SDK 错误单独计数。
+在仓库根目录运行下面命令。读取工具只用 Python 3 标准库，不需要安装 pyserial。
 
-示例（演示数据，并非现场测量）：
+```sh
+python3 tools/read_usb_log.py --list
+python3 tools/read_usb_log.py --port /dev/cu.usbmodemXXXX --reconnect
+```
+
+将 `cu.usbmodemXXXX` 换成拔插设备后新增的实际端口。多个串口时，工具要求明确选择，不会自行选择第一个。确认选对端口的方法是看到 `[USB日志]` 在线提示；普通 USB 转串口适配器也可能出现在列表中。
+
+默认保存到当前目录的 `usb-logs/banban-年月日-时分秒.log`，同时在终端显示。短按原报警键开始网络诊断，随后进行对话，按 Ctrl+C 停止保存。`--reconnect` 等待同名端口重新出现，端口改名后需重新指定。可添加 `--output 路径` 更改文件位置，或 `--diag-only` 只保存 `[现场诊断]` 和 `[USB日志]` 行。
+
+也可以使用现有串口终端打开这个 USB CDC 口：115200、8N1、无流控、UTF-8。同一端口同时只用一个读取程序。没有新增端口时，先检查数据线和 Mac 的 USB 设备枚举；实际板上的 USB 数据连接、CDC 描述符和 Mac 驱动识别仍需上板确认。
+
+日志通过约 8 KB 的有界队列交给独立低优先级 USB 转发任务。业务日志入队使用零等待；USB 写失败时关闭并重新打开 CDC。队列拥塞或写失败会丢弃 USB 副本并累计计数，在线提示每约 5 秒报告一次。电脑接收时间不等于设备事件时间；断线前 SDK 已接受但未送到电脑的数据也无法保证补回，不支持历史日志回放。
+
+转发范围是 `custom_app` 目标内编译的 `printf`，包括这次新增的诊断、VAD、WSS 和播放器日志。预编译库、内核、基带和启动前日志不经过本转发。单次格式化最多 511 字节，超长记录会明确加 `[TRUNCATED]`，并在 UTF-8 字符边界截断。日志不写设备 Flash、不上传服务器。
+
+## 日志内容
+
+设备时间为开机毫秒；目标平台计数会回绕。搜索 `[现场诊断]` 筛选诊断行，按 `[对话#编号]` 关联一轮对话。
+
+- 每约 2 秒：注册状态、PDP 数据连接、MQTT、WSS，及 LTE 信号原始字段。SDK 查询可能增加采样间隔。
+- 每约 10 秒：可用的 SINR、LTE 驻留小区 CID/PCI/EARFCN、MCC/MNC 原始编码。标记小区变化。
+- 主动探测：依次测量参照 DNS 服务 `223.5.5.5:53` 和业务 WSS 入口 `banban.api.talkingq.com:443` 的 DNS 解析与 TCP 建连耗时。整轮完成后等待 10 秒；使用 PDP 1 的实际数据连接地址绑定。TCP 等待上限 3000 ms，不发送业务内容，也不进行 TLS/WSS 握手。
+- 即时事件：数据连接回调、当前 WSS 的建立/断开；注册/PDP 的采样变化、不可用和恢复。底层套接字写入失败或耗时达到 200 ms 时单独记录。
+- 每次探测后：本次开机的 TCP 有效尝试、成功、失败、失败率和执行异常数量。连续 TCP 失败遇到成功时清零。DNS、套接字初始化、绑定和本地等待错误单独计数，不混作 TCP 失败。
+
+原现场日志中两个目标均在 `ql_ping_init()` 阶段返回空指针，没有形成有效探测。当前默认直接使用业务已有的 DNS/TCP 路径，移除对可选 Ping API 的依赖；没有把空指针的根因武断归为网络错误或已确认的内核缺失。
+
+SINR 接口未导出或返回 255 时只记录一次不可用提示，本次开机跳过该项。CQI 不在 0～15 范围内时标为不可用并保留原始值。MCC/MNC 用十六进制明确表示原始编码，避免将编码值误当作普通十进制运营商号码。
+
+示例为演示数据，并非上板测量：
 
 ```text
 [现场诊断][12000 ms][连接] 注册=已注册本地网络(1) 数据连接=已连接 MQTT=已连接 WSS=已连接
-[现场诊断][12000 ms][信号原始值] RSSI=-71 RSRP=-97 RSRQ=-12 CQI=8；单位/无效值以模组为准
-[现场诊断][12500 ms][探测成功] 参照节点 223.5.5.5；往返=123 ms
-[现场诊断][12500 ms][累计统计] 参照节点；已发送=20 收到=19 未回应=1 未回应率=5% 执行异常=0（本次开机累计）
+[现场诊断][12000 ms][信号原始值] RSSI=-55 RSRP=-80 RSRQ=-3 CQI=不可用(raw=255)；单位/无效值以模组为准
+[现场诊断][12500 ms][探测成功] 业务WSS入口；IP=192.0.2.1 解析=35 ms TCP建连=123 ms（非AI响应时间）
+[现场诊断][12500 ms][累计统计] 业务WSS入口；TCP有效尝试=20 成功=19 失败=1 失败率=5% 执行异常=0；非业务丢包率
 ```
 
-## 判断边界
+## 一轮对话的分段计时
 
-信号值以 SDK 返回的原始字段记录。必须结合模组实际单位、无效值和无线制式确认后解释，暂不直接分档。注册成功不代表有互联网；MQTT/WSS 状态是业务维护的状态，断网瞬间可能滞后。当前按 LTE 项目设计，其他制式不能直接使用 LTE 字段判读。
+诊断模式开启后的下一轮录音开始计时，依次记录：开始录音、确认用户语音、录音结束、结束包入发送队列、收到 END_ACK（服务器实际返回时）、收到 TTS_START、收到首段音频 URL、首段开始下载/下载完成、首 PCM 交给播放接口。
 
-参照节点属于外部公共服务，可能限速或禁 ICMP；业务域名对应入口也可能不回答 Ping。两者均不是 AI 服务健康检查。ICMP 未回应率不等于语音业务丢包率；域名探测结果中的 RTT 是 ICMP 往返时间，不包括 DNS 或 AI 处理时间。
+首段根据通过当前 session 校验的完整 URL 匹配，只跟踪第一段正常回复，排除不匹配的本地提示、留言确认和错误提示；后续录音轮次开始后不接受上一轮的延迟阶段事件。VAD 统计显示总帧、活跃录音帧，以及首次确认前连续语音峰值，例如 `13/20`，帮助判断为什么一直没有确认开口。没有根据一份日志直接降低 VAD 阈值。
 
-网络不可用计时依据注册状态和实际 PDP 查询；查询失败不虚构掉线/恢复。时间包含采样误差和暂停期间，不能当作精确无线断线时间。小区变化表示驻留记录改变，不等同于已确认发生连接态切换。
+阶段齐全且顺序合理时，在首 PCM 提交后输出汇总：
 
-本次实现侧重网络现场日志，尚未新增每轮对话的 VAD/上传/服务端/首音分段计时，也未新增 DNS/TCP/TLS 独立探测。若网络记录正常但回复仍慢，需结合已有 WSS/TLS/音频日志和服务端记录继续定位。
+```text
+[现场诊断][3350 ms][对话#3][耗时汇总] 录音结束到首PCM=2350 ms；收尾入队=100 等TTS通知=400 等首URL=1500 播放队列=100 下载=200 解码提交=50（均ms；含网络与服务端处理，尚未分离）
+```
+
+`录音结束` 是 VAD 停止录音的时间，不是人实际停止说话的时间。`结束包入队` 不表示底层发送完成或服务端收到；底层慢写事件可作辅助，END_ACK 也仅在后端返回该事件时存在。`首PCM提交` 不是扬声器的精确出声时刻。只有后端配合同一轮请求的收包/ASR/模型/TTS 时间，才能进一步分离服务端处理与网络等待。
+
+## 如何判断
+
+先看对话编号对应的慢阶段，再看同一时段的信号、DNS、TCP 和掉线事件。连续语音峰值未达到确认条件、最后以 no_speech 结束，应优先核对当时是否说话及采音/VAD。首 URL 出现得晚应结合服务器日志；URL 已到但下载/播放排队慢，则优先看对应下载和播放阶段。
+
+TCP 建连成功只说明该次能连接目标端口，不代表 TLS、WSS 或 AI 业务正常；失败也可能是目标端口策略、服务状态等原因。参照端口和业务端口不相同，不能仅凭一次结果直接归责运营商。解析可能命中缓存，未清空业务 DNS 缓存，解析耗时不是强制冷查询耗时。TCP 失败率不等于业务丢包率。
+
+信号按 SDK 原始字段记录，单位和无效值仍应以模组确认结果解释。注册成功不代表有互联网；MQTT/WSS 状态是业务维护的状态，可能滞后。网络不可用计时包含采样误差和暂停时间，查询失败不会虚构掉线/恢复。小区变化表示驻留记录改变，不等同于已确认发生连接态切换。
+
+## GNSS 日志开关
+
+`gnss.c` 中 `BANBAN_GNSS_LOG_ENABLED` 默认 0，临时屏蔽模式提示、倒计时、坐标、解析提示和原始 NMEA 输出。定位、卫星搜索、开关 GNSS 与位置上报流程保留。静默函数仍求值原日志参数，保留历史上写在参数中的 `ql_gnss_close()` 调用。需要恢复时设为 1 或为该目标添加同名编译宏。
 
 ## 验证与上板
 
-运行 `python3 tools/test_net_diag.py`，以 SDK 头文件和模拟模组接口编译运行真实诊断源码，验证任务创建失败重试、重复开启、成功/无回应/执行异常统计、网络恢复计时和休眠暂停；并检查按键分支没有原报警/留言/音频操作。
+```sh
+python3 tools/test_net_diag.py
+python3 tools/test_conversation_timeout.py
+python3 tools/test_read_usb_log.py
+```
 
-macOS 测试仅在临时副本中移除 SDK 与宿主不兼容的 32 位 size_t 定义，不改 SDK 文件。该测试不代表 ARM 完整固件编译或硬件验收。正式构建沿用项目 Windows ARM Compiler 5 构建流程。
+诊断测试编译执行真实诊断源码，模拟 SDK 的成功、DNS 失败、连接拒绝、超时、初始化失败、取消和资源释放；验证统计、SINR/CQI 不可用处理、USB 零等待队列/部分写/断线重开、对话分段与旧轮次隔离、GNSS 静默仍保留副作用。已有对话回归测试验证超时、打断和角色提示流程。Mac 读取工具使用临时伪终端验证 UTF-8 分包、过滤、Ctrl+C 与末行保存，不打开物理串口。
 
-上板后核对：UTF-8 中文是否正确；50 ms 以下抖动、正常短按、重复短按、3 秒以上长按；断网仍可开启诊断；两目标成功和不回应；恢复网络；对话时不因按键中断声音；OTA/定时休眠暂停；重启关闭。核实实际模组信号单位、Ping 回调和内存余量。
+宿主测试只在临时头文件副本/编译选项中处理 SDK 的 32 位 size_t 和 timeval 与 Mac 的差异，不修改 SDK。测试不能代替完整 ARM 固件构建与硬件验收。正式构建沿用项目 Windows 工具链；当前应用 Makefile 使用 arm-none-eabi-gcc。
+
+上板后确认：直接 USB 枚举与端口识别；UTF-8 日志；晚插线、拔插、拥塞和 USB 丢弃计数；离线仍可开启诊断；两个目标的 DNS/TCP 结果；对话时音频正常且汇总匹配；OTA/定时休眠暂停；重启关闭。核实模组信号单位、实际内存余量和 USB SDK 的返回语义。