游戏服务器工程实践六:lua cpu 和 heap profiling
游戏服务器时常需要做一些 profiling 工作,c/c++ 部分可以使用 gperftools(Google Performance Tools)进行 profiling,而 lua 并没有一个业界权威的工具,在 github 找到的也都不能满足我的要求。
于是我自己做了一个项目 https://github.com/antsmallant/luaprof,实现了想要的效果:开销低,又能相对精确地捕捉到较大的热点。
本文主要介绍 profiling 的机制,以及 luaprof 的功能和设计。luaprof 虽然大部分是 ai coding 出来的,但其思想是经过比较长期的摸索和实践才得来的,也在生产项目上得到了实践。对于大热点的采样挺准的,并且开销很低,远低于那种基于 tracing 机制的 profiling 库。
我们这里说 heap profiling,是比较精确的说法,因为我们确实只是对堆(heap)内存进行 profiling 而已,并不涉及栈内存。
1. profiling 有哪几种机制?
首先说一说 profiling 的机制,对 CPU profiling 而言,常见的数据采集方式有两类:sampling(采样)与 tracing,后者在有些地方也称为基于事件的插桩(instrumentation-based profiling)。
GNU 的官方 gprofng 手册直接有一节叫 “Sampling versus Tracing”:它把 sampling 的对立技术称为 tracing,并定义为“向目标程序插入特定调用来采集信息”。
sampling:周期性记录当前 PC 或调用栈,结果是统计意义上的热点分布。
tracing:通常是利用插桩(instrumentation)方式,在函数调用、返回等事件发生时执行 hook,精确记录调用次数和持续时间。
tracing 和 instrumentation 的关系可以这样理解:
| 词 | 它描述什么 |
|---|---|
| instrumentation(插桩) | 怎么取得事件:在函数入口/退出、系统调用、业务点插入或启用 probe/hook。可静态编译插桩、动态二进制插桩、VM hook 等。 |
| tracing(追踪) | 怎样记录和观察事件:通常保留带时间戳、顺序、参数的事件流。它常由 instrumentation 产生。 |
相关资料:
- GNU gprofng:Sampling versus Tracing
- GNU gprof:采样误差与函数插桩实现
- GCC:Program Instrumentation Options
- Lua 官方手册:
lua_sethook的 call / return / line / count 事件
2. github 上若干 lua profiling 项目
github 上有不少做 lua profiling 的项目,但研究下来,都有一些局限,不能满足我的要求。
2.1 plua
项目地址:https://github.com/esrrhs/pLua 。
局限1:抓不到 c 栈帧
见这个issue:无法抓到 c 栈帧 #9。
它是使用 LUA_MASKCOUNT 去 sethook 的,采样时钟到的时候,在下一个 vm 指令去抓栈,此时抓到的只是 lua 栈。像 tonumber / print 这种简短的 c 函数抓不到,问题还不是特别大,但一些执行时间长的 c 函数没抓到,对于整个结果的影响就很大了。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
static void SignalHandlerHook(lua_State *L, lua_Debug *par) {
lua_sethook(L, 0, 0, 0);
LLOG("Hook...");
if (gRunning == 0 || (gSampleCount != 0 && gSampleCount <= gProfileData.total)) {
LLOG("lrealstop...");
lrealstopsafe(L);
return;
}
CallStack cs;
get_cur_callstack(L, cs);
gProfileData.callstack[cs]++;
gProfileData.total++;
}
static void SignalHandler(int sig, siginfo_t *sinfo, void *ucontext) {
lua_sethook(gL, SignalHandlerHook, LUA_MASKCOUNT, 1);
}
局限2:不支持多线程
见这个 issue:接入到lua 服务器,崩溃 #8。
它的实现是:
- 全局只有一个
gL、一个gRunning、一个SIGPROFhandler。 ITIMER_PROF统计整个进程的 CPU 时间,不是某个 Lua VM 所在线程。- 信号可能在别的线程到达,但它仍对那个全局
gL设置 hook。
pLua 使用 ITIMER_PROF 作为周期 CPU 定时器;该定时器每次到期时,内核向进程投递 SIGPROF,pLua 注册的 SIGPROF handler 再为 Lua VM 设置 LUA_MASKCOUNT hook。
也就是说:
1
2
ITIMER_PROF 定时器的种类/计时依据
SIGPROF 该定时器到期时投递的信号
Linux 的 setitimer(2) 明确规定:ITIMER_PROF 统计进程的用户态与内核态 CPU 时间,每次到期产生 SIGPROF。man7 setitimer(2)
pLua 源码确实同时出现两者:它用 sigaction(SIGPROF, ...) 注册 handler,再用 setitimer(ITIMER_PROF, ...) 启动定时器;handler 中设置 LUA_MASKCOUNT hook。pLua 源码
另外,源码中报错字符串写的是 sigaction(SIGALRM) failed,但实际调用参数是 SIGPROF;这是日志文案的笔误,不是它真的注册了 SIGALRM。
2.2 lsg2020/luaprofile
项目地址:https://github.com/lsg2020/luaprofile 。
这个更早是追溯到 https://github.com/lvzixun/luaprofile 。
lsg2020 另外有个项目: https://github.com/lsg2020/swt ,也是基于 https://github.com/lsg2020/luaprofile 去做的一个火焰图。
局限:使用 tracing 机制
tracing 方式,对于每个调用都做了 profiling,profiling 这个动作本身就特别耗时,对结果干扰很大。
2.3 spin6lock/skynet_systemtap_set
项目地址:https://github.com/spin6lock/skynet_systemtap_set。
局限:可能出现较大统计偏差
当前这个实现只是采样对于 c lua api 的调用,如果一个运行1秒的纯lua函数只调用了几次 api,而1个运行100毫秒的lua函数调用了几百次api,则统计结果完全不准。
理论上,用 stp 或 ebpf 也能做到接近我这次做的 luaprof 的统计精度,但工程实现难度会很高,完整实现下来比 luaprof 费劲得多。
ebpf 能提供按 cpu 时间触发的采样,用 perf_event_open 指定线程的 tid、设 cpu = -1,事件会跟随线程在不同 cpu 上运行;可设置采样频率,再把 ebpf 程序挂到这个 perf event 上。ebpf 也能读取用户态数。难点在于把采样正确还原成 lua 调用栈,并在 skynet 的 worker 之间持续识别目标 service。
3. 为什么 sampling 机制能够 work?
sampling 就是用少量观测估计整体分布,背后是概率论和统计学中的抽样估计和大数定律。样本越多,随机误差通常越小。
能解决什么问题
- 发现稳定的大热点。
不能解决什么问题
- 锁相问题。如果采样频率是固定的,则可能遇到锁相的问题,比如某个周期执行的函数,刚好不在采样频率上,那么即使它频繁发生,也不会被采样到。样本多只能压低随机误差,不能自动消除系统偏差。
- 稀有事件。如果某状态只占0.1%的时间,那么采样1000次,那么它仍有37%的概率不被看到。
4. luaprof 介绍
4.1 接入与使用
详细的说明: luaprof 项目接入指南 ,里面已经包含了接入和使用说明了。
需要指出的是,为了实现安全的采样,对 lua 源码做了一些小修改,luaprof 对于 lua 近期的各个版本都做了相应的 patch,可以直接使用,如果是旧一些的版本,就需要参照新版本的 patch 进行相应的修改。
skynet 的 lua 源码也同样需要做类似的修改,luaprof 也有相应的 patch。
使用很简单,就几个 api:start , stop, write,比如 cpu profile 就这样:
启动
1
local cpu_recorder = profile.cpu.start()
停止并写结果
1
2
3
local cpu_result = cpu_recorder:stop()
local save_path = "xxx_cpu.pb.gz"
cpu_result:write(save_path)
具体可以参考上面提到的 luaprof 项目接入指南 ,或这个 example 代码: luaprof/blob/master/examples/thread_vm/profile.lua 。
4.2 核心功能
| 核心功能 | 能回答的问题 | 主要能力 |
|---|---|---|
| CPU 采样 | CPU 主要消耗在哪里? | 按线程 CPU 时间采样,区分 Lua、CFunction、GC 和 host 状态,保留 Lua 调用栈与行号 |
| 内存分配采样 | 哪些调用路径产生了大量分配? | 估算累计分配字节数 alloc_space 和分配次数 alloc_objects |
| 存活内存统计 | 本次采集期间分配的内存,哪些在停止时仍未释放? | 开启 track_free 后,统计 inuse_space 和 inuse_objects |
| Skynet service 分析 | 指定 service 的热点是什么? | 跟随 service handle 跨 worker 迁移,排除其他 service、排队和 sleep 时间 |
| 结果分析与质量检查 | 如何查看热点、判断结果可信度? | 导出 pprof、folded stacks,生成火焰图,并提供丢样、溢出、截断等统计 |
CPU 和 memory recorder 可以同时运行,也可以独立启动、停止。停止后得到冻结的 result,再通过 stats() 查看统计、通过 write() 导出。
1、cpu 采样支持传统的每线程一个 lua vm 的
1
2
make example-thread-vm
go tool pprof -top build/thread-vm-cpu.pb.gz
也可以按行去归因,但这会显得过细了:
1
go tool pprof -lines -top build/thread-vm-cpu.pb.gz
说明:如果是每线程多 lua vm(skynet 除外),则目前不支持,直接使用会出现统计不准的问题,主要是暂时还没遇到有传统项目是每线程多 vm 的,遇到了再说吧,改造难度中等。
2、cpu 采样也支持 skynet 按 service 采样
运行示例:
1
2
make example-skynet
go tool pprof -top build/skynet-cpu.pb.gz
skynet example 是这个 service : luaprof/examples/skynet/luaprof_demo.lua 跑了采样。
同样也可以按行去归因,只需要改一下 pprof 的参数就行,这里不展开了。
3、内存采样支持传统的每线程一个 lua vm 的
运行示例:
1
2
make example-thread-vm
go tool pprof -sample_index=alloc_space -top build/thread-vm-heap.pb.gz
也可以按行去归因,不过同样会显得过细:
1
go tool pprof -sample_index=alloc_space -top -lines build/thread-vm-heap.pb.gz
alloc_space 只是一个维度,我们也可以使用 alloc_objects 来观察分配的对象个数:
1
go tool pprof -sample_index=alloc_objects -top build/thread-vm-heap.pb.gz
我们的 example 做内存打开了 heap_use 开关,
4、内存采样也支持 skynet 按 service 采样
运行示例:
1
2
make example-skynet
go tool pprof -top build/skynet-cpu.pb.gz
4.3 主要设计
cpu 采样的原理
heap/memory 采样的原理
线程级 timer
使用实际 cpu 时间消耗来计时,而不是墙钟(wall time),避免 sleep 也被采样。
cfunction 延迟
安全点写入
skynet 支持按 service 做 profiling
skynet 底层起了若干个 worker 线程,service 运行时可能在其中任一个 worker,所以实现上每个 worker 线程都设了 thread timer,timer 到期的时候会判断当前线程是否运行着需要采样的 service,如果不是,则跳过 handle。
pprof 格式
- 结果保存为 pprof 格式,把采样的一些关键信息也附带上了,比如 overrun 之类的信息。
- 结果可以直接用 pprof 查看,可以生成 txt 报告,也可以生成 svg 报告。
4.4 细节处理
关于 overrun
overrun 指 cpu timer 已经多次到期,但系统只送达了一次采样信号,其余到期次数没有独立的执行现场。
luaprof 的处理原则是:记录这些缺失次数,但不把它们补算到某个函数上。
Linux 的 POSIX timer 对每个 timer 最多保留一个待处理。这个信号尚未送达时,timer 再次到期,就累计 overrun;送达时通过 siginfo_t.si_overrun 告诉我们额外到期了多少次。即使使用实时信号,也有这个限制的。 linux timer 语义
例如,配置 1000HZ,即每消耗 1ms 线程 cpu 时间采样一次:
1
2
3
4
5
线程 CPU 时间 1ms 2ms 3ms 4ms
timer 到期 ↓ ↓ ↓ ↓
通知状态 信号待处理,后续到期累计 overrun
最终送达 一次信号
si_overrun = 3
这里有4次到期,但只有一次信号送达。
常见成因包括:
- 信号暂时被屏蔽:线程继续消耗 CPU,timer 继续到期,但无法进入 handler。
- 内核到期检查和信号送达有延迟:CPU timer 的处理涉及内存 tick 等路径,配置间隔很短时,一次检查可能跨过多个周期。
- 信号处理期间继续消耗 CPU:同一个信号通常在 handler 执行期间被屏蔽;频率过高或处理过慢会增加积压机会。





