记一次cursor pin s wait on X的处理

今天遇到个问题，客户说某天的11:45开始，系统遇到了大量的cursor pin s wait on X，经历一个小时后自动消失，需要查找原因。

这报错一般是某个会话需要申请S模式的mutex，而mutex被其他会话以X模式占有了。查holder也很容易，11g版本前看p2raw的前8位，将16进制转换成10进制即为holder的sid，在11g之后只需直接看blocking_session即可。

在11g中，我们有ash，这个很方便能查到过去发生的一切。

（1）根据客户反馈的情况，cursor pin S wait on X最严重的一个时间段为12:25~12:35，取这个时间段为例。发现cursor: pin S wait on X的进程都被sid为2的进程堵塞。

（2）SID为2的进程被sid为1129的进程堵塞：

（3）sid为1129的进程被sid 951的堵塞：

（4）sid 951的进程被Wnnn的进程堵塞：

（5）最终的堵塞进程为Wnnn。

Wnnn是11g新的进程，有SMCO进程spawn出来，用于主动空间的管理(It perform proactive space allocation and space reclaimation)。
从上述SQL看，由于有insert又有truncate，因此空间清理将有SMCO和Wnnn进程介入。在操作的过程中，堵塞其他的进程的操作。

到这里，我们可以有个初步的解决方案：

既然是Wnnn进程堵塞了其他进程的操作，那么我们禁用这个11g的新功能，禁用SMCO的空间管理 “Tablespace-level space（Extent）pre-allocation”，即可避免该问题的发生。

还原的反向操作为：

注：

但是我们到这里也会问一个问题，为什么Wnnn的操作没有blocking_session，却要操作那么久的时间。这时一个不常见的等待事件映入眼帘：log file sequential read 。

log file sequential read 一般是在恢复或者logmnr的时候，才将redo log file的内容顺序的读入到内存中，此时为什么需要做log file sequential read？

根据上述的时间点，我们进一步结合alertlog看，我们发现在对应的时间点，都有关于w004的ora600的报错。

结合ora -600 [ktecgsc:kcbz_objdchk]查询MOS，我们可以定位到一个11.2.0.2的bug 10237773，并且从该bug的Rediscovery Note中，也可以看到：The problem is likely to occur in a Wnnn background process ktssupd_segment_extblks_bkg is likely to appear on the stack.

进一步分析trace文件，我们可以看到11：40到12：43都在dump redo record。因此，我们在那段时间看到wnnn进程的log file sequential read的等待。即wnnn进程在读取redo log file做dump。

Dump redo record（11：40到12：43）：

另外，在trace文件中，也查到的bug中所说的ktssupd_segment_extblks_bkg的调用。

因此，问题的原因应该是这样的：

找到了问题根源，对应的解决方法也就明了了。workaround是禁用11g新特性，SMCO的空间管理，fix是打bug 10237773的补丁，或者升级到11.2.0.3。