一个数据库连接慢的问题分析

白鳝的洞穴 2020-06-30

1754

客户的一套Oracle 11.2.0.4的数据库跑在AIX 6.1上，偶尔会出现应用HANG死的现象，从数据库的角度看似乎没有什么问题：

从等待事件上看：

出问题当时似乎系统没有什么业务。从等待事件上看十分可以，排在第一位的是reliable message，一般来说是把这个事件当成空闲事件的。如果真的这个等待导致了问题，那么就会比较麻烦。后面的RFS等待基本上是DATAGUARD相关的，和我们的这个问题无关。sql *netvector data from client这个等待事件是十分可疑的。这个等待事件是在会话建立过程中的一个步骤中产生的等待事件，居然产生了这么多次，而从上面的负载文件看到的平均每秒登录才0.4个。

看到这个问题，老白首先怀疑的就是OS 启动进程比较慢，因为只有进程启动慢，才可能出现那个SQL*NET的等待。于是马上翻看后面的等待事件详情：

果然，os sthread startup占据了第一位，而且平均每次等待超过1.4秒。于是和用户说是用户的数据库连接慢导致了相应的问题。用户于是在一台LINUX环境中做了测试，发现linux的os thread startup平均等待大概是1.1秒左右，略低一些，不过在LINUX环境下应用是正常的。

从上面的分析我们怀疑用户是短连接应用较多，大量会话并发登录导致了数据库性能受到影响，这一点在和开发商沟通后也得到了确认，确实在出问题时候，大概有40-50个会话正在连接。并且要修改应用难度较大，希望从数据库角度来解决。同时他们也提出了，为什么在LINUX上没问题，在AIX上有问题呢？后续客户的DBA在另外一台AIX系统上做了类似测试，发现在那台AIX上也有问题。

下面我们就要分析AIX和LINUX在创建会话时候性能有什么差异了。通过sql*net client trace分别采集了两个平台在压力测试时的TRACE文件，进行比对。做客户端TRACE的方法以前老白就介绍过，这里再写一下：

DIAG_ADR_ENABLED=off

TRACE_LEVEL_CLIENT = 16

TRACE_FILE_CLIENT = <FILE NAME>

TRACE_DIRECTORY_CLIENT = <DIRECTORY>

TRACE_TIMESTAMP_CLIENT = ON

经过对TRACE文件进行分析我们发现

AIX环境下，等待进程启动时间是4秒

同样位置，LINUX下只有1秒。

确实AIX下等待SERVER 进程启动的时间要比LINUX长很多。下面需要去分析AIX下负载比较高的时候系统慢在哪个地方了。我们通过下面的TRACE来进行比较，测试场景是，首先压测到类似的负载，然后在服务器上通过SQLPLUS连接数据库，使用truss来跟踪连接过程，这个操作在无负载的时候再进行一次，进行比对：

truss -aDefo tmp/a.log sqlplus "/as sysdba"

通过TRACE文件的比对，我们发现几乎所有的文件类型的系统调用在负载较高时都比负载较小时有较大的提高。

一个简单的oraus.msb文件打开操作，在负载较低时和负载高时竟然延时相差200多倍：

看样子在这个应用负载较高时，AIX操作系统的一些调用性能下降，导致了会话连接变慢。由于对AIX的这方面的性能分析能力不足，因此这个问题只能先交给IBM去分析。我们要想一个临时性的解决方案。考虑到目前定位了是OS kfork子进程较慢导致了该问题，于是我建议用户先通过shared server方式来连接这些应用。首先预先启动100个SHARED SERVER，让这些应用使用。通过这样配置后，在压测下，以前应用hang死的问题不再重现了。

目前暂时先用这个方法临时解决这个问题。后续要看IBM是否能够定位问题了。关于最终的问题定位，老白会在后续和大家分享。

技术

文章转载自白鳝的洞穴，如果涉嫌侵权，请发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。

一个数据库连接慢的问题分析

评论