共计 2357 个字符，预计需要花费 6 分钟才能阅读完成。
| 导读 | 从日志中我们可以梳理出一个大致的脉络。可以看出在 Oracle 等待事件的统计时长与实际情况并不完全一致。事实上数据库也没必要十分精确的统计等待时长，只要是一个大致的就足够了。只要误差都是差不多的，对于实际分析来说并没有太大的问题。 |
可观测性能力是 IT 运维的强有力的支撑。日志告警、指标是两种在运维中很常用的可观测性指标。而对于数据库这样复杂的 IT 组件来说，有时候仅仅依靠日志和指标还是不够的。
跟踪是解决数据库复杂问题的十分常用和有效的方法。今年的 openGauss 开发者大会上，华为的黄凯耀分享的案例就是使用了 eBPF 进行跟踪，最终精准定位了一个比较复杂的性能问题。在跟踪方面，国产数据库与 Oracle 等传统商用国数据库还有这很大的技术差距。做好跟踪并不容易，让运维人员或者售后服务人员能够很方便的跟踪数据库的某种运行行为可以帮助提升运维，加快 BUG 定位。
Oracle 提供了十分强大的分析功能，特别是 EVENT 设置。我刚刚开始学习 Oracle 不久，就学会了使用 event 10046 去跟踪 SQL 语句的执行。这对于我刚刚开始接触 Oracle 这个黑匣子的说话帮助巨大。在缺乏必要的资料，甚至连一个 METALINK 账号都没有的时期，学习 Oracle 数据字典的基本原理，以及数据库启动时的主要动作等，都是通过 10046 trace 文件完成的。后来也经常使用 10046/10053 等事件分析，来解决用户的 SQL 语句性能问题。后来我学习一些 Oracle 新特性的说话，还是经常会使用 event 做一些 trace。
前两天研究了一下 Oracle 的 LGWR worker 新机制，我后来也问了一些客户，在一些系统规模不是很大的场景，好像客户都没有感受到这个新的变化。也有写负载较大的用户遇到了 LOG FILE SYNC 延时过高的问题，后来通过将 LGWR 改为原来的写模式解决了问题。于是我昨天写了一篇相关的文章，猜测了一下 Oracle 实现这个功能的原理。当天下午和一个朋友聊起这个事情，他希望我能够进一步确认一下我的猜测是否靠谱。在网上能够找到的资料极少，于是我只能再次使用起 5、6 年没用过的跟踪大法来做一个分析。
分析 Oracle 数据库的后台进程功能有一种十分常用的方法，这个是我从 Poder 大师那边学来的。结合 10046 和 LINUX 的 strace，可以比较清晰的分析 Oracle 后台进程的一些行为。因为 10046 中会输出某个会话执行过的 SQL 语句，产生过的各种等待事件，利用这个 TRACE 上的时间戳，结合 strace 对于调用堆栈的跟踪，就很容易进行问题定位了。这个方法归纳起来很简单：首先对需要跟踪的后台进程设置 8 级的 10046 TRACE，然后开启压测脚本，同事启用 strace 对调用堆栈进行跟踪就可以了。我们来看看这个完整的过程。
首先我们找到要跟踪的进程，我们准备跟踪 lgwr 和 lg00。然后分别针对这两个进程设置 10046 trace。
在两个窗口中分别通过 oradebug 设置好之后。我们就可以启用一个压测工具 slob 去产生一些写负载了。为了减少跟踪的日志量，我们把 slob 设置为 1 个进程，并且只启动一个并发。
启动好压测负载后，我们就可以分别在两个窗口中对 lgwr/lg00 进行 strace 跟踪了：
对于 strace 不太熟悉的朋友我可以解释一下，-T -tt 是在每个调用前显示时间戳，- s 是对于每个调用的数据，最多显示 512 字节。-p - o 我就不解释了，估计地球人都明白。跑上几十秒钟后，我们就可以停止跟踪了，因为大部分的行为都十分类似，没必要跑太久。
我们先来看看 lg00 的 strace 跟踪信息，因为我加上了 - s 参数，因此在 trace 里可以看到所有写入 lg00 trace 文件的数据的前面 512 字节。因此我不需要去查看 orcl1_lg00_15626.trc 文件了。
上面这段 trace 的开始是 lg00 完成了一个日志写入的工作，进入 Idle 等待状态。随后就收到了写任务，开始写入 REDO 文件，大家注意看因为使用了异步 IO，因此 lg00 通过 io_submit 来提交 IO。我们往下看，可以发现 lg00 随后发生了 ASM IO for non-blocking poll 等待，这是因为向 ASM 发出了 IO。然后 lg00 产生了我们熟悉的 log file parallel write 等待。到收到 io_getevents 为止，异步写完成。于是 lg00 记录了 log file parallel write 等待完成。
从日志中我们可以梳理出一个大致的脉络。可以看出在 Oracle 等待事件的统计时长与实际情况并不完全一致。事实上数据库也没必要十分精确的统计等待时长，只要是一个大致的就足够了。只要误差都是差不多的，对于实际分析来说并没有太大的问题。
我们再来看看 lgwr 的相关时段的跟踪信息。为了方便查看，我梳理了一个表格，从中可以看出整个过程。
我们先来看 lgwr，收到写请求后，找到了一个空闲的 worker，然后发出写任务。同时发现所有的 worker 都处于忙的状态。此时正好没有写任务，于是发出一个本地 IPC 消息，等待 ipc 消息回复。
而 lg00 收到写任务后，首先异步提交了 IO，然后产生了一系列预期的写日志的等待。完成后先通知 lgwr，然后再给等待着发通知。这个算法是比较合理的，由 lg00 直接发消息给 log file sync 等待的会话，而不是通过 lgwr，这样会有更高的效率。和我由 lgwr 发消息，lgwr worker 无阻塞写的想法不一致。二者可能在面对不同场景时各有优势，到底哪种更好也不太好判断，也不在我们今天讨论的范围内。今天我们重点要介绍的是跟踪数据库后台进程行为的方法。
