2017-09-23 74 views
2

我有一個oracle-10046-aka。 SQLTRACE文件類似這樣的結構::如何在代碼未檢測到時將一組SQL執行分組?

Oracle Release 11.2 
PARSING IN CURSOR #1 len=20 dep=0 uid=7 oct=6 lid=7 tim=2 hv=1 ad='1' sqlid='A' 
insert 
END OF STMT 
PARSING IN CURSOR #2 len=20 dep=0 uid=7 oct=6 lid=7 tim=2 hv=2 ad='2' sqlid='r' 
update next_step 
END OF STMT 
PARSING IN CURSOR #3 len=20 dep=0 uid=7 oct=6 lid=7 tim=2 hv=3 ad='3' sqlid='B' 
update complete 
END OF STMT 
PARSING IN CURSOR #4 len=20 dep=0 uid=7 oct=3 lid=7 tim=2 hv=4 ad='4' sqlid='X' 
select X 
END OF STMT 
PARSING IN CURSOR #5 len=20 dep=0 uid=7 oct=3 lid=7 tim=2 hv=5 ad='5' sqlid='Y' 
select Y 
END OF STMT 

EXEC#1:c=1,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=100 
EXEC#2:c=2,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=200 
EXEC#3:c=4,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=300 

EXEC#4:c=5,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=310 
EXEC#5:c=6,e=6,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=320 

EXEC#1:c=8,e=8,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=400 
EXEC#2:c=16,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=416 
EXEC#3:c=32,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=448 

我確定SQLID「A」作爲特定序列的開始,和SQLID「B」,因爲它的結束。在我的例子中,只有sqlid'r',但它可能更多,甚至不是相同的SQL或SQL序列。 像sqlid'X'和'Y'這樣的其他SQL不在我感興趣的序列中,因此應該可見。

我現在選擇的工具是來自Methodr的Method R Tools產品的mrskew。因爲它可以用Perl代碼擴展,所以我相信這可以完成,但是由於我對mrskew內部的理解,我的Perl技能有限。

我非常感謝這裏的任何提示或幫助。

回答

3

使用您的測試數據martin1.trc,我創建了rc文件martin1.rc。

--init=' 
    my $xfrm_id; 
    sub xfrm { 
     $xfrm_id = $exec_id if ($sqlid//"") eq "A"; 
     return $xfrm_id//$exec_id; 
    } 
' 
--group='xfrm()' 

然後我執行mrskew --rc martin1.rc martin1.trc,我得到這樣的輸出:

'xfrm()' DURATION  % CALLS  MEAN  MIN  MAX 
--------- -------- ------ ----- -------- -------- -------- 
     25 0.000056 75.7%  3 0.000019 0.000008 0.000032 
     18 0.000018 24.3%  5 0.000004 0.000001 0.000006 
--------- -------- ------ ----- -------- -------- -------- 
TOTAL (2) 0.000074 100.0%  8 0.000009 0.000001 0.000032 

此報告顯示有趣的交易兩次​​執行。最有意思的(最大響應時間)事務執行從跟蹤文件行25開始,並在總響應時間內超過3個dbcalls貢獻了0.000056秒(總數的75.7%)。另一個最有趣的執行從第18行開始,貢獻了其他24.3%。我們知道第22-23行是無趣的,但簡單的方法不區分它們。這就是爲什麼報告說,從第18行開始的執行有0.000018秒的5次dbcalls而不是0.000007秒的3次dbcalls。

如果我們顯著改變變換函數,那麼我們可以處理在聲明B(即使B是EXEC其次是其它b- dbcalls(例如,提取)下面是martin2.rc終止該事務:

--init=' 
    my $sawB; 
    my $xfrm_id; 
    sub xfrm { 
     if (($sqlid//"") eq "A") { 
      $xfrm_id = $exec_id; # global scope maintains state 
     } else { 
      if (($sqlid//"") eq "B") { 
       $sawB = 1; 
      } else { 
       if ($sawB) { 
        $sawB = undef; 
        $xfrm_id = undef; 
       } 
      } 
     } 
     return $xfrm_id//0; 
    } 
' 
--group='xfrm()' 

爲了符合配置文件的概念(總數代表整個體驗的總數),我決定將所有不感興趣的事務dbcalls轉換爲0,這是一個不能出現在文件中的行號。可以看到有趣的交易如何在整個體驗中排名。

$ mrskew --rc martin2.rc martin1.trc 

'xfrm()' DURATION  % CALLS  MEAN  MIN  MAX 
--------- -------- ------ ----- -------- -------- -------- 
     25 0.000056 75.7%  3 0.000019 0.000008 0.000032 
     0 0.000011 14.9%  2 0.000005 0.000005 0.000006 
     18 0.000007 9.5%  3 0.000002 0.000001 0.000004 
--------- -------- ------ ----- -------- -------- -------- 
TOTAL (3) 0.000074 100.0%  8 0.000009 0.000001 0.000032 

如果我複製線20(這需要4微秒),然後輸出這樣說:

'xfrm()' DURATION  % CALLS  MEAN  MIN  MAX 
--------- -------- ------ ----- -------- -------- -------- 
     26 0.000056 71.8%  3 0.000019 0.000008 0.000032 
     18 0.000011 14.1%  4 0.000003 0.000001 0.000004 
     0 0.000011 14.1%  2 0.000005 0.000005 0.000006 
--------- -------- ------ ----- -------- -------- -------- 
TOTAL (3) 0.000078 100.0%  9 0.000009 0.000001 0.000032 

你可以看到,上線18日起有趣的交易已經結束4個dbcalls貢獻11微秒。這似乎是一個更完整的測試,證明martin2.rc的合適性。

在上一次報告中,您可以看到有趣的交易佔文件總響應時間的71.8%+ 14.1%= 85.9%。如果你進一步修改轉換函數(向讀者行使),那麼你可以聚合成「有趣」和「不有趣」,而不是我所做的,這是增加兩個百分比。

+0

謝謝傑夫,那正是我在找的東西。由於我的規範並不是100%清晰,所以我將所有修改視爲_exercise留給讀者_。 –