一、问题发现：

       发现一个数据库语句执行很慢，奇怪的是，仅仅是一个insert 语句。难道一个insert语句要执行3秒钟，这个提起了我的兴趣。把当时的出问题的时段的awr报告打印出来一看发现一条奇怪的sql语句，我至今从来没有遇到过如此长的sql语句。看看它长什么样子：

  没有错，你没有看错，就是一条insert语句。这个我还没有截屏完整，好几个屏幕。绑定变量有28000个。第一次见这么长的sql语句，第一见绑定变量如此多的语句。

      和开发了解下需求：根据2个表数据，按一定业务逻辑插入到一个临时表，于是，就有上面这个拼接sql。（其实这要在以前，拿我来设计的话，我会直接写成plsql处理，但是现在是互联网微服务，于是，很多都变成微服务了。）

二、问题分析：

 insert语句很慢，索引很多是一个原因。分析了下awr，是cursor: pin S wait on X等待事件。这个事件什么意思呢?

A session waits for this event when it is requesting a shared mutex pin and another session is holding an exclusive mutex pin on the same cursor object.

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

    搜索了下网上文章，导致这个等待事件有如下原因：

过多的子游标 High Version Counts， Mutex持有者得不到CPU， 已经被KILLED的SESSION仍持有Mutex 

实际该 cursor: pin S wait on X等待事件往往是由于其他因素诱发的。Mutex争用仅仅是问题的症状，但根本原因需要Database Consultant 进一步挖掘。  那我这个是什么原因呢？

      我检查了下等待事件：

SYS@VIPAY>selects.p1,to_char(s.p2) ,BLOCKING_SESSION,s.session_id,s.sql_Id,to_char(s.SAMPLE_TIME,'mm-dd hh24:mi:ss')  fromv$active_session_history s  whereSAMPLE_TIME betweento_date('2019-08-27 00:15','YYYY-MM-DD HH24:mi') 

  2  andto_date('2019-08-27 00:45','YYYY-MM-DD HH24:mi')

  3   ands.event='cursor: pin S wait on X';

        P1 TO_CHAR(S.P2)                            BLOCKING_SESSION SESSION_ID SQL_ID        TO_CHAR(S.SAMP

---------- ---------------------------------------- ---------------- ---------- ------------- --------------

2721535173 12262131630080                                       2855       4225 5y45fw2j3fp65 08-27 00:30:23

2721535173 12262131630080                                       2855       4225 5y45fw2j3fp65 08-27 00:30:22

2721535173 12262131630080                                       2855       4225 5y45fw2j3fp65 08-27 00:30:21

2721535173 12262131630080                                       2855       4225 5y45fw2j3fp65 08-27 00:30:20

2721535173 6876242640896                                        1601       2855 5y45fw2j3fp65 08-27 00:30:19

2721535173 6876242640896                                        1601       4225 5y45fw2j3fp65 08-27 00:30:19

2721535173 6876242640896                                        1601       2855 5y45fw2j3fp65 08-27 00:30:18

2721535173 6876242640896                                        1601       4225 5y45fw2j3fp65 08-27 00:30:18

2721535173 6876242640896                                        1601       2855 5y45fw2j3fp65 08-27 00:30:17

2721535173 6876242640896                                        1601       4225 5y45fw2j3fp65 08-27 00:30:17

2721535173 6876242640896                                        1601       2855 5y45fw2j3fp65 08-27 00:30:16

2721535173 1979979923456                                         461       2855 5y45fw2j3fp65 08-27 00:30:10

2721535173 1979979923456                                         461       2855 5y45fw2j3fp65 08-27 00:30:09

2721535173 1979979923456                                         461       2855 5y45fw2j3fp65 08-27 00:30:08

2721535173 1979979923456                                         461       2855 5y45fw2j3fp65 08-27 00:30:07

2721535173 1979979923456                                         461       2855 5y45fw2j3fp65 08-27 00:30:06

2721535173 2946347565056                                         686        461 5y45fw2j3fp65 08-27 00:30:05

2721535173 2946347565056                                         686       2399 5y45fw2j3fp65 08-27 00:30:05

2721535173 2946347565056                                         686       2855 5y45fw2j3fp65 08-27 00:30:05

2721535173 2946347565056                                         686       3543 5y45fw2j3fp65 08-27 00:30:05

2721535173 2946347565056                                         686       4335 5y45fw2j3fp65 08-27 00:30:05

2721535173 2946347565056                                         686        461 5y45fw2j3fp65 08-27 00:30:04

2721535173 2946347565056                                         686       2399 5y45fw2j3fp65 08-27 00:30:04

2721535173 2946347565056                                         686       2855 5y45fw2j3fp65 08-27 00:30:04

2721535173 2946347565056                                         686       3543 5y45fw2j3fp65 08-27 00:30:04

2721535173 2946347565056                                         686       4335 5y45fw2j3fp65 08-27 00:30:04

2721535173 2946347565056                                         686        461 5y45fw2j3fp65 08-27 00:30:03

2721535173 2946347565056                                         686       2399 5y45fw2j3fp65 08-27 00:30:03

2721535173 2946347565056                                         686       2855 5y45fw2j3fp65 08-27 00:30:03

2721535173 2946347565056                                         686       3543 5y45fw2j3fp65 08-27 00:30:03

2721535173 2946347565056                                         686       4335 5y45fw2j3fp65 08-27 00:30:03

2721535173 2946347565056                                         686        461 5y45fw2j3fp65 08-27 00:30:02

2721535173 2946347565056                                         686       2399 5y45fw2j3fp65 08-27 00:30:02

2721535173 2946347565056                                         686       2855 5y45fw2j3fp65 08-27 00:30:02

2721535173 2946347565056                                         686       3543 5y45fw2j3fp65 08-27 00:30:02

2721535173 2946347565056                                         686       4335 5y45fw2j3fp65 08-27 00:30:02

原来是会话ID4225等待2855,2855等待461,461等待686.原来，所有的会话都在等待686会话完成。看来，只有 找到686这个会话在干什么，就知道所有的会话等待问题迎刃而解了。等我找到686会话之后，发现686会话等待是 on cpu。而且686真正执行的sql也是

15y45fw2j3fp65

到这里有点懵了。意思就是，所有的会话都在等待686，所以产生cursor: pin S wait on X等待事件。，而686自己正在执行。

三、问题解决：       

  到这里就有办法了，就是，减少insert执行时间，就不会产生等待。绑定变量的是28000个，上下文切换频繁，所以减少绑定变量。原来一个insert 拼接800记录，现在拼接300记录，果然发现，执行时间变成1秒，再减少，变成200记录，时间变成0.5秒，再减少100，执行时间变成0.05秒。再往下减少，执行时间不变。