案例：如何从SYSTEMSTATE DUMP查看Mutex的持有者和请求者

Keywords：

SYSTEMSTATE DUMP
Mutex HOLDER/WAITER
cursor: pin X
ORA-44203

客户的问题

某日客户报告，某系统经常发生ORA-44203错误，某些特定的SQL文无响应无法正常执行。
用户取得了某日（09:46左右）问题发生时的各种信息:
查看v$session视图中该SQL的等待事件为EVENT：cursor: pin X、 WAIT_CLASS：Concurrency，但BLOCKING_SESSION为空。

DB环境：

Red Hat Enterprise Linux 5 (for Intel64)
Oracle Database Standard Edition 11g 11.2.0.3 64bit
Single Instance

定位问题（Frame Issue）

根据用户描述，可以判定这是一个故障解决型的问题。针对这种问题，我们需要从现象入手一步一步进行分析。

澄清问题和核实问题（IC &IV）

首先我们需要明确问题并证明问题确实存在。

通过用户的描述，我们可以明确本次问题关键是解决ORA-44203错误和SQL文无响应的问题。 我们可以从用户提供的应用程序日志和提供的日志文件中确认到如下的输出：

应用程序日志：

v$session和v$session_wait的输出：

从输出内容可以看出，SQL文的等待事件是cursor: pin X，并且BLOCKING_SESSION为空，即没有明确的导致该次等待的会话。

信息收集(Data Collection)

为了进一步确认发生的事件详细，我们需要进一步去查看相关的警告和跟踪日志文件。

1.首先查看alert.log

我们发现在问题发生时间点（09:46左右），DB并没有报什么错误，但却在09:47左右生成了许多的SystemState dump。因此，准备从SystemState dump开始入手，查看有什么发现。

2.查看SystemState dump

根据V$session的信息，通过SID（sid: 17）定位到所在的问题进程（PROCESS 310）。 （也可以直接通过查看SystemState dump内容进行定位）

理清问题后的调查（Research ）

现在我们面临着以下的一些问题：

ORA-44203具体含义是什么？
“cursor: pin X”等待信息的意义？
v$session和SystemState dump还能得到有什么有用的信息？
有什么异常的点？
所有的信息有什么关联？

关于ORA-44203错误

首先让我们查看ORA-44203错误具体含义是什么。

$ oerr ora 44203
44203, 0000, "timeout waiting for lock on cursor"
// *Document : Yes
// *Cause    : A timeout occured while waiting for a cursor to be compiled.
//             This is usually caused by the SQL parse requiring access to
//             system resources which are locked by concurrently executing
//             sessions.
// *Action   : Investigate possible causes of resource contention. If
//             neccessary, contact support for additional information
//             on how to diagnose this problem.

通过以上的输出，ORA-44203错误是在游标（cursor）编译的时候去获得相关的锁资源，但是由于其他的一些会话持有着，无法获得导致超时发生的错误。通常需要找到竞争的源头，找到为什么保持锁的会话长时间持有锁。

关于“cursor: pin X”

通过v$session我们看以看到，会话在等待“cursor: pin X”，并且也可以得到相关的参数的值。

我们首先通过在线文档查看等待“cursor: pin X”的相关信息：

Database Reference

cursor: pin X A session waits on this event when it is requesting an exclusive mutex pin for a cursor object and it must wait because the resource is busy. The mutex pin for a cursor object can be busy either because a session is already holding it exclusive, or there are one or more sessions which are holding shared mutex pin(s). The exclusive waiter must wait until all holders of the pin for that cursor object have released it, before it can be granted. Wait Time: Microseconds Parameter Description P1 Hash value of cursor P2 Mutex value (top 2 bytes contains SID holding mutex in exclusive mode, and bottom two bytes usually hold the value 0) P3 Mutex where (an internal code locator) OR'd with Mutex Sleeps

等待“cursor: pin X”主要是在游标（cursor）编译的时候，以排他（X）模式获得相关的mutex 时，由于其他会话以排他（X）或共享（S）模式持有时发生的等待事件。 其中P1是游标的Hash值，P2是如果某会话以排他（X）持有mutex会话的SID，或以共享（S）持有mutex会话的个数。因此，解决问题的方法还是找到持有会话。

关于v$session和SystemState dump

通过v$session，可以确认到：

通过SystemState dump我们可以确认到：

1）发生问题的Session信息

2）正在等待的Mutex信息

其中， idn代表SQL文的HASH VALUE的后4位（也代表要求获得的Mutex），通过idn输出我们可以特定出要求获得的Mutex和要执行的SQL文。 value的前4位代表持有者的16进制表示SID（本次输出：0xffff→65535）； where代表Mutex的内部代码地址（对于用户不需要太注意）。

这个输出信息和v$session的P 1、P 2、P 3输出基本相同。 只不过通过v$session确认到的值是10进制，SystemState 确认到的值是16进制。

3）Mutex的详细信息 通过idn可以查看Mutex更详细的信息。

0x1801b8238(65535, 0)代表Mutex 的内存地址，(65535, 0)代表以排他模式持有Mutex的SID。 oper GET_XXX 代表这次会话正在要求排他模式的Mutex。

4)问题发生的SQL文 通过Hash值也可以定位到执行的SQL文的内容。

有什么异常的点？

通常情况下根据上面的输出信息基本可以找到Mutex的持有会话，并解决问题了。 但是，本次现象中查看V$session和SystemState dump中都没有发现该SID，并且持有会话的SID为65535（0xffff），SID值异常的大，所以我们需要依据这个线索进行调查。

我们通过以下关键字进行MOS的搜索：

'CURSOR: PIN X' 0xffff

很容易定位到了相关的一个已经存在的Bug：

原因认定和原因认定的理由（CD & CJ）

根据上面的调查结果，我们可以判断本次现象的原因是由于Bug 16600790（Base Bug 13542050）的影响产生的。

在某些条件下当会话还没有完全建立成功前需要KGL mutex时，会从PGA中分配相关的mutex Recovery 结构(AOL:atomic operation log）并把持有者（HOLDER）设为65534或相近的值。 如果这时候持有Mutesx的进程Crash或者被意外结束，由于PMON不能够访问已经死掉的进程的PGA，所以无法清除持有者（HOLDER）。 其他的会话还需要相同AOL的Mutex时，就会等待。

本次发生的ORA-44203错误和无响应现象同样是由于这个原因导致的。从v$session和SystemState dump中可以看到，无响应的会话一直在等持有者为65535的Mutex，由于等待超时，发生ORA-44203错误。 并且从用户提供的Opatch信息来看，用户的版本为11.2.0.3 且没有修复Bug 16600790（Base Bug 13542050）。 所以判断，本次现象是由于Bug 16600790（Base Bug 13542050）影响的。

推荐的解决方案和推荐的理由（PS & PJ）

由于对这个问题并没有合适的回避方法，所以为了避免现象的再次发生，需要下载相关的one-off path.

该问题在最新PSU 12.1.0.2.160419 (Apr 2016) 上也得到了修正，升级也可以解决。

※如果没有实施解决方案，再次发生时，重启数据库也有一定的缓解作用。

知识点总结（KM）

通过本次案例， 我们详细描述了解决问题的思路和过程，并介绍了以下的知识点。 并重点介绍了如何从SYSTEMSTATE DUMP查看Mutex的持有者和请求者。

ORA-44203错误含义
等待事件“cursor: pin X”和其参数的含义
如何从SYSTEMSTATE DUMP查看Mutex的持有者和请求者
Bug 16600790（Base Bug 13542050）的原因和解决方法

参考

Bug 16600790 : SESSIONS HANG WITH 'CURSOR: PIN X' WAITING FOR MUTEX IN "GETLONGEXCL" Bug 13542050 - A mutex related hang with holder around 65534 (0xfffe) (Doc ID 13542050.8)