查看: 22274|回复: 75

[精华] ORACLE小小说之武朝迷案

[复制链接]
认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:38 | 显示全部楼层 |阅读模式
   前几天遇到了一次数据库调优的经历,也在PUB上发出来和大家共同探讨过http://www.itpub.net/thread-1277587-1-1.html,经过自己回去后仔细琢磨,终于自己搞定了,现在整理出来,和大家共分享!
也请各位高手给予指点!

  处理问题后,总结非常重要,因此我花了好几个小时总结了处理问题的过程,我希望自己在总结中加深认识的同时,给更多的人带来帮助!(另外为了排版美观,我把例子用附件形式保存了,大家可以下载观看)


1、武朝迷案

   最近网管组遇到了一个困扰很长时间的棘手问题,就是如下执行频率极高的语句(用于权限管理),在生产环境中运行比较缓慢,执行需要200秒以上,急需优化,最好是控制在10秒以内。(测试环境服务器也是如此状况)

   据同事另外反映两点疑惑:1、生产环境及测试服务器环境运行时快时慢 2、模拟的本机笔记本环境居然跑的比生产快几十倍!

Select *
   From (Select Rownum Sid, a.*
           From (Select a.Ne_Alarm_List_Id Id,
                        a.Flow_Id, /*流程ID*/
                        a.Oprt_State Oprtstate, /*操作状态*/
                        a.Alarm_State Alarmstate, /*告警状态*/
                        a.Alarm_Level Alarmlevel, /*告警级别*/
                        a.Perf_Msg_Id, /*性能消息ID*/
                        a.Alarm_Class Alarmclass, /*告警类别*/
                        To_Char(a.Generate_Time, 'yyyy-mm-dd') Generatedate, /*产生日期*/
                        To_Char(a.Last_Generate_Time, 'yyyy-mm-dd') Lastdate, /*最后产生日期*/
                        B1.List_Label Alarm_Type,
                        C1.Ne_Name,
                        d.Kpi_Name,
                        a.Kpi_Value,
                        Decode(C1.Ne_Flag, 6, e.Region_Name, C2.Ne_Name) Datasource,
                        '<span style=\"color:black;background:' ||
                        Decode(a.Alarm_Level,
                               '1',
                               'red',
                               '2',
                               'orange',
                               '3',
                               'yellow',
                               'green') || ';\">' ||
                        Decode(a.Alarm_Level,
                               '1',
                               '严重',
                               '2',
                               '重要',
                               '3',
                               '一般',
                               '未知') || '</span>' Alarm_Level,
                        To_Char(a.Generate_Time, 'yyyy-mm-dd hh24:mi:ss') Generate_Time,
                        To_Char(a.Last_Generate_Time, 'yyyy-mm-dd hh24:mi:ss') Last_Generate_Time,
                        Pkp_Flow_Function.Getflowcurstaffname(a.Flow_Id) Flow_Operator,
                        a.Alarm_Times,
                        Decode(a.Oprt_State,
                               '20',
                               To_Char(a.Confirm_Time, 'yyyy-mm-dd hh24:mi:ss'),
                               '25',
                               To_Char(a.Suspend_Time, 'yyyy-mm-dd hh24:mi:ss'),
                               '30',
                               To_Char(a.Clear_Time, 'yyyy-mm-dd hh24:mi:ss'),
                               '40',
                               To_Char(a.Delete_Time, 'yyyy-mm-dd hh24:mi:ss')) Executetim,
                        B2.List_Label Alarm_State,
                        Decode(a.Flow_Id, '', '未派单', '已派单') Work_State /*自定义列项*/
                   From Ne_Alarm_List a,
                        (Select *
                           From Tp_Domain_Listvalues
                          Where Domain_Code = 'DOMAIN_NE_ALARM_TYPE') B1,
                        (Select *
                           From Tp_Domain_Listvalues
                          Where Domain_Code = 'DOMAIN_ALARM_STATE') B2,
                        (Select *
                           From Tp_Domain_Listvalues
                          Where Domain_Code = 'DOMAIN_DR_ID_FLAG') B3,
                        (Select *
                           From Tp_Domain_Listvalues
                          Where Domain_Code = 'DOMAIN_ALARM_OPRT_STATE') B4,
                        Net_Element C1,
                        Net_Element C2,
                        Kpi_Code_List d,
                        Manage_Region e,
                        Kpi_Mapping_Cfg f,
                        Ne_Trans_Alarm Nta,
                        (Select t.Primary_Id "$PRIMARY_ID",
                                Sum(t.Has_Read) "$HAS_READ"
                           From Tree_Privilege t
                          Where t.Tree_Cfg_Name = 'NET_ELEMENT'
                            And t.Assign_Object In ('STAFF_3', 'ORG_2', 'STATION_22')
                     Group By t.Primary_Id) "$PRI_VIEW"
             Where Nvl(a.Config_Ne_Id, a.Ne_Id) ="$PRI_VIEW"."$PRIMARY_ID"(+)
                    And Nvl("$PRI_VIEW"."$HAS_READ", 0) > 0
                    And B1.List_Value = a.Alarm_Type
                    And a.Ne_Id = C1.Ne_Id
                    And B2.List_Value = a.Alarm_State
                    And B3.List_Value = a.Dr_Id || ''
                    And B4.List_Value = a.Oprt_State
                    And a.Config_Ne_Id = C2.Ne_Id(+)
                    And a.Kpi_Id = d.Kpi_Id
                    And a.Kpi_Id = f.Kpi_Id(+)
                    And Nvl(a.Alarm_Region_Origin, '-1') =
                        To_Char(e.Region_Id(+))
                    And a.Ne_Alarm_List_Id = Nta.Ne_Alarm_List_Id(+)
                    And (Select Path || '/'
                           From Net_Element
                          Where Ne_Id = a.Ne_Id) Not Like
                        (Select Path || '/%'
                           From Net_Element
                          Where Ne_Type_Id = 30
                            And Ne_Flag = '6'
                            And State = '0SA') /*非业务系统*/
                    And To_Number(a.Dr_Id) = 0
                  Order By B2.Sort_Id,
                           B4.Sort_Id,
                           a.Alarm_Type,
                           a.Ne_Id,
                           Nvl(a.Last_Send_Time, a.Create_Time) Desc) a) b
  Where b.Sid >= 1
    And b.Sid <= 15;

  首先自己确认了一下这个情况,确实,测试环境中执行该语句,需要跑230多秒,继而在别人和自己的笔记本环境上实验(有将语句涉及到的数据同步进自己的环境),10秒左右结果就出来了。另外随着如下子查询IN值的变化,测试环境服务器上该脚本的执行速度也在变化,当该子查询的结果集很小的时候,查的很快。越大越慢!

                        (Select t.Primary_Id "$PRIMARY_ID",
                                Sum(t.Has_Read) "$HAS_READ"
                           From Tree_Privilege t
                          Where t.Tree_Cfg_Name = 'NET_ELEMENT'
                            And t.Assign_Object In ('STAFF_3', 'ORG_2', 'STATION_22')
                     Group By t.Primary_Id) "$PRI_VIEW"

应OO兄的要求,写好DOC文档,并和附件打包在一起,为了方便阅读,将DOC文档中涉及到附件的地方用超链接,大家可以方便直接在WORD中点击查看文档中涉及到的各个附件。具体见上传的《ORACLE小小说之武朝迷案.rar》。



感谢大家这么支持和认可我写的这个《武朝迷案》,很开心可以帮到大家!
希望大家帮我多推荐一下你的朋友们在京东和当当上买俺的《收获,不止Oracle》了,这是我自认为写的最棒的一本书了,哈哈。请买时请顺便写点书评

书第一次印刷后的一周时间,即第二次印刷了,真给力!
京东:http://book.jd.com/11220905.html
当当:http://product.dangdang.com/product.aspx?product_id=23224719
再次感谢!

ORACLE小小说之武朝迷案.rar

53.2 KB, 下载次数: 461

认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:39 | 显示全部楼层
2、疑云重生

   表面情况都了解清楚了,现在要考虑深入其中,探索真相!

   首先想到的就是,为何在本机上可以跑的很快而在服务器上跑的很慢,不是涉及到的表数据量都一样吗?应该是执行计划出了问题,于是,各自做了个set autotrace traceonly来查看执行计划的差异 (详情请见<<附件服务器autotrac.log>>和<<笔记本autotrace.log>> )

    一分析,发现执行计划是有少许差异,但是逻辑读却有天壤之别,笔记本上788910  consistent gets 而服务器上是37494576  consistent gets  。递归调用对比更是离谱 :笔记本为   0  recursive calls而服务器为1305552  recursive calls 。
    究竟是什么原因导致如此大的差异呢?执行计划虽有差异,但是却并不感觉特别离谱,限入沉思中。。。。

[ 本帖最后由 wabjtam123 于 2010-3-16 13:00 编辑 ]

服务器autotrace.txt

12.53 KB, 下载次数: 58

笔记本autotrace.txt

12.18 KB, 下载次数: 52

使用道具 举报

回复
认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:39 | 显示全部楼层
3、无所适从

   3.1统计信息不全?

    查询后发现系统确有收集统计信息,心中略有不甘,为防止收集不准确,继续做全收集如下(无分区表,所以不用    dbms_stats包了)
    analyze table Ne_Alarm_List             compute statistics for table for all indexes for all indexed columns;
          analyze table Tp_Domain_Listvalues      compute statistics for table for all indexes for all indexed columns;
          analyze table Net_Element               compute statistics for table for all indexes for all indexed columns;
          analyze table Kpi_Code_List             compute statistics for table for all indexes for all indexed columns;
          analyze table Manage_Region             compute statistics for table for all indexes for all indexed columns;
          analyze table Kpi_Mapping_Cfg           compute statistics for table for all indexes for all indexed columns;
          analyze table Ne_Trans_Alarm            compute statistics for table for all indexes for all indexed columns;
           analyze table Tree_Privilege            compute statistics for table for all indexes for all indexed columns;

        收集完毕,发现执行依旧缓慢,执行计划有变,但是罗极读和递归依旧大到惊人!

   3.2 物理分布OR碎片?

    于是检查如下:

   UNIX服务器上表和索引的情况
select table_name,num_rows,blocks from user_tables where lower(table_name) in
    ('ne_alarm_list'
    ,'tp_domain_listvalues'
    ,'net_element'
    ,'kpi_code_list'
    ,'manage_region'
    ,'kpi_mapping_cfg'
    ,'ne_trans_alarm'
    ,'tree_privilege')
   order by table_name;

TABLE_NAME                       NUM_ROWS     BLOCKS
------------------------------ ---------- ----------
KPI_CODE_LIST                       64018       1378
KPI_MAPPING_CFG                      4063         20
MANAGE_REGION                         237          5
NET_ELEMENT                        103485       1882
NE_ALARM_LIST                      138278      15197
NE_TRANS_ALARM                          0          5
TP_DOMAIN_LISTVALUES                 1121         13
TREE_PRIVILEGE                       2443       4780

select table_name,index_name,blevel,leaf_blocks from user_indexes where lower(table_name) in
    ('ne_alarm_list'
    ,'tp_domain_listvalues'
    ,'net_element'
    ,'kpi_code_list'
    ,'manage_region'
    ,'kpi_mapping_cfg'
    ,'ne_trans_alarm'
    ,'tree_privilege')
   order by table_name;

TABLE_NAME                     INDEX_NAME                         BLEVEL LEAF_BLOCKS
------------------------------ ------------------------------ ---------- -----------
KPI_CODE_LIST                  PK_KPI_CODE_LIST                        1         170
KPI_MAPPING_CFG                PK_KPI_MAPPING_CFG                      1          19
MANAGE_REGION                  PK_MANAGE_REGION                        0           1
NET_ELEMENT                    IDX_NE_ELEM_PARENT_NE_ID                1         241
NET_ELEMENT                    IDX_NE_ELEM_NE_NAME                     2         367
NET_ELEMENT                    IDX_STATE_PATH                          2         768
NET_ELEMENT                    PK_NET_ELEMENT                          1         369
NET_ELEMENT                    IDX_NE_ELEM_STATE                       1         234
NET_ELEMENT                    IDX_NE_PATH                             2         656
NET_ELEMENT                    IDX_NEID_NETYPEID                       1         317
NET_ELEMENT                    IDX_NE_ELEM_NET_TYPE_ID                 1         237
NE_ALARM_LIST                  PK_NE_ALARM_LIST                        1         338
NE_TRANS_ALARM                 PK_NE_TRANS_ALARM                       0           0
TREE_PRIVILEGE                 PK_TREE_PRIVILEGE                       2        5059

14 rows selected
   

  笔记本上表和索引的情况

select table_name,num_rows,blocks from user_tables where lower(table_name) in
    ('ne_alarm_list'
    ,'tp_domain_listvalues'
    ,'net_element'
    ,'kpi_code_list'
    ,'manage_region'
    ,'kpi_mapping_cfg'
    ,'ne_trans_alarm'
    ,'tree_privilege')
   order by table_name;

TABLE_NAME                       NUM_ROWS     BLOCKS
------------------------------ ---------- ----------
KPI_CODE_LIST                       64018       1378
KPI_MAPPING_CFG                      4063         20
MANAGE_REGION                         237          5
NET_ELEMENT                        103485       1440
NE_ALARM_LIST                      138278      12901
NE_TRANS_ALARM                          0          0
TP_DOMAIN_LISTVALUES                 1121         13
TREE_PRIVILEGE                       2443         21

SQL> select table_name,index_name,blevel,leaf_blocks from user_indexes where lower(table_name) in
   ('ne_alarm_list'
    ,'tp_domain_listvalues'
    ,'net_element'
    ,'kpi_code_list'
    ,'manage_region'
    ,'kpi_mapping_cfg'
    ,'ne_trans_alarm'
    ,'tree_privilege')
   order by table_name;

TABLE_NAME                     INDEX_NAME                         BLEVEL LEAF_BLOCKS
------------------------------ ------------------------------ ---------- -----------
KPI_CODE_LIST                  PK_KPI_CODE_LIST                        1         230
KPI_MAPPING_CFG                PK_KPI_MAPPING_CFG                      1          16
MANAGE_REGION                  PK_MANAGE_REGION                        0           1
MANAGE_REGION                  IDX_REGION_141                          0           1
NET_ELEMENT                    PK_NET_ELEMENT                          1         332
NET_ELEMENT                    IDX_NE_ELEM_PARENT_NE_ID                1         365
NE_ALARM_LIST                  IDX_CREATE_TIME                         2         544
NE_ALARM_LIST                  IDX_ALARM_LIST_NE_ID                    1         435
NE_ALARM_LIST                  IDX_ALARM_NE_CONFIG_ID                  1         339
NE_ALARM_LIST                  PK_NE_ALARM_LIST                        1         425
NE_ALARM_LIST                  IDX_ALARM_LIST_FLOW_ID                  1         377
NE_TRANS_ALARM                 IDX_NE_TRAN_LIST_ID                     0           0
NE_TRANS_ALARM                 PK_NE_TRANS_ALARM                       0           0
       TREE_PRIVILEGE                 PK_TREE_PRIVILEGE                       1          13

   心头一喜,好像看出TREE_PRIVILEGE 的表和索引的统计信息明显有问题,块是4780对21,叶子的高度是2对1 ,差异还算明显啊!
    于是操刀如下,从数据字典中捞出如下两批语句,分别执行,做好了表重组和索引重建两大工作
   select table_name,index_name,blevel,leaf_blocks
,'alter table '||table_name||' move;','alter index '||index_name||' rebuild;'
from user_indexes where lower(table_name) in
('ne_alarm_list'           
,'tp_domain_listvalues'  
,'net_element'  
,'kpi_code_list'  
,'manage_region'  
,'kpi_mapping_cfg'  
,'ne_trans_alarm'  
,'tree_privilege')
order by table_name;
     操作完以后刚才的4780对21和2对1的情况不见了(具体就不贴出了),变得非常接近了,我感觉问题好像已经搞定了。。。
      欢天喜地一跑脚本,天,依旧奇慢无比,再一看autotrace 跟踪的结果,心凉了半截,执行计划又略为小变动了一下,但是巨大惊人的逻辑读和递归调用形同鬼魅,如影随形,挥之不去!  

    3.3 版本,BUG?

    为什么会有这么多逻辑读,为什么我的笔记本没有这么多逻辑读?我们的环境可是一摸一样啊,并且在别的同事的机器上也是跑的和我笔记本一样顺畅,百思不得其解。。。。。
    会不会是版本问题,BUG? 跳起身来,进行了以下查询
    服务器版本为
    SQL> show parameter feat

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
optimizer_features_enable            string      10.2.0.4

    我笔记本版本为

    SQL> show parameter feat

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
optimizer_features_enable            string      10.2.0.1

    和我笔记本一样OK的别人环境数据库版本为

    SQL> show parameter feat

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
optimizer_features_enable            string      10.2.0.3

眼睛一亮,看来版本问题啊,版本不一样,怪不得莫名奇妙,心跳加速,心里寻思:离谱真的源于BUG?

  猜测不如动手,咋确认呢?来狠的,直接把服务器的版本降下来
  SQL> alter system set optimizer_features_enable='10.2.0.3';
  System altered.
  
  继续执行服务器环境SQL语句,发现没效果,重启数据库,依然如故!

  3.4 分页调优?

  大家对分页调优写法都有了解,本案例中由于如下子查询语句和整个结果集关联,并有 And Nvl("$PRI_VIEW"."$HAS_READ", 0) > 0的条件,导致无法将整个结果集先分页再和子查询关联,因为这样只取ROWNUM范围15行的值参与关联,结果就错了!
  

                        (Select t.Primary_Id "$PRIMARY_ID",
                                Sum(t.Has_Read) "$HAS_READ"
                           From Tree_Privilege t
                          Where t.Tree_Cfg_Name = 'NET_ELEMENT'
                            And t.Assign_Object In ('STAFF_3', 'ORG_2', 'STATION_22')
                     Group By t.Primary_Id) "$PRI_VIEW"
  所以本案例中,分页调优难以凑效!


  唉,长叹一声,无所适从!

[ 本帖最后由 wabjtam123 于 2010-3-16 18:56 编辑 ]

使用道具 举报

回复
认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:39 | 显示全部楼层
4、峰回路转
   
   为什么会有那么多次的逻辑读和递归?看来看执行计划还是太表面了,难以回答ORACLE内部在做啥小动作,不查出问题所在,不将谜团大白于天下,誓不罢休!
   试试10046trace吧,看看整个执行开始到结束,到底在执行什么,等待什么?玩啥猫腻!
   分别做了两次10046TRACE,具体见附件10046trace_notebook.txt》和《10046trace_service.txt》

   仔细观察,终于有重大发现了,笔记本中环境10046trace_notebook.txt

   SELECT PERSON
FROM
TACHE WHERE FLOW_ID = :B1 AND STATE <> 'F'


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  65249      2.26       1.90          0          0          0           0
Fetch    65249      1.23       1.30          0      65243          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   130499      3.50       3.20          0      65243          0           0
   

这里怎么跑出一个这样的语句,Eeecute6万多次最终获取0行

  而10046trace_service.txt中类似的地方确实如下,rows显示为65331和前者为0!有所发现。

SELECT PERSON
FROM
TACHE WHERE FLOW_ID = :B1 AND STATE <> 'F'


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  65339      0.78       0.75          0          0          0           0
Fetch   130670    148.79     145.17          0   32714110          0       65331
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   196010    149.58     145.93          0   32714110          0       65331


继续分析发现 10046trace_service.txt还有如下调用,而10046trace_notebook.txt根本找不到如下两处调用!


SELECT PKP_FLOW_FUNCTION.GETSTAFFNAMEBYID(LTRIM(RTRIM(TO_CHAR(:B1 ))))
FROM
DUAL


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 522102      7.43       6.78          0          0          0           0
Fetch   522102     42.59      42.17          0          0          0      522102
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1044205     50.03      48.96          0          0          0      522102

SELECT NAME
FROM
STAFF_INFO WHERE STAFF_ID = :B1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 522102      8.51       7.78          0          0          0           0
Fetch   522102     21.35      20.21          0    4110939          0      456771
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1044205     29.86      27.99          0    4110939          0      456771


仔细观察,还有新发现, 10046trace_service.txt还有如下递归调用 统计信息,而10046trace_notebook.txt
根本找不到!

RECURSIVE STATEMENTS
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse       11      0.00       0.01          0          0          0           0
Execute 1109552     16.74      15.33          0          0          0           0
Fetch   1174883    212.73     207.57          1   36825069          0     1044211
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   2284446    229.48     222.92          1   36825069          0     1044211

看来,这个递归毫无疑问来自函数的调用,仔细回到复杂的SQL脚本一看,发现了原先SQL中有函数
Pkp_Flow_Function.Getflowcurstaffname(a.Flow_Id) Flow_Operator,
查看这个函数调用的代码写法

FUNCTION getFlowCurStaffName(in_flow_id in number) RETURN VARCHAR2 IS
    ss         VARCHAR2(255);
    person1    VARCHAR2(255);
    v_tabArray PKP_STRING_UTIL.varArray;
    CURSOR c2 IS
      SELECT person
        FROM tache
       WHERE flow_id = in_flow_id
         AND STATE <> 'F';
  BEGIN
    --从环节表中取得
    FOR rel1 IN c2 LOOP
      v_tabArray := PKP_STRING_UTIL.split(rel1.person, ',');
      FOR i IN 1 .. v_tabArray.COUNT() LOOP
        SELECT getStaffNameById(LTRIM(RTRIM(TO_CHAR(v_tabArray(i)))))
          INTO person1
          FROM dual;
        ss := ss || person1 || ' ';
      END LOOP;
    END LOOP;

    RETURN(ss);
  END getFlowCurStaffName;


其中getFlowCurStaffName函数还调用了getStaffNameById函数,具体如下:

  FUNCTION getStaffNameById(in_staff_id IN varchar2) return varchar2 is
    ret varchar2(255);
  begin
    select NAME INTO ret FROM STAFF_INFO WHERE STAFF_ID = in_staff_id;
    return(ret);
  end getStaffNameById;

而这些语句都出现在刚才的 10046trace_service.txt中,看来问题就出在这个函数调用中了!
虽然函数中的语句为什么与部分没有出现在10046trace_notebook.txt中这个问题我还无法回答,但是我相信,真相已经离我们很近了!

[ 本帖最后由 wabjtam123 于 2010-3-16 13:01 编辑 ]

10046trace_service.txt

16.89 KB, 下载次数: 40

10046trace_notebook.txt

15.57 KB, 下载次数: 37

使用道具 举报

回复
认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:40 | 显示全部楼层
5、大白天下

   目标既锁定函数为“元凶巨恶”,那就除恶务尽!在剔除了Pkp_Flow_Function.Getflowcurstaffname(a.Flow_Id) Flow_Operator 后,发现服务器环境的SQL从原先的230秒瞬间降低为3秒,乖乖,料到有效果不假,但没料到到这么有效果!
再一看autotrace ,不得不相信真能有这样的提升,逻辑读为: 82617  consistent gets 而原先为:37494576  consistent gets

    到此其实还有一事未明,就是为什么说笔记本环境没有那么多递归调用和逻辑读呢,在前面的基础上继续探讨,问题就变的容易了,因为前面的函数中

    CURSOR c2 IS
      SELECT person
        FROM tache
       WHERE flow_id = in_flow_id
         AND STATE <> 'F';
这个 tache表在笔记本及其他环境中是没记录的,而服务器及生产是有2万多条记录!

   发现这个以后,一切谜团都解开了!

   1、为什么笔记本环境没有看到递归调用?
          ------这个外循环没值,递啥归啊?
   2、为什么服务器环境看到大量逻辑读?
          ------一层套一层,在C2的CURSOR不是空的情况下,自然就调用到了getFlowCurStaffName,加上外面的6万次循环,能 不产生大量逻辑读吗?笔记本环境C2是空的,做啥啊,呵呵。
   3、为什么生产服务器环境时快时慢
         ----存在函数调用,由于函数调用次数和外层结果集的记录有关,所以时快时慢,笔记本环境C2游标是空的,当然稳定!

[ 本帖最后由 wabjtam123 于 2010-3-16 19:36 编辑 ]

使用道具 举报

回复
认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:40 | 显示全部楼层
6、乘胜追击

现在问题是如何解决这个问题,因为去除该函数毕竟不是解决问题的正道!

先实验一个自定义普通函数

(其中set_clinet_info函数这个是为了测试最终该函数被调用多少次,实用技术,简单易学,值得推广)
create or replace function f(id in number)
  Return  number
is
begin
  dbms_application_info.set_client_info(userenv('client_info')+1);
  return id;
end a;
/

接着改写代码,将 Pkp_Flow_Function.Getflowcurstaffname(a.Flow_Id) Flow_Operator 修改为f(a.Flow_Id) Flow_Operator,
发现整体运行时间非常短,大致5秒,说明Pkp_Flow_Function确实是做太多事了。

通过开始exec dbms_application_info.set_client_info(0);
后续执行select userenv('client_info') from dual;来观察,发现该函数F(a.Flow_Id) 是执行了65339次,和10046trace的一致。具体见附件《自定义函数测试调用次数.txt》
另外Pkp_Flow_Function.Getflowcurstaffname(a.Flow_Id)也是执行了65339次 ,具体见附件《测试原函数调用次数.txt》 而该函数的子函数却调用了456771次!!!原因在于 FOR i IN 1 .. v_tabArray.COUNT() LOOP这循环是对表的字段里的内容进行循环,(字段中的内容用逗号分割符进行分割,如何拆开循环)
具体见附件《测试原函数的子函数调用次数.txt》


  看来解决的思路如下

  1、尽量减少外部调用,如何能避免调用65339次

   经过分析,由于分页的缘故,每次都只会展现15条记录,而这个函数经确认只是取得姓名的字段,完全可以放在最后执行,修改为将 Pkp_Flow_Function.Getflowcurstaffname(a.Flow_Id) Flow_Operator放置于整个结果集的外面,这样,调用立减为15次。性能瞬间提高为4-5秒完成任务!优化的最终代码见《终极解决.sql》,其中分页其实并无效果,只是写写而已。


  2、进一步完善,Pkp_Flow_Function调用次数过多,可考虑用表关联改写该函数的代码,减少不必要的递归和调用(这个待后续再考虑完善)

另外细心的朋友在分析《10046trace_service.txt》的时候或许注意到
SELECT PERSON
FROM
TACHE WHERE FLOW_ID = :B1 AND STATE <> 'F'
该语句有着惊人的逻辑读!32714110/65331=500意味着每获取一行需要进行500次的逻辑读,由此可见,该语句应该可以优化,果然,当前语句是全表扫描。
建如下索引后,继续执行,立即发现代价从原先的111缩短到2,收效相当明显!

create index idx_union on tache (flow_id,person,state)
具体可以看《单次逻辑读优化.txt》 ,收效相当明显,在我未进行上述调整函数调用的时候,优化的效果是:从每获取一行需要进行500次的逻辑读到每获取一行需要3次逻辑读。
SELECT PERSON
FROM
TACHE WHERE FLOW_ID = :B1 AND STATE <> 'F'


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  65339      0.85       0.79          0          0          0           0
Fetch   130670      1.27       1.11          3     195993          0       65331
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   196010      2.13       1.90          3     195993          0       65331

《单次逻辑读优化.txt》的下半部分贴着auto trace的结果,就不另外贴个TXT了,大家可以看到由于函数调用这个硬伤未处理,递归依然极大,但是逻辑读变小确实不争的事实。事实上是,这个语句在66秒完成,虽说不如意,但总比以前的230多秒好,加上致命硬伤函数调用一解决,最终在3秒多执行完毕。(只改函数调用的致命伤而不优化这个语句,执行是在5秒完成)


[ 本帖最后由 wabjtam123 于 2010-3-16 18:35 编辑 ]

自定义函数测试调用次数.txt

17.84 KB, 下载次数: 46

测试原函数调用次数.txt

19.61 KB, 下载次数: 31

测试原函数的子函数调用次数.txt

19.91 KB, 下载次数: 36

终极解决.sql

5.22 KB, 下载次数: 33

单次逻辑读优化.txt

29.63 KB, 下载次数: 42

使用道具 举报

回复
认证徽章
论坛徽章:
50
2014年世界杯参赛球队: 荷兰
日期:2014-07-11 07:56:59蛋疼蛋
日期:2012-03-06 07:22:542012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-02-13 15:09:522012新春纪念徽章
日期:2012-01-04 11:53:29蛋疼蛋
日期:2011-11-11 15:47:00ITPUB十周年纪念徽章
日期:2011-11-01 16:23:26
发表于 2010-3-16 12:40 | 显示全部楼层
7、余音绕梁
事情算是最终解决了,想想,有如下几点总结
   1、开发人员尽量避免写过多的函数调用,这样将有可能导致惊人的递归调用和逻辑读,此外在SQL中大量调用函数,也容易导致SQL引擎和PLSQL引擎进行大量的上下文切换,这样性能必定收到影响。
   2、查问题不能想当然,其实我们的笔记本环境和服务器环境大多记录是一样的,唯独tache表是不同,笔记本是空记录,就这一处差别,让我们限入迷茫中。
   3、解决问题要所有的疑惑都解决了,才是真正解决问题,比如我们考虑改写SQL,分页调优,即便真的变快了,能回答为什么笔记本不需要改写SQL就能快吗?
   4、解决问题可以从 看执行计划----看逻辑读递归-------10046trace  这种方式深入。
当然中间少不了各种猜想。
比如降低数据库版本,在本案例中无用,或许在下一个案例中,就是你发现问题的一个方法。
比如分页查询,在本案例中或许无用,但是在别的场合,就有可能会有用武之地。
比如看统计信息收集情况及表物理索引物理分布,这些或许就是在下一案例中的有力武器。
    此外优化的思路莫过于减少访问量和增大吞吐量,而访问量是由单次访问量和执行的次数决定的,本次优化处理函数写法就是减少了执行次数,而修改那条SQL则是减少单次的访问量!
   5、其实本案例并未完,该过程的调用写法一定不是最佳的写法,所以要有精益求精的精神,后续,考虑优化这个过程。因为如果不是需求每次只要展现15页,优化这个函数就已成必然!

[ 本帖最后由 wabjtam123 于 2010-3-16 19:41 编辑 ]

使用道具 举报

回复
认证徽章
论坛徽章:
9
ITPUB社区OCM联盟徽章
日期:2013-03-27 11:17:11奥运纪念徽章
日期:2013-06-18 09:13:52ITPUB社区千里马徽章
日期:2013-08-22 09:58:03大众
日期:2013-08-30 14:51:33路虎
日期:2013-12-01 18:25:42
发表于 2010-3-16 12:52 | 显示全部楼层
写小说啊。精彩 呵呵!

使用道具 举报

回复
认证徽章
论坛徽章:
28
ITPUB元老
日期:2008-01-15 09:32:23授权会员
日期:2008-08-13 23:37:22ITPUB十周年纪念徽章
日期:2011-09-27 16:30:47迷宫蛋
日期:2012-02-25 10:02:36秀才
日期:2017-03-20 13:42:20布鲁克
日期:2018-02-23 09:22:57
发表于 2010-3-16 13:05 | 显示全部楼层
看完,学习了。

使用道具 举报

回复
论坛徽章:
0
发表于 2010-3-16 13:33 | 显示全部楼层
大概看完了,好多地方不懂……
真是高手啊!

能否帮忙看看我那DB是怎么回事么:http://www.itpub.net/thread-1279673-1-1.html

能否帮忙诊断一下!

使用道具 举报

回复

您需要登录后才可以回帖 登录 | 注册

本版积分规则 发表回复

TOP技术积分榜 社区积分榜 徽章 团队 统计 知识索引树 积分竞拍 文本模式 帮助
  ITPUB首页 | ITPUB论坛 | 数据库技术 | 企业信息化 | 开发技术 | 微软技术 | 软件工程与项目管理 | IBM技术园地 | 行业纵向讨论 | IT招聘 | IT文档
  ChinaUnix | ChinaUnix博客 | ChinaUnix论坛
CopyRight 1999-2011 itpub.net All Right Reserved. 北京盛拓优讯信息技术有限公司版权所有 联系我们 
京ICP备09055130号-4  北京市公安局海淀分局网监中心备案编号:11010802021510 广播电视节目制作经营许可证:编号(京)字第1149号
  
快速回复 返回顶部 返回列表