实时计算引擎处理延迟的排查过程
作者: 大圆那些事 | 文章可以转载，请以超链接形式标明文章原始出处和作者信息
实时计算引擎在处理实时数据时，要保证新到来的数据被及时得到处理。例如，对于网站的访问日志数据，假设每一分钟有一个日志文件，那么实时计算引擎必须满足能够在一分钟之内处理完这一分钟的日志数据文件，否则会导致日志文件堆积而不能被及时处理。前几天，量子后端团队排查了一次实时计算引擎出现的处理延迟故障，其中使用到了ltrace和strace工具，在这里和大家分享一下。
1. 故障描述
当天由于大量突发异常数据的到来，导致实时计算引擎在处理每分钟日志文件时的速度大幅下降，出现明显的延迟现象，表现为平均每处理1分钟文件需要2分钟甚至更长的时间，最长可以到5分钟，进而导致了日志文件堆积而不能被处理。
2. 故障分析
实时计算引擎在处理日志文件时，采用顺次读取各分钟文件中的日志记录到内存中进行计算的方式（compute过程），因此引擎在每处理完1分钟文件时，需要进行日志的轮转切换（rotate过程）。
实时计算引擎采用全内存计算的方式，在处理每分钟日志文件和轮转时，都会进行频繁的内存操作：内存的申请和释放（内存管理使用的是glibc库）。在整点轮转（rotate过程）时，会释放掉相当一部分计算过程不再需要的内存。
经过统计后发现，实时计算引擎在处理故障当天各分钟日志文件时的compute时间和rotate时间有如下的规律：
(1) 每分钟日志文件的处理时间（compute时间），整点轮转之后的前半个小时日志（如10:00~10:30的日志），每处理一分钟日志一般都需要超过1分钟的时间才能处理完；半点之后的日志（如10:31~11:00的日志），每处理一分钟日志一般只需要十几秒到一分钟以内。
(2) 每分钟日志文件处理后的轮转时间（rotate时间），整点轮转时间耗时会比其他时间长很多，整天结束时的轮转时间最长。
以上统计信息提示我们，实时计算引擎的处理延迟就是发生在了整点rotate轮转之后的前半个小时内，后半个小时基本可以恢复到正常水平：处理1分钟日志文件只需要不到1分钟时间。可见，引擎的处理延迟和整点rotate有一定的联系，是被整点rotate所触发产生的。具体是什么原因导致的，还需要进一步对实时计算引擎发生处理延迟时的状态进行跟踪才能确定。
3. 故障排查
考虑要具体跟踪到实时计算引擎程序在发生故障时的执行情况，实时得到引擎在做什么操作（如库函数调用、系统调用）时最耗时，才能定位到导致引擎处理延迟的根本原因，这里讨论后选择strace和ltrace工具进行排查过程。其中，strace可以跟踪系统调用情况及耗时情况，ltrace可以跟踪库函数调用情况及耗时情况。
3.1 排查过程
在测试机上，使用线上版本的实时计算引擎程序，重跑触发故障的日志数据，当整点rotate触发引擎发生处理延迟时，开始使用ltrace和strace工具跟踪引擎当前的运行状态，统计引擎在系统调用和库函数上的调用时间开销。
- 跟踪库函数的耗时情况：ltrace -fp pid -T –c
- 跟踪系统调用的耗时情况：strace -fp pid –T –c
3.2 排查结果
以下是对排查过程的结果分析：
- 测试发现在整点rotate时，CPU 100%用在了用户空间，日志处理到整点时，系统的空闲内存已经被用尽，所有的内存被page cache或者进程使用。
- 使用ltrace跟踪发现，malloc较大内存块时（如大于1000字节），其执行时间较长，大约2~4秒钟，这个是ltrace统计到的耗时最多的库调用，引擎的大部分时间都花费在了malloc上。
- 使用strace跟踪系统调用，发现在malloc内存的时候，没有任何系统调用发送到内核空间。再加上CPU 100%消耗在用户空间，基本上可以判断，malloc的时间都耗费在glibc的内存管理模块中，推测可能是由内存碎片引起的，当程序申请分配较大内存块时，它会整理内存碎片从而形成较大的内存块分配给计算引擎。
- 为 了进一步验证第3步的结论，我们使用google的tcmalloc进行测试（export LD_PRELOAD="./libtcmalloc.so"）。测试结果发现使用tcmalloc后，实时计算引擎恢复正常，每个日志文件的处理时间从几分钟降到几秒钟，整点rotate时间也从十几分钟降到30~40秒。
4. 解决方法
由于本次实时计算引擎的处理延迟问题最终定位到是出在glibc的内存管理上，一个简单的解决方案是用tcmalloc替换glibc。但是从长远来看，是否需要我们自己实现内存管理模块，取决于人力资源情况和tcmalloc的发展情况。
5. 经验教训
- 避免只依赖于经验进行故障排查，要结合代码实现逻辑和故障现场环境进行分析。
- 数据才是最真实可靠的，包括现场收集到的数据，历史的数据，这些都是分析定位故障的重要依据。
- 没有哪种工具是通用的，必须结合实际情况，选择使用合适的调试跟踪工具，积累相关使用经验。
最后，感谢这次一起排查问题的同事们：太奇、澄苍、民瞻、渊虹。你们都很牛！
