Śledzenie sesji , śledzenie aplikacji pod kątem planów wykonania. Narzędzie tkprof.

Zawartość tego rozdziału stanie się użyteczna gdy będziemy chcieli obserwować co się dzieje w naszej sesji, lub sesji wykorzystywanej przez aplikację którą zarządzamy. Dzięki tej opcji będziemy mogli przejrzeć jakie są wykorzystywane explain plany dla zapytań, oraz szczegółowe informacje statystyczne.

Pierwsze co musimy zrobić to włączyć śledzenie dla tej sesji. Jeśli chcemy śledzić własną sesję włączamy po prostu:

ALTER SESSION SET SQL_TRACE = TRUE;

lub

execute dbms_session.set_sql_trace(true);

Możemy też ustawić parametr TIMED_STATISTICS na true:

ALTER SESSION SET TIMED_STATISTICS=TRUE;

Dzieki temu będziemy mięli informacje na temat czasów wykonania poszczególnych elementów zapytania, oraz na temat zdarzeń wait. Ze zdarzeniami wait mamy do czynienia wtedy, kiedy Oracle czeka na jakiś proces zanim będzie mógł kontynuować wykonywanie zapytania . Przykładowo chcemy zmienić coś w bazie. Bloki które będziemy zmieniać muszą trafić do bufora db_cache. Muszą zostać zaczytane z dysku. Zanim to się jednak stanie, proces naszego update musi poczekać. To jest właśnie takie zdarzenie.

Możemy również obserwować inną sesję:

execute dbms_system.set_sql_trace_in_session(SID, SERIAL#,TRUE|FALSE);

Sid i serial# są wartościami które jednoznacznie identyfikują pojedyńczą sesję. Możemy te wartości pobrać ze słownika v$session:

W powyższym przypadku wyszukałem sobie sesję użytkownika HR. Gdybym zechciał obserwować jego sesję mogę wykonać:

execute dbms_system.set_sql_trace_in_session(33,3,TRUE);

Wyłączenie śledzenia sesji wygląda tak:

dla własnej sesji:

ALTER SESSION SET SQL_TRACE = FALSE;

śledząc własną sesję możesz też wykonać polecenie :


ALTER SESSION SET tracefile_identifier='jakasnazwa';


Dzięki temu, plik trace będzie w nazwie posiadał to co podamy między "dziabągami" i łatwiej go będzie zidentyfikować.

Śledzenie dla innej sesji:

execute dbms_system.set_sql_trace_in_session(33,3,FALSE);

Wyniki śledzenia zarówno mojej, jak i innej sesji znajdą się w pliku na dysku. Plik ten znajdzie się w katalogu określonym przez parametr USER_DUMP_DEST.

Najlepiej jest przejść do tego katalogu i wyszukać właściwy plik po dacie utworzenia:

Następnie wywołujemy narzędzie tkprof by przetworzyć ten plik śladu do postaci czytelnej dla człowieka:

Pierwszy parametr to źródłowy plik śladu, drugi to plik do którego ma zostać wyrzucony czytelny wynik. Po włączeniu śledzenia sesji wykonałem zapytanie :

SELECT * FROM EMPLOYEES JOIN DEPARTMENTS USING (DEPARTMENT_ID);

następnie po przetworzeniu pliku śladu tkprofem znalazłem go w swoim pliku wynikowym. Oto efekt:

********************************************************************************

select *

from

employees join departments using (department_id)

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 1 0.00 0.04 0 0 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 1 0.00 0.00 0 13 0 50

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 3 0.00 0.04 0 13 0 50

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 33

********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 20 0.28 0.66 0 0 4 0

Execute 21 1.81 4.63 100 206 144 1

Fetch 18 0.09 0.22 5 1614 0 179

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 59 2.18 5.51 105 1820 148 180

Misses in library cache during parse: 11

Misses in library cache during execute: 3

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 1852 1.10 3.33 17 142 10 0

Execute 4952 1.06 6.24 120 5178 4365 1422

Fetch 6780 2.98 23.69 28217 44647 1 10017

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 13584 5.15 33.27 28354 49967 4376 11439

Misses in library cache during parse: 214

Misses in library cache during execute: 75

129 user SQL statements in session.

3453 internal SQL statements in session.

3582 SQL statements in session.

********************************************************************************

Trace file: C:\ORACLEXE\APP\ORACLE\ADMIN\XE\UDUMP\xe_ora_2144.trc

Trace file compatibility: 10.01.00

Sort options: default

1 session in tracefile.

129 user SQL statements in trace file.

3453 internal SQL statements in trace file.

3582 SQL statements in trace file.

227 unique SQL statements in trace file.

37791 lines in trace file.

766 elapsed seconds in trace file.