玖叶教程网

?导读：大家好，我是 Pivotal Greenplum 团队的一名售后工程师。平时会帮助我们的全球的商业用户解决数据库的相关的问题。在实际工作中，我们经常会被数据库管理员问及：“我的 SQL 跑了很长时间没有结果，我该怎么样排查?”“数据库某一条 SQL 卡住了怎么办？” 今天，我们将就这个内容做一些分析和总结。

一般来说，SQL 卡住或者运行时间长这类常见问题的原因如下：

1. SQL 因为死锁原因，并没有执行
2. SQL 因为 Resource Queue 或者 Resource Group 没有资源而等待
3. SQL 因为在某一个 segment 或者某个机器的问题而卡住

针对原因1和原因2，在 Greenplum 中，我们可以通过查询 pg_locks 表和 gp_toolkit/GPCC 中资源队列/组的状态来排查。而原因3，往往是非常棘手又不得不解决的。下面我们将详细介绍在排除了死锁和资源组/队列问题后，SQL 仍然长时间没有返回结果的排查方法。

首先，我们需要通过如下语句确定 SQL 的 Session ID 也叫 Connection ID。比如我们数据库中有一个 truncate 语句长时间没有返回结果，我们可以通过下面语句确定 SessionID。

gpadmin=# SELECT * from pg_stat_activity where upper(current_query) like '%TRUNCATE%';

datid | datname | procpid | sess_id | usesysid | usename | current_query | waiting | query_start | backend_start | client_addr | client_port | application_name | xact_start | waiting_reason | rsgid | rsgname | rsgqueueduration
-------+---------+---------+---------+----------+---------+------------------------------------------------------------------------------+---------+-------------------------------+-------------------------------+-------------+-------------+------------------+-------------------------------+----------------+-------+---------+------------------ 
16384 | gpadmin |   15103 | 310 |     10 | gpadmin | TRUNCATE aoco; | t | 2019-11-12 00:24:56.017908-05 | 2019-11-12 00:24:47.147582-05 | | -1 | psql | 2019-11-12 00:24:56.017908-05 | lock | 0 | unknown | 16384 | gpadmin |   15218 | 91014 |   10 | gpadmin | SELECT * from pg_stat_activity where upper(current_query) like '%TRUNCATE%'; | f | 2019-11-12 00:28:06.973462-05 | 2019-11-12 00:24:58.490902-05 | | -1 | psql | 2019-11-12 00:28:06.973462-05 | | 0 | unknown |

(2 rows)

上面输出显示的 sess_id 是310。

紧接着，我们要通过 gpssh 工具来检查每个 segment 的进程执行状况：

$ gpssh -f <hostfile> 'ps -ef | grep con<sess_id> | grep -v idle'

注：这里的 con<sess_id> 就是对应 sessionID 310，就是 con310 这里我们排除了 idle 的进程，因为 idle 进程是处理完自己 Slice 当时分配任务的进程，我们无需关心。通过上面 gpssh 命令的输出，我们就对所有这个 SQL 的对应进程在 greenplum 上的执行状况有个大致的了解。

• 比如说 SQL 只在一个 segment 进程上有非 idle 的情况，那么我们只要着重查看这个 segment 状况即可。可能引起这样状况的原因最常见的状况就是 data Skew；就是这个 SQL 对应表可能有分布不均的情况，也有可能是我们的 SQL join 的键值原因导致的 SQL 处理过程中的分布不均。
• 假如说这个 SQL 的对应进程只在一个机器上有非 idle 的状况，那么我们可以着重关注一下这台机器对应的硬件是否有问题。最常见的就是磁盘的问题。是否磁盘的读写率一直很高在100%？是否其他 SQL 在这台机器上也有卡住的状况？
• 如果我们在所有的机器上看到这个 SQL 的进程都是分布很均匀的，那么很有可能这个 SQL 本身处理的数据量发生了变化，所以时间变长。还有一种最不好的可能性，就是因为我们这个 SQL 不能被 Greenplum 的优化器很好的识别，所以很慢。

不管针对上面的任何的情况，strace 和 pstack 这两个工具都可以帮助我们理解在进程级别这些 SQL 都做了什么动作。所以，我们建议所有的机器都要装这两个工具（另外，针对情况2的磁盘问题，我们建议iotop工具来甄别那个进程用的磁盘资源较多）。

Strace 是一个动态追踪进程系统调用的工具（进程跟操作系统内核的交互)，我们可以直接使用

strace -p

这个命令直接查看。也可以用如下命令：

strace -T -f -ff -y -yy -p

根据我们的经验，这个 strace 的参数组合的可以更好的输出可读性更好的结果。

Strace 是一个在顺着时间动态追踪的工具，而 pstack 可以纵向打印出来某个确定时间点上进程的 Call Stack 信息。Call Stack 可以让我们知道进程在某个具体时间点某个进程究竟在做什么事情。比如：

[root@bdlgpscprd07 gpadmin]# pstack 6495
Thread 2 (Thread 0x7f442920e700 (LWP 6504)):
#0 0x00007f4424e2d043 in poll () from /lib64/libc.so.6
#1 0x0000000000bc1ac4 in rxThreadFunc ()
#2 0x00007f442588f9d1 in start_thread () from /lib64/libpthread.so.0
#3 0x00007f4424e3686d in clone () from /lib64/libc.so.6
Thread 1 (Thread 0x7f44293d2720 (LWP 6495)):
#0 0x00007f4424e2f2e3 in select () from /lib64/libc.so.6
#1 0x00000000008e1cfa in sendSequenceRequest ()
#2 0x00000000006ee69d in nextval_oid ()
#3 0x0000000000759606 in ExecMakeFunctionResultNoSets ()
#4 0x000000000075e662 in ExecProject ()
#5 0x0000000000784727 in ExecHashJoin ()
#6 0x0000000000757d64 in ExecProcNode ()
#7 0x000000000078f249 in SubqueryNext ()
#8 0x0000000000762d5b in ExecScan ()
#9 0x0000000000757c09 in ExecProcNode ()
#10 0x0000000000798b0a in ExecMotion ()
#11 0x0000000000757b66 in ExecProcNode ()
#12 0x000000000074d5bc in ExecutePlan ()
#13 0x000000000074dd76 in ExecutorRun ()
#14 0x000000000099d634 in ProcessQuery ()
#15 0x00000000009a0050 in PortalRun ()
#16 0x0000000000995dc0 in exec_mpp_query ()
#17 0x0000000000999c95 in PostgresMain ()
#18 0x00000000008f6e3e in ServerLoop ()
#19 0x00000000008f9ae0 in PostmasterMain ()
#20 0x00000000007fb13f in main ()

从上面这个 callstack 中我们可以看到这个进程在执行一个Hashjoin。所以如果看到所有的进程都是这个地方比较慢，我们可以尝试考虑对应的 hashjoin 是否有问题（更加具体的分析可能需要结合代码）。

针对 pstack，我们可以用一个简单的 shell 脚本每20秒钟打印出一次，去更好的理解进程的工作状况，每20秒的工作状况。

$ while true; do date; pstack <pid>; sleep 20; done;

在运用了 strace 和 pstack 之后我们会对问题有个大致的判断。比如磁盘操作比较慢，比如大部分进程是在等待网络上的数据，等等。但是如果 pstack 和 stace 后，我们仍然无法对问题有一个深入的了解，对于商业用户，可以通过联络 Pivotal 技术支持获取帮助。（注：如果问题可以在您的环境重现问题，那么将极大的帮助 Pivotal 技术支持定位问题）。

那么，我们怎么样帮助 Pivotal 技术支持收集相关信息呢？Pivotal 技术支持已经开发了gpmt analyze_session tool（https://community.pivotal.io/s/article/Analyze-Session-Tool-Automates-Debug-Tracing-for-Hung-Greenplum-Sessions）来帮助商业用户收集 SQL 卡住的对应信息：GPMT 是一个非常好的收集日志的工具，也非常建议大家在环境中安装。另外，如果问题可以连续复现，我们建议您使用 mini-repro 来收集对应 SQL 的 DDL 和统计信息。这个我们在之前的文章也有过分享过收集日志的步骤，详情请查看链接（ https://greenplum.cn/2019/07/12/how-to-use-minirepro/ ）。

今天的分享就到这里，非常感谢大家的关注，请大家继续关注我们的文章系列。如果有任何问题，可以给我们留言，商业用户可以通过 Pivotal 技术支持与我们保持联络！

关于作者：

姜天旭（Alex Jiang）

Pivotal 技术支持中心售后支持专家。作者曾就职于 EMC、埃森哲、爱立信等知名公司。有多年的数据库相关经验，熟悉 Greenplum、PostgreSQL。