Bilgisayar Mühendisleri Portalı

Veritabanı seviyesinde, yazılan kod ya da kod parçasında bir yavaşlık, performans düşüklüğü varsa bunun nedenini araştırmak gerekir.Bunu yapabilmenin en iyi yolu da “SQL Trace” almaktır.Peki nedir SQL Trace?

SQL Trace istenilen bir andan yine istenilen bir ana kadar olan zaman dilimi içersinde session ya da veritabanı seviyesinde gerçekleşen tüm olayların CPU da harcanan zaman, parse-execute-fetch aşamalarında gecen süre ve adet bilgileri , I/O miktarı gibi SQL in performansı ile direk alakalı bilgilerin okunabildiği ortamdır.TKPROF ta alınan bu SQL Trace’in okunabilirliğini arttırmaya yönelik Oracle ın bir ürünüdür.Öncelikle veritabanının trace dosyalarını nereye attığını tespit etmek gerekir. 

select value from v$parameter where name = ‘user_dump_dest’

ile dosyaların atıldıgı dizin bilgisini alabiliriz.

NOT : ”USER_DUMP_DEST” bir init.ora parametresidir.SESSION bazında değil ama SYSTEM seviyesinde aşağıdaki komutla değiştirilebilir :
            alter system set user_dump_dest=”d:sqltrace”;

SQL Trace dosyaları session bazlıdır, “kullanıcı(user)” bazlı değildir.Aşağıdaki script ile veritabanında bulunan kullanıcılara ait trace dosyaları bulunabilir :

select b.username, c.value || ‘\’ || lower(d.value) || ‘_ora_’ ||
       to_char(a.spid, ‘fm00000′) || ‘.trc’ “TRACE_FILE”,
       a.pid PID, b.serial#  session_number
from v$process a, v$session b, v$parameter c, v$parameter d
where a.addr   = b.paddr
and c.name     = ‘user_dump_dest’
and d.name     = ‘db_name’
and b.username is not null;

Burada dikkat edilmesi gerek bir başka nokta da oluşan trace dosyalarının isimlendirme yöntemidir.Örneğin yukardaki sorguda “_ora_” gibi bir formatlama yapıldı.9.x ve yukarısında bu şeklidedir.Aşağıda örnekler verilmiştir :

Version     Isimlendirme şablonu    Örnek
 
7.3.4         snnn_pid.trc                      s000_1234.trc
8.0.5         ora_pid_trc                       ora_1234.trc
8.1.7         ora_pid_instance.trc          ora_1234_INSTNC1.trc
9.x-10g.x   instance_ora_pid.trc          INSTNC1_ora_1357.trc

Şimdi de SQL Trace ‘i “session” bazında  alabilmek için yapılması gereken adımlara bakalım :

1) CPU da harcanan zaman, bekleme süreleri gibi bilgileri alabilmek için :alter session set timed_statistics = true;

2) SQL Trace i kullanabilmek için :
alter session set sql_trace = true;

NOT : Aynı işlem DBMS_SESSION.SET_SQL_TRACE(TRUE); ile de yapılabilir.

NOT : Bir DBA başka bir session içinde bu özelliği aktif edebilir.Bunun içinDBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(sid,serial#,sql_trace true/false);kullanılır.

Uygun ”sid” ve “serial#” degerleri ilgili kullanıcı için v$session tablosundan alınabilir.

3) Trace dosyasının boyutunu sınırsıza cekmek iyi olabilir :
alter session set max_dump_file_size =unlimited;

4) Her seviye de istatistik alabilmek için :
alter session set statistics_level = all ;

5) Oluşacak dosyanın adına okunabilirlik amacıyla eklenti yapmak için :
alter session set tracefile_identifier = ‘user_sql_trace’;

Örneğin normalde “xe_ora_3584.trc” adında olşacak olan dosya “xe_ora_3584_user_sql_trace.trc” adı ile oluşacaktır.

6) “wait events” bilgilerinin trace dosyasına yazıldıgından emin olmak için :alter session set events ‘10046 TRACE NAME CONTEXT FOREVER, LEVEL 8′;

7) Trace alacağımız kod çalıştırılır.(SQL , PL/SQL …) Istediğimiz kod çalıştıktan sonra trace almayı durdurmak için :
alter session set sql_trace = false;NOT : işlem DBMS_SESSION.SET_SQL_TRACE(FALSE); ile de yapılabilir.     

alter session set events ‘10046 TRACE NAME CONTEXT OFF’;

NOT: Yeterli miktar veri toplandığından emin olunduğunda trace özelliği kapatılmalıdır.Yoksa dosya şişer, diskte yer problemleri başlayabilir.Bu işlemler sonucunda “USER_DUMP_DEST” dizini altında “xxxuser_sql_trace.trc” adlı dosya oluşur.Ancak bu dosya okunabilirlik anlamında sıkıntı olan bir dosya.

Okunabilirliği arttırmak amacıyla Oracle “TKPROF” eklentisi yapmıştır.İşletim sisteminde “command prompt“ ta örneğin aşağıdaki gibi (Windows ta):tkprof ..\UDUMP\xe_ora_3060_user_sql_trace .trc D:\ sql_trace.txt explain=test/test sys=yes waits= yesşeklinde olabilir.

“UDUMP\xe_ora_3060_user_sql_trace .trc”  - - > oluşan trace dosyası
“D:\ sql_trace.txt”                                     - - > oluşacak yeni dosya adı
“explain=test/test sys=yes waits= yes”       - - > TKPROF parametreleriPek çok TKPROF parametresi ve kullanımı var.Ihtiyaca göre set edilebilir.Detay bilgiyi aşağıdaki linkten bulabilirsiniz :
http://download-uk.oracle.com/docs/cd/B19306_01/server.102/b14211/sqltrace.htmOluşan 

trace dosyası örneğin aşağıdaki gibi olacaktır :
…………………..
PARSING IN CURSOR #8 len=41 dep=0 uid=0 oct=3 lid=0 tim=19068624436 hv=253931300 ad=’1d337414′
select * from ttest where object_id = 123
END OF STMT
PARSE #8:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=19068624429
EXEC #8:c=0,e=79,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=19068682136
WAIT #8: nam=’SQL*Net message to client’ ela= 9 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068691291
FETCH #8:c=0,e=89,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,tim=19068700670
WAIT #8: nam=’SQL*Net message from client’ ela= 269 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068710270
FETCH #8:c=0,e=57,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,tim=19068720765
WAIT #8: nam=’SQL*Net message to client’ ela= 10 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068759424
WAIT #8: nam=’SQL*Net message from client’ ela= 347 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068769859
*** SESSION ID:(25.70) 2007-01-22 15:39:16.740
STAT #8 id=1 cnt=1 pid=0 pos=1 obj=14673 op=’TABLE ACCESS BY INDEX ROWID TTEST (cr=4 pr=0 pw=0 time=127 us)’
STAT #8 id=2 cnt=1 pid=1 pos=1 obj=14674 op=’INDEX RANGE SCAN TTEST_ID_IDX (cr=3 pr=0 pw=0 time=92 us)’
WAIT #0: nam=’SQL*Net message to client’ ela= 7 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068811087
WAIT #0: nam=’SQL*Net message from client’ ela= 335 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068821991
=====================
PARSING IN CURSOR #1 len=45 dep=0 uid=0 oct=7 lid=0 tim=19068832275 hv=349105966 ad=’1d0ef7cc’
DELETE FROM PLAN_TABLE WHERE STATEMENT_ID=:1
END OF STMT
PARSE #1:c=0,e=53,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=19068832269
EXEC #1:c=0,e=181,p=0,cr=3,cu=0,mis=0,r=0,dep=0,og=1,tim=19068887749
WAIT #1: nam=’SQL*Net message to client’ ela= 8 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068898228
WAIT #1: nam=’SQL*Net message from client’ ela= 145 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=19068908629
STAT #1 id=1 cnt=0 pid=0 pos=1 obj=0 op=’DELETE  PLAN_TABLE$ (cr=3 pr=0 pw=0 time=106 us)’
STAT #1 id=2 cnt=0 pid=1 pos=1 obj=8655 op=’TABLE ACCESS FULL PLAN_TABLE$ (cr=3 pr=0 pw=0 time=96 us)’
…………………..

TKPROF kullandıktan sonra olusan dosya içeriği ise aşağıdaki gibi olacaktır :
…………………..
EXPLAIN PLAN SET STATEMENT_ID=’PLUS4294967295′ FOR select * from ttest where
  object_id = 123
call        count       cpu    elapsed       disk      query    current    rows
——- ——  ——– ———- ———- ———- ———-  ———-
Parse        2          0.00       0.00          0          0          0           0
Execute     2          0.03       0.20          0          0          0           0
Fetch        0           0.00       0.00          0          0          0           0
——- ——  ——– ———- ———- ———- ———-  ———-
total         4            0.03       0.20          0          0          0           0 

 Hakkı Oktay
http://hakkioktay.wordpress.com