当前位置：首页 > backend >正文

Erlang 利用 recon 排查热点进程

backend 2025/9/5 18:15:39

原因

erlang 进程在windows系统下持续占用 20% - 25%，怀疑 CPU 异常空转，于是进行排查。排查较快，但过程比较经典，特此记录学习。

工具

recon, recon_trace

过程

1、找出最繁忙的进程

执行指令 recon:proc_count(reductions, 10).，找出最繁忙的 10 条进程

recon:proc_count(memory, 10). 可以检查内存
user_default 可以定义 tred(10).和 tmem(10).来缩短指令

也可以使用 etop:start(). 跟 etop:stop().指令进行调试，后者的优点是自动进行了 reduction的间隔delta跟踪，相较于recon输出的是累计 reduction会更加符合直觉。
很快可以抓到高频消耗reduction的进程，进入下一步。

2、找出进程当前的堆栈，确定卡点

执行指令process_info(<0.471.0>, current_stacktrace).，输出

{current_stacktrace,[{gen_server,loop,7,[{file,"gen_server.erl"},{line,1001}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,241}]}]}

多试几次，堆栈都是如此。这说明当前进程并无特别卡点，而是正常在 gen_server 这级接收信息、执行逻辑。大概锁定问题在于信息处理过于频繁，但是也没有造成可观测的消息堆积，进入下一步。

3、确定进程后查看当前热点函数

使用 recon_trace模块，执行recon_trace:calls({'_', '_', '_'}, 20, [{pid, <0.471.0>}]). 指令，本意抓取20次调用函数，并且查看调用时间，发现 recon 拒绝了，因为 {M, F, A} 不可同时为'_'通配，因为recon认为不安全，会导致卡滞。
结合上一步的特点（处理消息频繁），所以把Mod设置在 gen_server 这一层。在我的代码中，这一层是 ms_tbllog_gs。指令修改为recon_trace:calls({ms_tbllog_gs, '_', '_'}, 20, [{pid, <0.471.0>}]).。很快抓取结果如下：

11:11:35.568000 <0.471.0> ms_tbllog_gs:handle_info(sync, #{table=>tbllog_level_up, handler=>tbllog_level_up,batch_len=>2097152})
%% 重复18次...
11:11:35.594000 <0.471.0> ms_tbllog_gs:handle_info(sync, #{table=>tbllog_level_up, handler=>tbllog_level_up,batch_len=>2097152})