Apr 18 2007

SQL Parse Time overload

Published by kamus at 8:31 pm under Oracle RDBMS

新系统上线，下午忽然几近崩溃，数据库服务器IDLE只有5%-10%，大量latch: library cache和cursor: pin S wait on X等待，旁边客户技术经理的手机短信不断，全部是在各个省市的技术人员报告应用终端报错的短信，现场一片凝重。

AWR报告显示数据库90%以上的时间都花在了Parse过程上，而且是软解析。

  1. SQL> show parameter cursor
  2.  
  3. NAME                                 TYPE                             VALUE
  4. ------------------------------------ -------------------------------- ----------
  5. cursor_sharing                       string                           EXACT
  6. cursor_space_for_time                boolean                          FALSE
  7. open_cursors                         integer                          1000
  8. session_cached_cursors               integer                          20

session_cached_cursors只有20。

  1. SQL> select *
  2.   2    from (select b.VALUE, b.SID
  3.   3            from v$statname a, v$sesstat b
  4.   4           where a.STATISTIC# = b.STATISTIC#
  5.   5             and a.NAME = 'opened cursors current'
  6.   6           order by 1 desc)
  7.   7   where rownum < 10;
  8.  
  9.      VALUE        SID
  10. ---------- ----------
  11.         52       2058
  12.         40       2057
  13.         38       2065
  14.         38       2064
  15.         32       2059
  16.         30       2069
  17.         29       2068
  18.         28       2063
  19.         28       2072

另外AWR报告中“SQL ordered by Elapsed Time”和“SQL ordered by CPU Time”部分，也显示同样的一句SQL（一个新加入的应用功能）占据所有SQL的消耗时间和CPU时间90%以上。

采取措施：
1. 增加session_cached_cursors到50
2. 在应用端屏蔽那个SQL

重新启动数据库，应用恢复正常，服务器IDLE升高到80%以上。

因为同时修改了数据库参数和应用才解决了问题，所以下午的争用是不是确实由于session_cached_cursors设置过小引起的？如果此时再次加回那个SQL应用还会不会出问题？

No Tags

13 Responses to “SQL Parse Time overload”

  1. yumianfeilong Says:
    April 18th, 2007 at 9:28 pm [ Quote ]

    99%是应用的问题。

  2. eygle Says:
    April 18th, 2007 at 10:21 pm [ Quote ]

    应该是SQL引起的，跟参数关系不大。session_cached_cursors 设置为20已经不小了，cache和exec的次数还有关系的

  3. 木匠 Says:
    April 19th, 2007 at 1:30 am [ Quote ]

    “应用端屏蔽那个SQL”

    这是怎么回事? Oracle 内建功能?

  4. kamus Says:
    April 19th, 2007 at 2:13 pm [ Quote ]

    to eygle
    我没有想明白的是，如果不是session_cached_cursors的原因，为什么仅仅增加了这个SQL就会导致90%以上的时间耗费在parse上。

    to 木匠
    呵呵，不是，就是开发人员紧急修改程序，把这个SQL去掉了而已。我的文章写的可能有些歧义，已经修改了。

  5. 木匠 Says:
    April 20th, 2007 at 1:02 am [ Quote ]

    Good. 难道是没有binding variable in SQL…

    你把这个神秘的SQL TEXT 帖出来给大伙瞧瞧.

  6. kamus Says:
    April 20th, 2007 at 3:19 am [ Quote ]

    就是很简单的一句update tablename set column=xxx where col1=xxx and col2=xxx;
    其中table比较大，千万级的数据量，但是col1和col2上有联合索引，并且执行计划显示确实走了索引。
    如果说因为这句在execute阶段产生lock contention我是可以理解的，但是为什么会是在parse阶段？

  7. logzgh Says:
    April 20th, 2007 at 12:03 pm [ Quote ]

    我估计是应用程序里面写错了。或者说逻辑上有问题，导致这条语句在频繁的执行，比如说陷入某个循环里面，出不来之类的。

  8. 木匠 Says:
    April 20th, 2007 at 1:14 pm [ Quote ]

    如果col1 和 col2 都使用了绑定变量, Binding.

    再试一下,
    alter system set cursor_sharing=EXACT;

    不然就打开 SQL_Trace , 用 tkprof 分析一下 trace 文件,
    看看这个 UPDATE 到底做了些什么(见不得人的事情)

    CallableStatement cs_trace = conn1.prepareCall(”{ CALL dbms_monitor.session_trace_enable( WAITS => TRUE, binds=>true) }”);
    cs_trace.executeUpdate();
    cs_trace.close();

  9. Thomas Zhang Says:
    April 21st, 2007 at 2:25 pm [ Quote ]

    与session_cached_cursors 关系不大！10g? 也不一定是应用的问题[也不排除]，或许是bug呢. ^|^

  10. gulibin Says:
    April 22nd, 2007 at 9:19 pm [ Quote ]

    SQL引起的吧！！

  11. kamus Says:
    April 23rd, 2007 at 2:52 am [ Quote ]

    因为是产品环境所以不能继续测试了，但是很快就会再搭建一个两节点的测试环境，到时候详细跟踪一下这个问题。

  12. yumianfeilong Says:
    May 16th, 2007 at 4:12 pm [ Quote ]

    今天也被Cursor: pin S wait on X搞大了

  13. kamus Says:
    May 17th, 2007 at 2:15 am [ Quote ]

    哦，对了，忘了更新这篇文章了，这是oracle10.2.0.3的一个bug，在执行大量并行检索时，会导致sql的version count过高，从而消耗了共享内存，然后导致过多的latch和mutex争用。

Trackback URI | Comments RSS


Leave a Reply

-> :( :! :D :| :? :X ;;) :) ;)