故障诊断 | 系统级追踪诊断方法及案例分享

我们在进行Oracle故障调试和内核原理工作的时候，经常需要了解后台运行的动作和细节。一些故障场景，如ORACLE后台进展慢、程序无法启动、无法登陆、相同环境执行结果却大不相同等问题，就需要操作系统级别监控，检查定位问题。

Oracle自身已经提供了很多这类型的工具，如oradebug、各种等待事件和跟踪方式。此外，各类型的操作系统提供出很多系统级别工具，帮助我们进行监控。

我们先来看一个简单的示例：

LGWR进程写 online redo log是否用到缓存？

这里的这个缓存不是指数据库缓存，操作系统的文件缓存，如果对这个问题不明白，我们先看另外一个问题，我们如果怀疑存储有问题，经常会使用DD命令对磁盘进行测试，相关命令如下所示，那这个命令对磁盘的操作是直接写磁盘还是把数据写到文件缓存里去？

我们来实地进行测试验证看一下，这是在我电脑虚拟机上的一个测试结果，DD了2G的文件，花了4.99秒的时间，实际上这个命令结束的时候数据没真正写到磁盘上去，对于磁盘的写到缓存就返回了。我们另外看一条命令

这里加了一个标志，就是ofag=sync，加完这个标示之后，我们发现写磁盘的速度下降了，写2G的文件花了8秒，多用了60%的时间。这就是文件系统缓存的作用，文件系统缓存大大增加了主机的性能。

我们现在回到之前那个问题，LGWR进程写redo log 会不会用到缓存呢？我们使用strace –p命令来跟踪LGWR进程，为方便观察我们添加一组新的redo日志组并进行切换。

通过分析TRACE信息我们发现，LGWR进程对online redo log打开使用了o_sync标示，该标示表示直接写入存储设备。

TRUSS/TUSC/STRACE是什么？

下面我引用一下TRUSS的官方解释，TUSC与STRACE工具功能基本一样。

它是一个在系统层处理复杂问题非常有用的工具，用来跟踪一个进程的系统调用或者信号产生的情况。适用于不同的系统环境。

它们适用于不同的Unix环境：

• Truss ： AIX，Solaris
  
• Tusc  ：HP-Unix（需单独安装）
  
• Strace：Linux
  

Truss常用参数介绍

Tusc常用参数介绍

Strace常用参数介绍

下面我们看两个简单的使用示例：

首先是使用strace –tt date来跟踪date命令，使用-tt参数在每一行的行头上加上时间信息，到微秒级别。

另外一个示例就是使用strace –d cate命令统计所有函数调用的次数及总时间占用，这个对于命令跟踪的分析统计非常有用。

一个SQLPLUS连接慢的问题

接下来我们来看一个案例，这个案例是一个SQLPLUS连接慢的问题，AIX 7.1的操作系统，11.2.0.3 两节点RAC数据库，检查硬件的安装环境没有问题，重新配置环境变量也不能解决问题。

对于这种问题，我们首先要进行一些排查，排除一些可能性：

1、  我们看一下使用sqlplus/ as sysdba慢不慢，经过反馈，sqlplus / as sysdba也慢，连接时间要5秒左右。

2、  远程连接慢不慢？

• 本地使用远程连接慢不慢  sqplus username/passwdd@tns 澄清： 测试也慢，慢约5秒钟左右。
  
• 其它主机使用远程慢不慢？澄清：同样也慢， 慢约5秒钟左右。
  

以上判断表明这个连接慢并非一定和Listener有关，同时也可以排除网络问题引起的监听连接慢，所以先需要解决sqlplus / as sysdba 慢的问题，很大可能在ORACLE数据库的连接处理机制上面。

我们使用TRUSS命令去跟踪跟踪sqlplus / as sysdba连接命令，发现不断出现sigpromask、_sigaction及thread_setmystate函数调用。

那这些函数代表什么？

之后对这些函数进行分析，其主要功能如下：

We see in that truss that main reason weare waiting is that the forked thread is looping on some signal handlingmodification :

 They impact the way memory isconfigured (read/write protected, guard pages...)

通过上述分析发现，连接的时候慢与内存页的分配有关，通过进一步检查内存参数发现，pre_page_sga设置为true。接下来通过测试可以重现这个问题，实际验证的确如此：设置为true，问题重现，设置为false，问题消失，并且发现这个参数为True的情况下，SGA内存越大连接变慢的越明显。

这种行为正常吗？

通过查询MOS文档Notes 289585.1，我们了解知这个行为是正常。

原文发布时间为：2018-01-03

本文作者：邝志辉

本文来自云栖社区合作伙伴“数据和云”，了解相关信息可以关注“数据和云”微信公众号