故障排查——SQLite在PoleFS上的同步异常
根因定位:PoleFS 客户端的文件同步请求长期停留在 S3 上传签名前的脏数据读取路径,反复进行范围查询、内存分配并引发 GC;高度怀疑读取零进度循环,但未直接取得现场返回值。停止 SQLite 使用进程未解除异常,重启客户端并重新挂载后恢复。本次完成的是服务恢复,不是客户端缺陷修复。
现象
PoleFS 客户端持续占用约一个逻辑 CPU,常驻内存约 5.5 GiB。挂载目录中运行着使用 SQLite WAL 的监控程序。
客户端实时采样结果如下。CPU 百分比按单个逻辑 CPU 为 100% 计。
1 | 采样1: 3.01秒; 整机非空闲=9.5%; iowait=2.7% |
另一次 5 秒采样区分了用户态与内核态消耗。
1 | 用户态CPU%: 100.8 |
SQLite 所在进程还出现了不可中断等待。最终取得的内核栈表明,它正在等待文件同步完成。
环境
| 项目 | 本次环境 |
|---|---|
| 故障日期 | 2026 年 11 月 10 日 |
| 系统内核 | Linux 5.10.134-14.an8.x86_64 |
| 逻辑 CPU | 32 个 |
| 文件系统 | PoleFS,挂载类型为 fuse.polefs |
| 挂载点 | /public_data |
| 后端访问 | 客户端调用链中使用 AWS SDK for Go 访问 S3 后端 |
| 应用 | Python 监控程序,使用 SQLite WAL 文件组 |
| 客户端二进制 | Go 程序,常规符号已裁剪,保留 .gopclntab |
| 客户端管理方式 | 遗留在登录会话 scope 中,不是专用 systemd 服务 |
| 客户端版本 | 未取得明确版本号 |
| SQLite 版本与同步配置 | 未取得,不推定 synchronous、checkpoint 阈值等实际设置 |
本文隐藏主机、账号、域名、认证参数和个人路径。保留 PoleFS 名称及函数名,用于说明本案的实现特点。命令中的 <占位符> 需要替换后执行,不能直接照抄。
排查过程
一、确认不是整机 CPU 满载
机器有 32 个逻辑 CPU。进程占用约 100%,表示约占满一个逻辑 CPU,而不是整机使用率达到 100%。整机采样也未显示 CPU 已耗尽。
目标进程的消耗主要在用户态,主缺页为零。因此先调查客户端自身的计算路径,而不是把原因归为整机算力不足或频繁换入页面。
后续热点线程在多个线程间变化,不能只根据主线程显示的 S 状态判断进程空闲。
二、用 perf 采样,先解决符号映射问题
当前会话无权读取 root 客户端的 I/O、文件描述符和性能数据,因此需要在 SSH 终端通过 sudo 执行相关命令。
最初使用 perf top,采样进程进入了 T 状态,未正常结束。这是诊断命令被暂停,不是目标客户端进入相同状态。随后改用非交互式采样,并设置强制退出兜底。
1 | PERF_DIR=$(mktemp -d /tmp/polefs-perf.XXXXXX) |
本次采集到 481 个样本,无丢失。报告起初只显示地址。
1 | 3.12% polefs-client polefs-client [.] 0x0000000000734c67 |
直接把报告中的地址交给 Go 地址解析工具,曾错误映射到 Gob、HTTP 函数。完整报告出现了低于代码加载区的地址,促使重新核对 ELF 加载基址。
1 | readelf -l /usr/bin/polefs-client |
本次二进制为 ELF EXEC,可执行加载段从 0x400000 开始。perf script 输出的原始指令地址,与报告显示的未解析偏移相差 0x400000。
| 报告显示地址 | 原始指令地址 | 正确函数 |
|---|---|---|
0x734c67 |
0xb34c67 |
fs.(*block).readRange |
0x6e1745 |
0xae1745 |
backend.(*Range).Less |
0x12fdb |
0x412fdb |
runtime.mallocgc |
该基址修正只适用于本次二进制和报告格式,不能作为所有 perf 地址的通用加法。优先解析原始指令地址,并核对采样二进制是否匹配。
使用保留的 Go 行号表解析原始地址,再按函数汇总。
1 | sudo perf script -i "$PERF_DIR/perf.data" -F ip \ |
主要结果如下。
1 | 30.56% 147 runtime.mallocgc |
范围查找、脏数据读取和内存分配成为主要方向。此时只有自身热点,还不能证明这些函数之间的调用关系,也不能把 mallocgc 的全部时间算作 GC。
三、I/O 增量很小,不支持大流量读写解释
查看 5 秒内的进程 I/O 计数变化。
1 | sudo sh -c 'cat /proc/<客户端PID>/io; sleep 5; cat /proc/<客户端PID>/io' |
| 计数 | 起点 | 5 秒后 | 增量 |
|---|---|---|---|
rchar |
7414014317608 | 7414014317881 | 273 字节 |
wchar |
6070685366824 | 6070685367103 | 279 字节 |
syscr |
2205242581 | 2205242586 | 5 次 |
syscw |
570085334 | 570085339 | 5 次 |
read_bytes |
2670166016 | 2670166016 | 0 |
write_bytes |
230727680 | 230727680 | 0 |
这些计数不能直接等同于共享文件业务吞吐或远端存储流量,但说明该窗口内没有大量读写系统调用。
这削弱了“大量正常 I/O 导致高 CPU”的解释。不过它与先前的 CPU 样本不在同一窗口,仍需调用链确认。
四、通过本机 pprof 找到完整调用链
检查文件描述符后,发现客户端有本机可访问的 HTTP 监听端口;二进制也包含 net/http/pprof。实际请求确认了诊断接口可用。
以下端口为本次发现的端口,不应假定其他部署相同。请求从本机发出,不经过代理。
1 | curl --noproxy '*' --fail --max-time 5 \ |
通过同一接口采集 10 秒 CPU profile,再用 go tool pprof 分析自身和累计热点。本次实际使用本机 Python HTTP 客户端完成采集;以下为等价复查命令。
1 | DIAG_DIR=$(mktemp -d /tmp/polefs-diag.XXXXXX) |
采样持续 10.10 秒,累计 CPU 样本为 14.63 秒,相当于平均约使用 1.45 个逻辑 CPU。
| 调用路径 | 累计样本占比 |
|---|---|
buffer.flushDirty |
64.52% |
AWS SDK Request.Sign |
64.39% |
signingCtx.buildBodyDigest |
64.11% |
part.Read |
63.98% |
block.ReadDirty |
54.82% |
后台 GC runtime.gcBgMarkWorker |
30.83% |
累计占比存在包含关系,不能逐行相加。 摘要生成和脏数据读取属于同一上层调用链。
调用方向为:文件同步请求进入 SyncFile,经 FlushFile、flushDirty 和 flush 调用 S3 putObject;AWS SDK 在签名前计算请求体摘要,读取请求体时进入 part.Read、ReadDirty 和 B 树范围查询。
因此,热点不是简单的 SHA-256 算法计算,而主要是计算摘要所需的数据读取路径。内存中的读取和整理可以持续消耗 CPU,而不产生大量网络 I/O。
五、日志关联到 SQLite WAL,但不把关联当作全部因果
客户端日志反复出现同一 inode 的读取失败。
1 | 2026-11-10T10:25:03.300+0800 ERROR fs/buffer.go:390 [ReadFile] InvalidRange, no data in backend, inode(18315880), offset(4124152), len(4096), backend fsize(4124152), buf.fsize(4276592), nNeed(520), err: data not in buffer |
这里客户端记录的文件大小比后端大 152440 字节。读取走到后端文件末尾,需要缓冲区补充数据,但没有取得所需内容。
大小暂时不同可以是待刷写状态;最终返回读取错误才是本次异常证据。 不能仅凭这条日志证明数据库已损坏。
通过挂载级文件句柄查询定位 inode,避免递归扫描整个共享目录。
1 | sudo timeout --kill-after=3s 15s lsof -nP +f -- /public_data \ |
匹配结果为一个 Python 进程打开的测试数据库 WAL 文件。脱敏后的关键字段如下。
1 | COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME |
同一进程还打开了对应的主数据库和 -shm 文件。这确定了读取失败文件的身份,但没有直接取得热点同步请求对应的文件标识,不能声称已经证明二者为同一文件。
六、停止测试进程后 CPU 不降,排除简单的新请求驱动
测试进程被停止后,旧 PID 消失,但客户端 CPU 连续三次仍为:
1 | 96.0% |
随后再次查询测试库文件组,没有发现新进程打开它们,未取得守护进程重新拉起该工作负载的证据。
但扩大检查整个挂载后,发现另一监控进程仍打开非测试数据库,并有大量数据库句柄。同一进程多个句柄不能单独证明连接泄漏,也不能排除其他工作负载。
这个进程的两个线程都处于 D 状态。内核栈的关键部分为:
1 | request_wait_answer [fuse] |
另一个线程停在关闭文件的 FUSE 路径:
1 | rwsem_down_write_slowpath |
由此确认:至少一个应用在等待 FUSE 文件同步回复,另一个线程关闭文件时也受阻。用户态的同步热点与内核等待相互吻合,但尚未按请求 ID 完成一一关联。
七、固定位置重复读取,反汇编发现零进度保护缺口
连续三次读取详细协程栈。
1 | curl --noproxy '*' --fail --max-time 5 \ |
同一个 runnable 协程的关键参数保持相同:
- 同一个
part、block和 S3 请求对象。 ReadDirty偏移为0x300000,即 3 MiB。- 传入切片长度为
0xff0,即 4080 字节。 - 执行位置在
ReadDirty、日志调用和 B 树遍历间变化。
优化后的 Go 栈参数可能不完全准确,因此这属于强线索,而不是直接测量读取返回值。
维护方源码不可得,转而只读反汇编本机二进制。本次函数地址如下,换版本后必须重新定位。
1 | objdump -d --start-address=0xb34340 --stop-address=0xb345a0 /usr/bin/polefs-client |
反汇编显示:ReadDirty 调用下层读取并返回,重复读取的循环实际在 part.Read 中。它根据返回字节数更新当前位置、剩余长度和累计读取量;当前分析的路径未见明确的零进度退出保护。
因此,如果下层返回零字节,且没有触发其他退出条件,读取位置和剩余长度可能都不变化,而循环继续。
此外,每次 ReadDirty 都会构造 Debug 日志参数,其中包含接口装箱。即使日志最终不输出,参数构造仍可能带来开销。这与热点中的分配、GC 相符,但不是唯一的分配来源。
根因
已确认的故障本质是 PoleFS 的文件同步处理长期不完成,应用因此阻塞在 FUSE 同步等待中;其主要 CPU 消耗位于上传签名前的脏数据读取与范围索引处理,并伴随明显内存分配和 GC。
证据分级如下。
| 层次 | 结论 | 状态 |
|---|---|---|
| 直接故障 | 客户端同步处理持续高 CPU,应用等待同步回复 | 已确认 |
| 具体缺陷 | 读取在固定位置无法推进,调用方缺少零进度保护而忙循环 | 高度怀疑,未直接取得 n、err 返回值 |
| 文件异常 | 测试库 WAL 出现后端与缓冲数据衔接失败 | 已确认 |
| 触发源 | SQLite WAL 的访问模式触发了当前异常同步请求 | 强关联,未证明热点请求属于该 WAL |
| 数据结果 | 数据库是否损坏、重启前哪些数据尚未持久化 | 未验证 |
SQLite 与 PoleFS 的机制适配风险
SQLite 的正确性不仅要求能读写文件,还要求可靠的锁、缓存一致性以及同步和写入顺序保障。
| SQLite 操作 | 对文件系统的要求 |
|---|---|
| 多连接访问 | 文件锁和共享状态能正确协调访问者 |
| 事务同步 | fsync、fdatasync 提供约定的持久化和顺序保障 |
| WAL 读取与复用 | 文件内容、大小、截断和缓存视图保持一致 |
| 默认 WAL 索引 | 同一主机的访问者通过映射 -shm 文件共享索引与协调状态 |
SQLite 官方明确说明,WAL 不适用于网络文件系统,同一数据库的所有访问进程必须位于同一主机。不同机器映射同名远程文件,并不等价于共享 SQLite 所需的内存协调机制。
本次未观察到跨主机访问,所以不能把故障归为已经证实的跨主机共享内存失效。同主机访问也不足以证明该远程挂载满足全部锁、缓存和同步要求。
PoleFS 本次同步路径还涉及脏范围整理、请求体读取、摘要计算和上传。SQLite 的小粒度写入、同步及 WAL 复用,可能放大这些操作的成本;但性能不匹配本身不能解释永不推进的循环,后者仍指向客户端实现问题。
不能泛化成所有 FUSE 都不能运行 SQLite,也不能声称所有远程文件系统必然损坏数据库。 实际可靠性取决于实现、配置和部署;没有明确兼容性保证时,不应将活跃 SQLite WAL 数据库放在本次这种远程共享挂载上。
解决
一、明确恢复边界
本次恢复前确认了:监控程序可以停止,相关数据风险可接受,整个 /public_data 暂时不用。
同时列出挂载使用者,确认除数据库外还有 Shell、开发工具和 Git 进程,避免只停止一个进程就直接重启整个文件系统。
1 | sudo timeout --kill-after=3s 15s lsof -nP +f -- /public_data |
客户端属于登录会话 scope,而非专用服务。未对该 scope 执行整体重启。
帮助信息确认,启动参数 -o 是 owner 字符串,不能把形如 Pid:... 的值误解成进程监控配置。
二、保存重启资料,再停止客户端
停止前,将以下内容保存到新建的 root 私有目录中:
/proc/<客户端PID>/cmdline。/proc/<客户端PID>/environ。- 原工作目录。
这些文件可能含认证信息,不能打印、公开上传或提交到仓库。
客户端停止后,确认原客户端和阻塞的监控进程都已退出。此时才进入旧挂载清理。
不能将此流程简化为直接强杀后凭记忆拼接命令。 必须先确认重新挂载所需参数和环境可用,并接受未刷写数据丢失风险。
三、清理断开的旧挂载
普通卸载失败。
1 | sudo timeout --kill-after=2s 10s umount /public_data |
1 | umount: /public_data: target is busy. |
继续检查时返回:
1 | Cannot stat /public_data: Transport endpoint is not connected |
这表示旧 FUSE 挂载还在,但对应客户端已经退出。占用可能来自原有进程的工作目录、打开文件或内存映射。
在共享挂载停用、影响已确认的前提下,执行懒卸载。
1 | cd / |
本次 findmnt 无输出,确认旧挂载已从当前命名空间移除。
懒卸载不是刷写,也不是修复。 它不会让原进程的旧挂载引用自动变成新挂载引用。原开发工具需要退出重开,Shell 需先离开旧目录,再进入新挂载。
四、按保存的参数重新启动
实际恢复使用 Python 读取保存的 NUL 分隔参数和环境,不通过 shell 拼接命令,也不打印凭据。检查挂载不存在、程序路径和原工作目录正确后,使用 subprocess.Popen 启动,并设置:
start_new_session=True,使前台客户端脱离当前终端会话。- 标准输入指向空设备。
- 标准输出和错误输出写入 root 私有日志。
- 保留原参数、环境和工作目录,不同时调整缓存或刷写配置。
这是本次应急启动方式,不等于已建立持久的服务托管和自动恢复机制。
五、验证恢复结果
重新挂载后检查:
1 | findmnt -M /public_data |
挂载类型恢复为 fuse.polefs,根目录 stat 正常返回。随后连续三次采样,每次 2 秒。
1 | 采样1: CPU=0.5% |
| 项目 | 恢复前 | 恢复后 |
|---|---|---|
| 客户端 CPU | 多次约 100%,停止应用后仍为 96%~99% | 三次为 0.5%、0.5%、3.5% |
| 常驻内存 | 约 5.5 GiB | 约 30.4 MiB |
| 线程数 | 58 | 15 |
| 文件系统状态 | 同步请求长时间不返回,应用进入 D 状态 |
新挂载根目录访问正常 |
验证范围仅覆盖客户端运行、挂载根目录和短时 CPU,未完成数据库完整性及全部业务文件读写验证。 重启使异常现场消失,但没有修复二进制中的潜在缺陷。
防复发
以下为本案后续措施,未在本次记录中验证全部实施完成。
活跃数据库退出共享挂载
| 用途 | 放置方式 |
|---|---|
| 单机监控的活跃 SQLite 数据库 | 放在确认属于本地磁盘、支持相关语义的文件系统 |
| 可丢弃测试库 | 在本地重新建库 |
| 数据库备份 | 用 SQLite 备份机制生成一致性快照,再上传 PoleFS |
| 静态数据库副本 | 可作为文件保存,需要查询时优先下载到本地 |
| 多机并发读写 | 使用客户端/服务器数据库,或由数据所在主机提供数据库访问 API |
目录叫 /data 或位于家目录,并不代表一定是本地磁盘。迁移前检查实际文件系统。
1 | findmnt -T /准备存放数据库的目录 |
不要把正在使用的主 .db 文件直接复制成完整备份,已提交事务可能还在 WAL 中。
不用弱化事务保障掩盖问题
- 改为回滚日志模式可以避开 WAL 的共享内存要求,但仍依赖正确的锁和同步,不保证绕过客户端同步缺陷。
- 不把
synchronous=OFF当作修复方案。 - 不靠扩大缓存、降低日志级别或修改刷写间隔替代读取循环修复。
- 不在故障现场盲目执行 checkpoint、全局
sync或删除 WAL。
建立托管与诊断边界
- 为客户端规划明确的服务管理方式,保留安全的启动配置和恢复流程,避免依赖遗留登录会话。
- 不贸然配置无限自动重启,应先定义未刷写数据的风险处理方式。
- 同时监控持续 CPU、GC、同步延迟、
D状态进程及重复范围读取错误。 - pprof 可能暴露内部调用栈和运行信息,应限制网络可达性;本次通过本机访问不代表监听端口仅绑定回环地址。
- 恢复资料和采样文件按敏感诊断资料管理,在不再需要时按内部凭据管理流程清理。
关键知识点总结
| 知识点 | 可复用结论 |
|---|---|
| 进程 CPU | 100% 通常表示一个逻辑 CPU,不等于整机满载 |
| 用户态高 CPU 与低 I/O | 可能是内存计算、范围查询或忙循环,不能只看磁盘和网络吞吐 |
| Go 性能分析 | 裁剪常规符号后仍可能保留 .gopclntab;解析前核对原始指令地址和二进制匹配关系 |
| pprof 统计 | flat 是自身消耗,cum 包含下游,嵌套累计值不能直接相加 |
mallocgc |
包含内存分配路径,不等于全部时间都在 GC;GC 应结合对应调用栈判断 |
| 零进度读取 | 循环必须考虑非空缓冲下读取不推进的情况,避免位置不变仍无界重试 |
D 状态 |
表示不可中断等待;本案通过内核栈确认在 FUSE 同步与关闭路径受阻,而不是仅凭状态猜测磁盘故障 |
| FUSE 断开 | 客户端退出后旧挂载可能保留,并返回 Transport endpoint is not connected |
| 懒卸载 | 移除路径上的挂载关系,不保证旧引用消失,也不会刷写未持久化数据 |
| SQLite WAL | 对同主机共享状态、锁和同步有要求,不能把远程共享文件当作普通本地文件使用 |
| 恢复与修复 | 重启后 CPU 回落证明恢复有效,不证明具体缺陷、数据完整性或兼容性问题已经解决 |
本案的长期处理方向是将活跃 SQLite 数据库迁出 PoleFS,并保留客户端读取循环的缺陷线索。PoleFS 用于备份或静态副本,不再直接承载这类活跃 WAL 工作负载。
参考资料:
- SQLite 官方:Write-Ahead Logging。用于核实 WAL 的共享内存、网络文件系统限制、同步及 checkpoint 机制。
- SQLite 官方:SQLite Over a Network, Caveats and Considerations。用于核实远程文件系统的锁、同步风险与推荐部署架构。