在维护 OLAP 引擎时，很多时候需要对引擎做系统的性能分析和优化，此时往往需要查看 CPU 耗时，了解主要耗时点及瓶颈在哪里。俗语有曰：兵欲善其事必先利其器，程序员定位性能问题也需要一件“利器”。性能调优工具（perf）能够显示系统的调用栈及时间分布，但是呈现内容上只能单一的列出调用栈或者非层次化的时间分布，不够直观。火焰图（flame graph）能够帮助大家更直观的发现问题。本文将以 Presto 为例，介绍火焰图的使用技巧。

初识火焰图

Perf 的原理是这样子的：每隔一个固定的时间，就在 CPU 上（每个核上都有）产生一个中断，在中断上看看，当前是哪个 pid，哪个函数，然后给对应的 pid 和函数加一个统计值，这样，我们就知道 CPU 有百分几的时间在某个 pid，或者某个函数上了。而火焰图（Flame Graph）是由 Linux 性能优化大师 Brendan Gregg 发明的，和所有其他的 profiling 方法不同的是，火焰图以一个全局的视野来看待时间分布，它从底部往顶部，列出所有可能导致性能瓶颈的调用栈。

火焰图整个图形看起来就像一个跳动的火焰，这就是它名字的由来。火焰图有以下特征（这里以采样CPU 火焰图为例）：

• 每一列代表一个调用栈，每一个格子代表一个函数。
• 纵轴展示了栈的深度，按照调用关系从下到上排列。最顶上格子代表采样时，正在占用 CPU 的函数
• 横轴的意义是指：火焰图将采集的多个调用栈信息，并行关系。横轴格子的宽度代表其在采样中出现频率，所以一个格子的宽度越大，说明它是瓶颈原因的可能性就越大。
• 火焰图格子的颜色是随机的暖色调，方便区分各个调用信息。
• 其他的采样方式也可以使用火焰图， 比如内存

所以，火焰图就是看顶层的哪个函数占据的宽度最大。只要有”平顶”，就表示该函数可能存在性能问题，也是我们性能优化收益最大的地方。
Java生态常见的用于perf的工具有：allocation-instrumenter、YourKit Profiler、async-profiler、JProfiler、Arthas（基于 async-profiler ）。笔者推荐使用阿里巴巴出品的 Arthas 或 async-profiler，笔者喜欢使用 async-profiler 这个 perf 工具生成火焰图，主要原因是用法简单，足够满足日常排查性能问题了。

Read More

背景

维护Presto集群，遇到了一些JVM Bug会严重导致Presto查询变慢，这里分享下Bugs表现及解决方法。

Ref Proc 耗时太久

线上Presto运行一段时间后，查询会越来越慢，打了下火焰图，发现30%的CPU都浪费在young gc上了，看了下gc log，如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

2020-12-21T20:50:15.009+0800: 4753827.928: [GC pause (GCLocker Initiated GC) (young) (initial-mark), 0.5723063 secs]
   [Parallel Time: 66.9 ms, GC Workers: 33]
      [GC Worker Start (ms): Min: 4753827940.4, Avg: 4753827940.5, Max: 4753827940.7, Diff: 0.4]
      [Ext Root Scanning (ms): Min: 26.2, Avg: 27.3, Max: 54.9, Diff: 28.7, Sum: 899.6]
      [Update RS (ms): Min: 0.0, Avg: 9.2, Max: 9.8, Diff: 9.8, Sum: 304.3]
         [Processed Buffers: Min: 0, Avg: 19.9, Max: 35, Diff: 35, Sum: 657]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.5, Avg: 11.2, Max: 13.8, Diff: 13.3, Sum: 369.9]
      [Termination (ms): Min: 0.0, Avg: 7.8, Max: 8.4, Diff: 8.4, Sum: 256.8]
         [Termination Attempts: Min: 1, Avg: 1.5, Max: 4, Diff: 3, Sum: 51]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.5]
      [GC Worker Total (ms): Min: 55.3, Avg: 55.5, Max: 55.7, Diff: 0.5, Sum: 1831.3]
      [GC Worker End (ms): Min: 4753827996.0, Avg: 4753827996.0, Max: 4753827996.1, Diff: 0.1]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.6 ms]
   [Other: 504.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 501.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.5 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.2 ms]
   [Eden: 320.0M(3264.0M)->0.0B(3392.0M) Survivors: 416.0M->288.0M Heap: 9068.7M(72.0G)->8759.2M(72.0G)]
 [Times: user=1.70 sys=0.39, real=0.57 secs]

从上面我们可以看到 Ref Proc: 501.3 ms，总共young gc耗时0.57s，而Ref Proc耗时就达到了0.5s。我们需要看下Ref Proc耗时主要在哪个地方。
我们通过配置gc参数-XX:+PrintReferenceGC，可以看到详细的Reference GC时间，并且如下图Case，JNI Weak Reference是主要瓶颈点。

Read More

背景描述

ES节点写入到5.7K，会产生比较多的reject，CPU利用率才30%，部分索引延迟在增加。如图所示：

CPU使用率在30%，但是Rejected记录达到8W行

原因分析

写入场景，CPU打不满且出现异常，根据之前Presto的经验，大概率是JVM问题。打下火焰图看下：

可以看到接近35%的CPU在做JIT Deoptimization。

JIT

为了提高热点代码（Hot Spot Code）的执行效率，在运行时，虚拟机将会把这些代码编译成与本地平台相关的机器码，并进行各种层次的优化，完成这个任务的编译器称为即时编译器（JIT）。

Read More

背景

Presto master出现jvm coredump情况，排查问题，这里记录下排查过程。

排查过程

先看下JVM Coredump日志：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42

#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (mmap) failed to map 12288 bytes for committing reserved memory.
# Possible reasons:
#   The system is out of physical RAM or swap space
#   In 32 bit mode, the process size limit was hit
# Possible solutions:
#   Reduce memory load on the system
#   Increase physical memory or swap space
#   Check if swap backing store is full
#   Use 64 bit Java on a 64 bit OS
#   Decrease Java heap size (-Xmx/-Xms)
#   Decrease number of Java threads
#   Decrease Java thread stack sizes (-Xss)
#   Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
#  Out of Memory Error (os_linux.cpp:2640), pid=22120, tid=0x00007ef9d2ed3700
#
# JRE version: Java(TM) SE Runtime Environment (8.0_144-b01) (build 1.8.0_144-b01)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode linux-amd64 )
# Core dump written. Default location: /data1/cluster-data/core or core.22120 (max size 52428800 kB). To ensure a full core dump, try "ulimit -c unlimited" before starting Java again
#

 
---------------  T H R E A D  ---------------
 
Current thread (0x00007eff5eaf5000):  JavaThread "IPC Client (1499102350) connection to presto-host.nmg01/data-node:8020 from user" daemon [_thread_new, id=28463, stack(0x00007ef9d2e93000,0x00007ef9d2ed4000)]
 
Stack: [0x00007ef9d2e93000,0x00007ef9d2ed4000],  sp=0x00007ef9d2ed2760,  free space=253k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0xacb18a]  VMError::report_and_die()+0x2ba
V  [libjvm.so+0x4ff4db]  report_vm_out_of_memory(char const*, int, unsigned long, VMErrorType, char const*)+0x8b
V  [libjvm.so+0x927d23]  os::Linux::commit_memory_impl(char*, unsigned long, bool)+0x103
V  [libjvm.so+0x927dec]  os::pd_commit_memory(char*, unsigned long, bool)+0xc
V  [libjvm.so+0x9217ba]  os::commit_memory(char*, unsigned long, bool)+0x2a
V  [libjvm.so+0x9261df]  os::pd_create_stack_guard_pages(char*, unsigned long)+0x7f
V  [libjvm.so+0xa6ffce]  JavaThread::create_stack_guard_pages()+0x5e
V  [libjvm.so+0xa797b4]  JavaThread::run()+0x34
V  [libjvm.so+0x92a338]  java_start(Thread*)+0x108
C  [libpthread.so.0+0x7dc5]  start_thread+0xc5

Read More

Presto 简介

简介

Presto是Facebook 开源的 MPP (Massive Parallel Processing) SQL 引擎，其理念来源于一个叫 Volcano 的并行数据库，该数据库提出了一个并行执行 SQL 的模型，它被设计为用来专门进行高速、实时的数据分析。Presto是一个SQL计算引擎，分离计算层和存储层，其不存储数据，通过Connector SPI实现对各种数据源（Storage）的访问。

架构

Presto沿用了通用的Master-Slave架构，一个Coordinator，多个Worker。Coordinator负责解析SQL语句，生成执行计划，分发执行任务给Worker节点执行；Worker节点负责实际执行查询任务。Presto提供了一套Connector接口，用于读取元信息和原始数据，Presto 内置有多种数据源，如 Hive、MySQL、Kudu、Kafka 等。同时，Presto 的扩展机制允许自定义 Connector，从而实现对定制数据源的查询。假如配置了Hive Connector，需要配置一个Hive MetaStore服务为Presto提供Hive元信息，Worker节点通过Hive Connector与HDFS交互，读取原始数据。

实现低延时原理

Presto是一个交互式查询引擎，我们最关心的是Presto实现低延时查询的原理，以下几点是其性能脱颖而出的主要原因。

• 完全基于内存的并行计算
• 流水线
• 本地化计算
• 动态编译执行计划
• 小心使用内存和数据结构
• GC控制
• 无容错

Presto 在滴滴的应用

业务场景

• Hive SQL查询加速
• 数据平台Ad-Hoc查询
• 报表（BI报表、自定义报表）
• 活动营销
• 数据质量检测
• 资产管理
• 固定数据产品

Read More

背景

一个Presto集群报警，显示Coordinator内存不足。看了下，发现RES内存(86.7G) > XMX(72G) + 堆外内存(10G)，然后看了下Presto UI里Resource Utilization的Non-Heap Memory Used，只用了200M。问题奇怪，pmap查看进程的内存映像信息，如下：

1
2
3
4
5
6
7
8
9
10
11
12

[presto@hostname ~/presto-current]$ pmap -x 107870 | sort -rn -k3 | head -n 10
total kB         106752092 86763996 86684760
00007fd673000000 75644928 61078708 61078708 rw---   [ anon ]
00007fd5c8000000 2654208 2537116 2537116 rw---   [ anon ]
000000000120a000 1244772 1244644 1244644 rw---   [ anon ]
00007fd5803cf000  520388  497972  497972 rw---   [ anon ]
00007fd08c836000  149720  149720  149720 rw---   [ anon ]
00007fd0e2fe2000  147620  147620  147620 rw---   [ anon ]
00007fd0d9b35000  146920  146920  146920 rw---   [ anon ]
00007fe964000000  116672  114164  114164 rwx--   [ anon ]
00007fd0612b1000  111932  111932  111932 rw---   [ anon ]

第一列表示虚拟空间地址，第二列表示该项在虚拟空间中占用的大小，第三列表示RSS，第四列表示DIRTY，第五列表示该项名称（anon是佚名的）。

jmap -heap 发现堆内内存占用正常，然后我jmap dump了一份内存，dump后发现只有700M+，应该与堆内存无关了，既然这样查找直接从堆外内存入手了。

Read More

背景

最近Presto集群又上线了几个新业务，伴之而来的是OOM很频繁，且发生时间多在早晨8点左右，线上稳定性是高优需要解决的，所以查找了下导致Presto集群OOM的原因，发现了一些问题，这里抛砖引玉下，可能其他使用Presto的用户也会遇到类似的问题。

排查过程

我给一些业务划分了不同的label，这里说明下我们把Presto引擎改进了下，可以动态将机器划分不同的label，这样SQL查询时候指定不同的label，SQL调度时只根据指定的label查找机器即可。之后发现一个业务方的SQL会导致集群OOM。具体表现为，多次Full GC，之后OOM，看GC日志第一感觉应该是有内存泄露。

我通过审计日志（之前通过event-listener实现了个日志审计模块）拿到OOM时2K左右条SQL，发现SQL都是简单的SQL，类似这种：

1
2

SELECT * FROM table WHERE year='2020' AND month='06' AND day='01' LIMIT 10;

根据SQL，我猜测可能以下2种原因导致了OOM：

• 查询的表存在Hive视图（我让Presto支持了Hive视图）
• 异常SQL触发了内存泄露

Read More