故障诊断 | 系统级追踪诊断方法及案例分享
所谓操作系统，是应用程序与服务器硬件进行沟通的中间层。应用程序的所有操作，都是和操作系统进行沟通交互。操作系统负责将所有交互转化为设备语言，进行硬件交互。
我们在进行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常用参数介绍
参数 | 介绍 |
|---|---|
-a | 显示在每一执行系统调用中传递的参数字符串。 |
-c | 计数跟踪系统调用、故障和信号而不是逐行显示跟踪结果。跟踪命令终止或 truss 中断时生成摘要报告。若还使用 -f 标志，计数包含所有跟踪的系统调用、故障和子进程信号。 |
-d | 每行输出包含时间戳记。时间从跟踪开始以每秒显示。跟踪输出的第一行显示测量单个时间戳记的基本时间。缺省不显示时间戳记。 |
-D | 每行输出显示增量时间。增量时间表示从由该线程引起的最后报告事件起计时引起事件的 LWP 的逝去时间。缺省不显示增量时间。 |
-e | 显示在每一执行系统调用中传递的环境字符串。 |
-f | 跟在 fork 系统调用产生的所有子进程之后，并包含跟踪输出中的信号、故障和系统调用。 通常，仅跟踪第一级命令和进程。如果指定 -f 标志，进程标识与每行跟踪输出一起显示哪个进程执行系统调用或接收信号。 |
-l | 显示有关 LWP 进程的标识（线程标识）及 truss 输出。输出中缺省不显示 LWP 标识。 |
-o | 指定用于跟踪输出的文件。缺省时输出指向标准错误。 |
-p | 将参数作为一列现存进程的进程标识而不是要执行的命令解释到 truss。 倘若进程用户标识或组标识与用户的用户标识或组标识匹配或者用户是特权用户，truss 控制并开始跟踪每个进程。 |
Tusc常用参数介绍
Strace常用参数介绍
参数 | 介绍 |
|---|---|
-c | 统计每一系统调用的所执行的时间,次数和出错的次数等. |
-d | 输出strace关于标准错误的调试信息. |
-f | 跟踪由fork调用所产生的子进程. |
-ff | 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号. |
-F | 尝试跟踪vfork调用.在-f时,vfork不被跟踪. |
-h | 输出简要的帮助信息. |
-i | 输出系统调用的入口指针. |
-q | 禁止输出关于脱离的消息. |
-r | 打印出相对时间关于,,每一个系统调用. |
-t | 在输出中的每一行前加上时间信息. |
-tt | 在输出中的每一行前加上时间信息,微秒级. |
-ttt | 微秒级输出,以秒了表示时间. |
-T | 显示每一调用所耗的时间. |
-v | 输出所有的系统调用.一些调用关于环境变量,状态,输入输出等调用由于使用频繁,默认不输出. |
-V | 输出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，我们了解知这个行为是正常。
