Oracle veritabanında yanıt süresini iyileştirme modeli - LOGOFF tetikleyicileri

Kullanıcılarınıza performansın ne anlama geldiğini sorduğunuzda muhtemelen hemen hemen hepsinin cevabı yaptıkları işlemlerin yanıt zamanı veya tamamlanma zamanı esnasında geçen süre olacaktır. Kullanıcılar bizleri performans problemleri için aradığında, işlemin yanıt süresi veya veri işlem ile ilgili yaşadıkları darboğazdan şikayet ederler. Bir kısım veritabanı hit ratio durumlarının kötü olduğu, aşırı önbellek tampon işlemleri olduğu, çok fazla fiziksel okuma meydana geldiği veya SQL komutlarının çok fazla CPU kullandığı gibi teknik sorunlardan şikayet etmezler elbette.

OWI(Oracle Bekleme Arayüzü), veritabanı yanıt sürelerini belirlemek için çok önemli bir rol oynamaktadır. OWI, bir oturumun açık olduğu süre boyunca karşılaştığı darboğazları belirlemek için yüzyüze kalınan bekleme olaylarını ve bu esnada geçen zamanı izler. Veritabanı yanıt süresi “hizmet süresi” ve “bekleme süresi” parametrelerini içermektedir.

Yanıt süresi = Hizmet Süresi + Bekleme Süresi

Yanıt süresi, bir prosesin CPU üzerinde harcadığı zamanın toplamıdır. Bekleme süresi ise, bir prosesin işleme devam etmeden önce çeşitli kaynakların uygun olması esnasında beklediği toplam süredir.  Bu formül, herhangi bir zamanda, bir prosesin ya CPU üzerinde bir isteği hizmete aktif olarak sunması yada CPU dışında hizmete sunması ve bekleme durumunda olması şeklinde bir kanıya dayanmaktadır. Bu durumda veritabanı yanıt süresini, hizmet süresini veya bekleme süresini veya her ikisini kısaltarak iyileştirebiliriz.

Aslında bu kavramlar anlaşılması zor değildir, çünkü zaten günlük hayattada bunlarla karşılaşmaktayız. Hepimiz süpermarketlere alışveriş yapmaya gideriz. Alışveriş sonunda kasaya ödeme için gittiğinizi düşünün. Peki nedir bu süreçte yanıt süresi? Kasada işlem için beklediğimiz süre ve kasiyerin ne kadar sürede işlemi tamamladığının toplamı, işte yanıt süresidir. Eğer haftasonu süpermarkete gidersek, yanıt süresi kasada yaşanan yoğunluktan dolayı uzayacaktır(yüksek bekleme zamanı) veya acemi bir kasiyer ile karşılaşırsak barkotların taranmasında sıkıntı olabilecek ve ürünleri scannera manuel girmeye çalışmasından dolayı işlem süresi uzayacaktır(yüksek hizmet süresi).Böylece, supermarkette işlem süresinin iyileştirilmesi için ya alışveriş yoğunluğun olmadığı zamanlar tercih edilecek(düşük bekleme süresi) veya süpermarkette daha önceden tanıdığımız uzman bir kasiyerde işlem yaptırmamız(düşük servis süresi) faydalı olacaktır.

Ancak burada dikkat edilmesi gereken nokta, toplam yanıt süresi, veritabanı yanıt süresini aşmaktadır. Uçtan uca yanıt süresi; kuyruk süresi, kullanılan switch şartları, bellek yönetim darboğazları, network ve middle-tier gecikmeleri gibi sunucu  tabanlı gecikmeleride içermektedir. Burada bizim amacımız, veritabanının cevap süresine bir bütün olarak bakmaktır, bu sebeple yukardaki formülü Oracle veritabanı için aşağıdaki gibi değiştirmemiz gerekecektir.

Yanıt süresi = “CPU used when call started” + Oturum TIME_WAITED

Oturum seviyesinde, hizmet süresi V$SESSTAT görünümünde “CPU used when call started” olarak adlandırılır ve bekleme süresi, belirli bir oturum için V$SESSION_EVENT görünümünde tüm önplan tabanlı bekleme olayları için TIME_WAITED değerinin toplamıdır. “CPU used when call started” istatistiği üç kategoriyi kapsar: “Ayrıştırma(parsing) için kullanılan CPU, takrarlanan çağrılar için kullanılan CPU ve normal işler için kullanılan CPU. Tekrarlanan çağrılar için için kullanılan CPU, recursive cpu usage istatistiği ile izlenirken, ayrıştırma için kullanılan CPU ise parse time CPU ile izlenir. Normal işler için kullanılan CPU (CPU_W) ise aşağıdaki şekilde hesaplanmaktadır.

CPU_W = “CPU used when call started” – “parse time CPU” – “recursive cpu usage”

Not: V$SYSTAT ve V$SESSTAT görünümleri içinde “CPU used by this session” ve “CPU used when call started” şeklinde iki istatistik vardır. “CPU used by this session” istatistiği için buglar olduğundan dolayı her iki değer aşağı yukarı aynı gözükmektedir. Bu sebeple “CPU used when call started” daha kararlı ve doğru sonuçlar vermektedir. Ayrıca CPU istatistikleri çağrı sonunda güncellenmesine rağmen bekleme olayı istatistikleri gerçek zamanlı oluşur. Yani, uzun bir SQL komutu, çağrı sonucu oturuma dönene kadar CPU istatistikleri güncellenmez ve istatistiklerin toplandığı zamandaki devam eden SQL komutlarının CPU üzerindeki yanıt ve bekleme süreleri elde edilemez.  Bu tarz CPU bekleme olayları tespit ve çözümü ile ilgili 8 Nisan 2011 tarihli analiz yazımı inceleyebilirsiniz.

Oturum seviyesinde veritabanı yanıt süresinin doğru olarak ölçülebilmesinin yolu, oturum bağlantısının sona ermesinden hemen önce toplanmasıdır, ancak bunun manuel olarak yapılması neredeyse imkansızdır. İşte bu işlemi otomatik yapmak üzere bir BEFORE LOGOFF tetikleyicisi kullanılabilir.Bu tetikleyici, oturum sonlanmadan hemen önce V$SESSION_EVENT ve V$SESSTAT görünümlerinden oturum seviyesinde özet bekleme olayı verilerini ve CPU istatistiklerini toplamak için kullanılabilir. Bunun faydaları arasında veritabanına bağlanmış tüm önplan proseslerine ait olayların görülebilmesi sayılabilir. Böylece, her bir oturum içinden en kötü darboğazlar kolayca tespit edilebilir ve çalıştırdığı prosesin yavaşlığından şikayet eden ilgili kişiye bir cevap verilebilir. Eğer pek çok veritabanı yönetiyor ve oturum seviyesinde özet performans verisi ile ilgileniyorsanız, veritabanı LOGOFF tetikleyicileri kullanmak çok avantajlı olacaktır. Performans sorununa neyin sebep olduğunu bilemeyebilirsiniz, ancak en azından başlıca semptomların neler olduğu hakkında kolayca cevap bulabilirsiniz.Tabii, sonucunda bu noktalara odaklanmak proaktif bir performans geliştirme inşasında temel teşkil edecektir.

Performans verileri toplayıcısı olarak veritabanı LOGOFF tetikleyicisinin kullanımı; htoplanacak istatitstiklerin her zaman hazır olması ve çalışırken sistem üzerinde düşük işyükü sebebiyle çok faydalıdır. Bu metot, instance genelinde izlemeye izin verir. Hangi oturumun izlenmesine gerek olduğunun seçimi veya sabahın erken saatlerinde ekran başına oturup hangi oturum darboğazda gibi paranoyakça zahmetlerde ortadan kalkacaktır. LOGOFF tetikleyicisi, oturum sonlandığında otomatik olarak ateşlenir ve performans verilerini toplayarak, canlı performans izlemesi için harcanan gereksiz zaman kaybından bizleri kurtarır. Ancak, oturum zorla sonlandırıldığında(KILL) LOGOFF tetikleyicisi ateşlenmez. LOGOFF tetikleyicisinin devreye girmesini engelleyen işlemler; işletim sistemi komutları ile sonlandırmalar, ALTER SYSTEM KILL SESSION ve SHUTDOWN IMMEDIATE/ABORT komutları ile birlikte kaynak limitlerini aşan oturumlar ve bunun neticesinde PMON tarafından ortadan kaldırılan oturumlardır. Ayrıca,  _SYSTEM_TRIG_ENABLED başlangıç parametresi FALSE olarak ayarlanırsa, LOGOFF tetikleyicisi devreye giremeyecektir.

LOGOFF tetikleyicisinin diğer bir güzelliği ise, oturum sonlanana kadar bu tetikleyicinin oturumdaki mevcut işyükü üzerinde etkisinin olmamsıdır, çünkü sadece oturum sonlandırılması neticesinde çalışır. Tabii, bu çalışma sırasındaki veritabanı üzerinde oluşan ek işyükü gözardı edilemez, ancak bu işyükünün etkisi tetikletici gövdesine ne eklendiği ile doğru orantılıdır. Oturum sonlanması esnasında biraz gecikmeler olacaktır, çünkü tetikleyici çalışmakta ve ambar(repository) tablolarına performans izleme verileri işlenmektedir. Eğer yoğun kullanımda bir sisteminiz varsa, eş zamanlı pekçok oturum sonlanması beklemeniz gerekir. Bu da demek olur ki, her bir oturum için LOGOFF tetikleyicisinin ateşlenmesi sonucunda, ambar tablolara eş zamanlı girişler yapılacaktır. Bu sebeple, bu ambar tabloları birçok INITRANS, FREELIST ve FREELIST GROUPS değeri ile inşa edilmelidir. Bununla ilgili kuyruğa eklemeler ile ilgili yazımı inceleyebilirsiniz, aksi durumda bu sefer bu ambar tablolarına yapılan işlemler esnasında kuyruğa ekleme TX bekleme olayları yaşanacaktır. Eğer ASSM(Otomatik Segment Alan Yönetimi) kullanılıyorsa, FREELIST ve FREELIST GROUPS değerlerinin ayarlanmasına gerek kalmaz, bunu sistem tablespace inşasında otomatik en iyi modda ayarlar.

Aşağıda örnek bir LOGOFF tetikleyicisi yer almaktadır. Oturumlar kapanırken çalışmak üzere ayarlanan bu tetikleyici, her bir oturum sonlanmasında, ilgili oturumun başlangıcından sonuna kadar geçen süre içindeki performans verisini toplayacaktır. “/ as sysdba” olarak oturum açarak bu örnek tetikleyici oluşturulmalıdır.

create or replace trigger sys.logoff_trig
before logoff on database
declare
  logoff_sid    pls_integer;
  logoff_time   date         := sysdate;
begin
  select sid
  into   logoff_sid
  from   v$mystat
  where  rownum < 2;

  insert into system.session_event_history
        (sid, serial#, username, osuser, paddr, process,
         logon_time, type, event, total_waits, total_timeouts,
         time_waited, average_wait, max_wait, logoff_timestamp)
  select a.sid, b.serial#, b.username, b.osuser, b.paddr, b.process,
         b.logon_time, b.type, a.event, a.total_waits, a.total_timeouts,
         a.time_waited, a.average_wait, a.max_wait, logoff_time
  from   v$session_event a, v$session b
  where  a.sid      = b.sid
  and    b.username = login_user
  and    b.sid      = logoff_sid;

  insert into system.sesstat_history
        (username, osuser, sid, serial#, paddr, process, logon_time,
         statistic#, name, value, logoff_timestamp)
  select c.username, c.osuser, a.sid, c.serial#, c.paddr, c.process,
         c.logon_time, a.statistic#, b.name, a.value, logoff_time
  from   v$sesstat a, v$statname b, v$session c
  where  a.statistic#  = b.statistic#
  and    a.sid         = c.sid
  and    b.name       in ('CPU used when call started',
                          'CPU used by this session',
                          'recursive cpu usage',
                          'parse time cpu')
  and    c.sid         = logoff_sid
  and    c.username    = login_user;
end;
/

Yukardaki scriptin sırasıyla çalışması için, önceden SYSTEM kullanıcısının sahipliğinde 2 adet ambar tablosu oluşturulmuş olmalıdır. Eğer başka bir kullanıcı tercih ederseniz, bu durumda yukardaki kodu buna uygun olarak değiştirmelisiniz. İlk tablo olan  SESSION_EVENT_HISTORY tüm bekleme olaylarını saklarken, ikinci tablo SESSTAT_HISTORY ise sonlanan oturumun CPU istatistiklerini saklar. Aşağıda bu ambar tabloları oluşturmak üzere DDL işlemleri yer almaktadır:

create table system.session_event_history
tablespace <name>
storage (freelist groups <value>)
initrans <value>
as
select b.sid,
       b.serial#,
       b.username,
       b.osuser,
       b.paddr,
       b.process,
       b.logon_time,
       b.type,
       a.event,
       a.total_waits, 
       a.total_timeouts,
       a.time_waited,
       a.average_wait,
       a.max_wait,
       sysdate as logoff_timestamp
from   v$session_event a, v$session b
where  1 = 2;

create table system.sesstat_history
tablespace <name>
storage (freelist groups <value>)
initrans <value>
as
select c.username,
       c.osuser,
       a.sid,
       c.serial#,
       c.paddr,
       c.process,
       c.logon_time,
       a.statistic#,
       b.name,
       a.value,
       sysdate as logoff_timestamp
from   v$sesstat a, v$statname b, v$session c
where  1 = 2;

Veritabanı LOGOFF tetikleyicilerinin çeşitli yönlerinden bahsederken, bu tetikleyicinin nasıl çalıştığı hakkında bir canlı örnek yapmak faydalı olacak diye düşünüyorum. Aşağıdaki örnek, benim test sistemimde çalıştırdığım bir SQL*Loader görevi sonucunda LOGOFF tetikleyicisi ile toplanan çalışma zamanı istatistiğidir.  Bu örnekteki açık oturum süresi yaklaşık 25 dakikaydı.

 EVENT                                     TIME_SPENT
-------------------------------------     -----------
log file sync                                92,232
log file switch completion                   21,865
log file switch (checkpoint incomplete)      15,630
SQL*Net message from client                  13,019
SQL*Net more data from client                1,021
db file sequential read                      68
SQL*Net message to client                    39
CPU used when call started                   20,481

** total_waits, average_wait,logon_time, logoff_timestamp ve total_timeouts değerleri bu yazı yayınlandıktan sonra SQL sorgusuna eklendiğinden dolayı, bu üç değerin sonuçları çıktıda yer almamaktadır. **

Açıkça, yukardaki ana darboğazlar commit(log file sync) ve log switch (log file switch completion) işlemleridir. Buradaki temel sorun, benim redo log dosyalarını oluştururken 10 MB ile sınırlandırmış olmam ve bu sebeple redo log switch işlemlerinin çok sık olmasıdır. Zaten, bu sorunda yukardaki özet raporda işaret edilmektedir. SQL*Loader bindsize değerinin 3MB ‘a çıkarılması ve redo log dosyalarının 100MB olanlarla değiştirilmesi sonucunda yükleme zamanıda 17 dakikadan yaklaşık 2 dakikaya düşmüştür.

Bunun yanında bu metodu kullanarak performans probleminin ana sorunu gözlemleme her zaman garanti altında olmadığını bilmemiz gerekir, çünkü toplanan performans verisi oturum seviyesi ile özetlenmiş ve sınırlandırılmıştır. Mesela, eğer latch free birincil darboğaz olarak görülüyorsa, elde edilen özet veri; hangi “latch” olayı ile uğraşıldığını, ne zaman meydana geldiğini, ne kadar deneme olduğunu ve hangi oturumun bu “latch” olayını tuttuğunu ortaya koymaz. Veya, eğer db file scattered read bekleme olayı birincil darboğaz olduğunda SQL komutunun ve FTS(full table scan) işlemine katılan objelerin tam yerini göstermez.

Evet, şimdi üstteki parağtaftan sonra LOGOFF tetikleyicisi kullanımı hakkında çekinceler oluşmuş olabilir kafanızda. LOGOFF tetikleyicisi sonunda toplanan verinin saklanması için disk alanı oturumların sonlanma sıklığına ve saklanması istenen verinin geçmiş süresine bağlıdır. Genellikle, 7 günlük bir geçmiş yeterlidir, çünkü herhangi bir performans sıkıntısı oluştuğunda birkaç gün içinde haberdar oluruz. Oturum sonlanma olayı ise kullanılan uygulamaya bağlı değişiklik gösterir. Bazı uygulamalar, birçok oturumun agresif olarak veritabanından bağlanıp kesilmesine sebebiyet verir. Eğer zamanlanmış görevleriniz varsa, SNP proseslerinin oturum kapatma sıklığını hesaba katmayı unutmayın. Her bir SNP arkaplan işlemi, ilgili zamanlanmış görevi tamamladığında LOGOFF tetikleyicisi devreye girer ve sonra uyku moduna geçer. 512MB büyüklüğünde bir tablespace alanı ile başlayabilir ve alan kullanımını izleyebilirsiniz.

Son olarak, veritabanı LOGOFF tetikleyicisi olarak bir uygulama vardır ve sadece sonuçların kıyaslanması ile ilgileniyorsanız size ideal bir çözüm sunar.  Mesela, özet oturum seviyesi bekleme olayıyla FAST_START_MTTR_TARGET değerinin bir proses üzerindeki etkisini  bu metodu kullanarak ve kullanmayarak kıyaslama yaparak görmek isteyebilirsiniz..

Pek çok yönden veritabanı LOGOFF tetikleyicisi “event 10046”  ile taban tabana zıtlık gösterir.Aşağıda her ikisi arasındaki farklılıklar net olarak yer almaktadır.

Veritabanı LOGOFF Tetikleyicisi:

1. Oturumun açık kaldığı süre boyunca bir sefer ateşlenir.
2. Özetlenmiş performans verisi toplar.
3. Veritabanına düşük işyüküne sahiptir.
4. Düşük disk alanı gereksinimi duyar.
5. Instance çapında genel bir izleme yeteneğine sahiptir.
6. Sınırlı sayıda temel sebep(root cause) analiz yeteneğine sahiptir.

Trace Event 10046:

1. Kesintisiz izleme yapar.
2. Çok detaylı performas verisi toplar.
3. Veritabanına ekstra yüksek işyükü getirir.
4. Yüksek depolama alanı gereksinimi duyar.
5. Genellikle oturum seviyesinde izleme yapar.
6. Temel sebep analizi için en iyi yöntemdir.

Bağlantısı sonlanmayan oturumlar için, aşağıdaki sorgu kullanılarak devam eden oturum seviyesindeki veritabanı yanıt süreleri alınabilmektedir, ancak unutmayın ki bunun kötü yanı daha öncedende bahsettiğim gibi, CPU zamanı istatistiğinin sadece işlemi tamamlanmış SQL komutlarını içerecek olmasıdır.

select event, total_waits as wait_count,
total_timeouts as timeout_count, average_wait,
logon_time, time_waited as time_spent
from   v$session_event
where  sid = &sid
and    event not in (
         'Null event',
         'client message',
         'KXFX: Execution Message Dequeue - Slave',
         'PX Deq: Execution Msg',
         'KXFQ: kxfqdeq - normal deqeue',
         'PX Deq: Table Q Normal',
         'Wait for credit - send blocked',
         'PX Deq Credit: send blkd',
         'Wait for credit - need buffer to send',
         'PX Deq Credit: need buffer',
         'Wait for credit - free buffer',
         'PX Deq Credit: free buffer',
         'parallel query dequeue wait',
         'PX Deque wait',
         'Parallel Query Idle Wait - Slaves',
         'PX Idle Wait',
         'slave wait',
         'dispatcher timer',
         'virtual circuit status',
         'pipe get',
         'rdbms ipc message',
         'rdbms ipc reply',
         'pmon timer',
         'smon timer',
         'PL/SQL lock timer',
         'SQL*Net message from client',
         'WMON goes to sleep')
union all
select b.name, null,null, b.logon_time, b.logoff_timestamp, a.value
from   v$sesstat a, v$statname b
where  a.statistic# = b.statistic#
and    b.name       = 'CPU used when call started'
and    a.sid        = &sid;

Aşağıdaki sonuç yukardaki sorgu sonucu alınmış bir örnektir. Eğer,  TIME_SPENT kolonuna tüm sayılar girilirse işlemin snapshot yanıt süresi elde edilir. Bu durumda, bu değer 3,199,836 sentisaniye’dir ve yaklaşık 8.89 saat eder.

EVENT                               TIME_SPENT
------------------------------      -----------
CPU used when call started          1,358,119
db file sequential read             1,518,787
SQL*Net message from dblink         191,907
db file scattered read              54,949
SQL*Net more data from dblink       44,075
latch free                          12,687
free buffer waits                   9,567
write complete waits                8,970
log file switch completion            553
direct path read                       97
local write wait                       33
log file sync                          32
SQL*Net message to dblink              24
db file parallel read                  14
direct path write                      13
buffer busy waits                       7
file open                               2

Veritabanı yanıt süresi modeli, son kullanıcı işlemlerine çok yakından bakmanıza imkan verdiğinden dolayı performans geliştirmelerinde elverişli bir metot olacaktır. Yanıt sürelerinin iyileştirilmesi her zaman darboğazların üstesinden gelmek noktasında ana çözüm yoludur.