ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

明明写了 defer Close,为什么日志任务还是报 too many open files?

明明写了 defer Close,为什么日志任务还是报 too many open files?

明明写了 defer Close,为什么日志任务还是报 too many open files?

目录

  • 明明写了 defer Close,为什么日志任务还是报 too many open files?
    • 1. 引言:文件少时好好的,多跑一些就出错了
    • 2. 业务场景:一批文件逐个处理,为什么会一起占着资源?
    • 3. 从代码入手:defer 写了,为什么本轮没有关闭?
    • 4. 实战演示:把问题缩小,看看文件到底有没有关
      • 第一步:用受控输入代替真实文件
      • 第二步:保留相同工作,只改变关闭方式
      • 第三步:看失败现场,再看返回后的变化
    • 5. 修复方式:让关闭跟着单个文件走
    • 6. 对比表:提高限制与及时关闭,结果有什么不同?
    • 7. 带回项目:三个地方值得顺手检查
      • 先看这个文件究竟要用到什么时候
      • 再看批次变大时,什么东西在增加
      • 最后看错误分支有没有绕过释放
    • 8. 回归时,我会再看哪些结果?
    • 9. 小结与复现入口

1. 引言:文件少时好好的,多跑一些就出错了

写一个日志批处理任务,流程并不难:扫描目录,打开文件,逐行解析,最后生成统计结果。打开成功后顺手写上defer f.Close(),看起来连错误退出时的清理也照顾到了。

先拿几份日志试一下,能跑。再换一批,还是能跑。可一旦积压文件多了,或者要补算一段历史数据,任务就可能在处理中途停下来,报一句too many open files。

这时翻代码,Close 明明写着;等函数退出再去看,打开的文件数量还恢复了正常。很容易让人犯嘀咕:是不是系统限制太小?是不是某个文件有问题?难道 defer 没有执行?

先抓住一个问题往下走:那些已经读完的文件,到底在哪一刻关闭?这个时间点想清楚了,后面的现象就能连起来。

下面以定时扫描日志目录的任务作为业务背景,沿着代码、故障现场和修复结果一步步说明。背景是为了方便理解,具体失败次数和图表来自保存的本地验证,没有把示意场景当作一份真实线上事故记录。

2. 业务场景:一批文件逐个处理,为什么会一起占着资源?

假设我们每天都要处理一些按服务、机器、时间分开的日志。任务先固定本批文件清单,然后顺序打开每个文件,统计请求数、错误数等信息,再把分文件结果合并起来。

正常情况下,一个文件读完,后面只需要它的统计结果,不再需要这个文件继续保持打开。处理完当前文件就关闭,再打开下一份,和这个需求是对得上的。

但如果把 defer 放在外层批处理函数里,每一轮只是在登记关闭操作,文件本身还没有关。任务继续处理下一份时,前面的文件也仍然占着资源。

先看一下两种关闭时机放回业务流程后的区别:

这里反复说的资源,就是文件描述符,简称 FD。可以先把它理解成进程使用一个已打开资源时拿到的编号。打开文件需要占用,关闭以后才能交还。

目录里有一千份日志,并不意味着程序必须同时持有一千个打开的文件。真正影响这类问题的是,程序此刻还把多少个文件开着。输入总量与同时占用,得分开看。

FD 也不只对应普通文件,连接、管道和运行时句柄同样可能占用它。因此到现场排查时,不光要数有多少,还要看它们分别指向哪里。本文先固定其他活动,只观察重复打开文件带来的变化。

3. 从代码入手:defer 写了,为什么本轮没有关闭?

先把日志解析拿掉,只留下打开、登记关闭和继续循环。下面是原验证程序的 bad_linux.go,s.opened用来记录打开后的资源状态:

funcbadDeferred(s*state)error{fori:=1;i<=s.iterations;i++{f,err:=os.Open("/dev/null")iferr!=nil{returns.failure(i,err)}deferf.Close()iferr:=s.opened(i);err!=nil{returnerr}}returnnil}

留意defer f.Close()所在的函数。它属于badDeferred这次函数调用,所以要等badDeferred返回,才开始执行已经登记的关闭。一次 for 循环结束,不等于这个函数返回。Go 规范说明了这个执行时机。

不用急着看所有文件,先把前三轮在脑子里走一下:

执行位置实际发生的事仍然开着的工作文件
处理完第一个文件登记 Close,进入下一轮第一个
处理完第二个文件再登记一个 Close第一个、第二个
处理完第三个文件继续登记,继续循环前三个
整个函数返回执行此前登记的 Close这时才逐个关闭

所以,代码确实安排了清理。只是清理所在的时间点,比每个文件真正需要使用到的时间更晚。外层循环越长,同时留在打开状态的文件就可能越多。

如果某轮用了 continue,也只是跳到下一轮,不会触发这个外层函数的 defer。判断时要顺着真实的调用和返回关系看,不能因为代码放在同一对大括号里,就默认它会在这一轮结束时执行。

把同一个 defer 挪到循环体的最后,也不会改变这一点。它仍然登记在外层函数里,等待的还是外层返回。检查这类代码时,先找到负责返回的那个函数,比反复调整语句在循环中的上下位置更有用。文件已经读完,是业务上的完成;函数已经返回,才是这里触发 defer 的边界。

读到这里,应该能理解为什么文件少时不容易暴露:还没有碰到限制,整个函数就返回了,积累的关闭操作随后也都执行。换成更大一批输入,同样的代码就可能先在中途耗尽。

4. 实战演示:把问题缩小,看看文件到底有没有关

接下来不必真的准备上千份日志。我们只验证一个动作:反复打开文件,比较不同的关闭时机。日志内容、解析规则、汇总算法,都暂时移开。

第一步:用受控输入代替真实文件

小程序计划执行 512 次os.Open("/dev/null")。这个目标已经存在,既不需要创建大量普通文件,也没有靠写入数据把磁盘填满;打开它仍然要取得 FD,正好用于观察占用。

再把被测进程自己的软限制降到 64,方便用较少的操作看到边界。另一组设成 128,用来判断多给一些位置以后会怎样。程序只调整自己的限制,硬限制保持继承值,没有修改宿主的全局配置。

在 Lab 004 的运行说明中,scripts/reproduce.ps1与sh scripts/reproduce.sh提供完整入口。程序使用 Linux 构建标签;Windows 上通过 Docker 运行这一组验证。

第二步:保留相同工作,只改变关闭方式

三种实现分别是:循环期间先不关、循环内登记 defer、每轮工作结束就 Close。前两个版本也会在退出时清理,便于验证完成后交还资源,但故障现场会先保存下来。

第一种实现还把成功打开的文件引用保存在切片里。这样可以明确说明它们仍由程序持有,不会把等待对象回收当作本轮的关闭策略。我们关心的是工作阶段有没有及时释放,而不只看进程最终怎样结束。

第三步:看失败现场,再看返回后的变化

软限制为 64 的第一份历史运行里,循环内 defer 的版本在第 58 次打开时失败。原始 stderr(本地归档)留下了:

open /dev/null: too many open files

同一进程的 stdout 还保存了出错与清理后的事件。下面把两条事件的指定字段并排展示,方便直接比较:

开始时进程已经占用 7 个 FD,成功打开了 57 个工作文件。到了下一次打开,清单正好占满本次允许的位置,FD 数为 64,实际错误是 Linux 的 EMFILE,errno 为 24。

再看右侧,函数返回以后,FD 数又降回 7。defer 并没有失效,它在返回时做了清理;但清理发生得太晚,前面那次打开失败已经真实发生。

这就是开头那个现象最容易被漏掉的地方:如果只在任务执行前后各看一眼,两个时间点都正常,中间的故障就可能被忽略。保存失败时的清单,才知道当时占用到了哪里。

5. 修复方式:让关闭跟着单个文件走

确认原因以后,修改可以先保持简单:当前文件处理完,就结束对它的使用,然后再处理下一份。验证程序没有调大限制,也没有少执行操作,只移动关闭时机。

完整代码见 good_linux.go,原核心循环如下:

fori:=1;i<=s.iterations;i++{f,err:=os.Open("/dev/null")iferr!=nil{returns.failure(i,err)}iferr:=s.opened(i);err!=nil{f.Close()returnerr}iferr:=f.Close();err!=nil{returnerr}ifi%64==0{iferr:=s.emit("after-close",i,0,"",false);err!=nil{returnerr}}}

本地每轮工作是打开文件并记录资源状态,做完就 Close。对应到日志任务,就是读取、解析并保存好这个文件的统计结果以后,关闭输入文件。后面的汇总如果只需要统计结果,就不必再持有文件本身。

想继续用 defer,也完全可以把“处理一个文件”拆成一个小函数。外层只负责遍历清单;内层打开成功后登记 defer,读完这个文件就返回。下一次外层循环开始时,前一个文件已经结束清理。

关键在于这个小函数确实完成了单文件工作。如果它只是启动一个后台 goroutine 就马上返回,而后台还要读文件,defer 又可能关得过早。选择释放时机之前,要先确认最后一个使用者是谁。

出错分支也要一起看。打开失败,没有这次成功打开的文件可关;打开成功后读取或解析失败,仍然需要交还文件。正常路径能关,不代表每条提前返回的路径都已经覆盖。

Close 本身的错误也应按业务需要保留。示例正常路径检查了关闭错误,观测失败分支属于受控程序的简化处理;将它接入真实解析器时,还需要整理读取、解析和关闭各自的错误,不能把这个小循环直接当成所有异常场景的模板。

6. 对比表:提高限制与及时关闭,结果有什么不同?

三种写法、两档限制,每组各运行十个独立 Linux 进程,共六十次。下面把正文历史运行的结果放在一起:

软限制关闭方式成功打开次数首次失败尝试工作中观测峰值 FD函数返回后 FD
64循环期间不关闭5758647
64循环内 defer5758647
64每轮及时 Close512无87
128循环期间不关闭1211221287
128循环内 defer1211221287
128每轮及时 Close512无87

这张表先看两处。限制从 64 改成 128,错误版本多成功了 64 次,失败位置也从 58 推迟到 122。关闭方式没有变,因此它只是获得了更多积累空间,依然没有完成计划中的 512 次。

再看每轮及时关闭的版本。它在两档限制下都完成 512 次,观测峰值为 8,返回后是 7。工作量保留了,额外同时持有的工作文件只有一个。

每组十次的数值完全重合。红柱表示工作期间观测峰值,绿柱表示函数返回后的状态;两个分面的纵轴范围不同。

如果只看绿柱,三种实现最后都回落,似乎差不多。把红柱、失败位置和完成量加上,差别就很清楚了。判断修复效果,不能只要求“结束以后没残留”,还要问“中间有没有失败,原本的工作有没有完成”。

7. 带回项目:三个地方值得顺手检查

先看这个文件究竟要用到什么时候

读完一份日志并生成独立统计后,后续通常只需要结果。此时继续持有输入文件,就比业务需要的时间更长。可以把打开、读取、解析、关闭放到同一段容易检查的单文件处理里。

如果后续步骤还需要读取文件,或者结果只是依赖文件继续工作的一个对象,就不能看到“解析函数返回”便认定文件已经没用了。释放得晚会积累,释放得早也会破坏工作;两边都要围绕实际使用者判断。

再看批次变大时,什么东西在增加

本例是顺序处理,输入文件多了,并不需要让已经处理完的文件继续打开。检查同一批任务中的已处理数量和活动 FD,有助于分清正常进度与不必要的累积。

真实服务还有连接和其他长期资源,不能照搬实验里的七八个作为固定要求。应结合 FD 指向的目标、创建位置和任务阶段,判断多出来的部分由谁持有。

最后看错误分支有没有绕过释放

空文件、读取中断、非法日志、汇总失败,都可能让函数从不同位置返回。明确每条路径打开了什么、交给了谁、在哪里关闭,比仅仅全文搜索 Close 更有用。

如果增加重试,也要确保上一轮的文件资源已经按要求处理。否则一次失败后又打开同一个文件,资源问题可能被重试放大;同时还要避免把已经成功处理的文件重复计入汇总。

例如任务在处理中途报错,前面一些文件的统计可能已经写入结果表。整批重跑之前,要先确认这些结果怎样标记完成,重试是接着未完成的部分处理,还是允许安全地覆盖旧结果。资源耗尽说明当前一轮没能完成,不代表此前所有业务动作都没有发生;恢复任务时仍要核对这层语义。

8. 回归时,我会再看哪些结果?

修复后先用同一份清单重新运行,核对完成文件数、失败文件数和统计结果。不能只因为错误不再出现,就宣布一切正常;如果某个修改让任务提前停止,打开次数少了,占用当然也可能下降。

再观察任务执行过程。已经读完的文件是否从打开清单中消失?错误出现的当下能不能保留现场?停止新增工作以后,资源是否按设计回落?过程和终点连起来看,才能解释修复改变了哪一段。

采样时机也会影响看到的现象。如果只在任务开始和结束时记录一次数量,中间的高峰自然可能被跳过。排查期间,可以在失败分支保存现场,再用过程记录辅助观察增长;需要长期保留哪些指标,则结合开销与任务频率选择。记录不一定越密越好,但至少要能回答那次失败发生时,哪些资源仍然没有交还。

如果处理一份日志还会同时创建输出文件、打开另一个索引文件,也要把这些资源列出来一起核对。输入文件关闭了,不等于同一轮里的其他文件也已经关闭。先说明每个打开操作由谁负责收尾,再检查正常与异常路径,才能避免只修好了最显眼的那个入口。

如果以后改成并发处理,合理峰值会随着同时打开的文件数变化。这时除了每个文件及时关闭,还要给并发安排上界,为进程原有的连接等资源留出位置。当前顺序处理的峰值不能直接当作并行版本的容量目标。

提高限制也有合理场景:如果这些资源确实需要同时存在,并且有明确的容量预算,就要为它们提供足够空间。但在本例里,文件已经处理完,却还等外层返回才关,先纠正持有时间才是对准原因的修改。

错误类型同样别混。本文实际捕获的是进程级 EMFILE;系统级打开文件资源不足涉及 ENFILE,空间不足还可能涉及 ENOSPC。现场应先保留原始错误,再沿相应资源检查。Linux open(2)有对应说明。

这一组没有测解析吞吐、CPU、RSS 或请求延迟。它验证的是关闭时机与工作阶段耗尽之间的关系。性能有没有变化,可以在功能与资源行为正确之后,针对实际负载另外测量。

9. 小结与复现入口

主要问题:写了关闭操作,还要看它安排在什么时候。日志批处理里,单个文件已经读完,外层任务却还要继续很久,就应该检查是否把两者的结束时间混在了一起。

遇到类似问题,可以沿三件事往下查:资源何时取得,最后谁还需要使用,何时真正交还。再用失败现场和工作完成量验证判断,就不容易被“任务退出以后又正常了”这个现象带偏。

这也能与第三篇的日志汇总偏差连起来看:文件处理结果要正确,处理中使用的资源也要按时释放。最后能生成一份报告,不能替所有中间过程作保证。

想自己再跑一遍,完整程序和说明在 Lab 004。它用受控的打开操作说明问题,业务场景中的文件规则、错误处理和重试仍要结合自己的项目确认。

公开代码:实验目录 · 运行入口。固定提交c3d8b36a,原始日志、协议等本地归档没有上传 GitHub。

RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进