Raporty AWR w bazach Oracle
Raporty AWR (Automatic Workload Repository) to narzędzie diagnostyczne dostępne w bazach danych Oracle, które pomaga analizować wydajność systemu i identyfikować obszary wymagające optymalizacji. Na pierwszy rzut oka wyglądają, umówmy się, dość zawile. Sporo sekcji, mnóstwo liczb i parametrów. Z powodu swojej szczegółowej i technicznej natury wymagają pewnej wprawy w użytkowaniu. Po głębszej analizie okazuje się jednak, że jest to niezwykle wartościowe narzędzie dla administratorów baz i fakt, że umożliwia sięgnięcie do archiwalnych stanów bazy (standardowo do 8 dni wstecz) czyni go jeszcze bardziej użytecznym.
Utrzymanie minimum ośmiodniowej retencji jest bardzo przemyślaną strategią, ponieważ daje wgląd do analogicznego okresu sprzed tygodnia. Innymi słowy, jeśli dziś wystąpił problem z wydajnością, warto sprawdzić, czy podobne zdarzenie wystąpiło tydzień temu. Być może problem ma charakter cykliczny i związany jest np. z automatycznym uruchamianiem zadań. Jeśli uważasz, że mimo wszystko okres ten jest zbyt krótki, zwiększ go przy użyciu poniższej procedury, pamiętając o zarezerwowaniu większej przestrzeni w tablespace SYSAUX:
exec dbms_workload_repository.modify_snapshot_settings(interval=>15*60,retention=>30*24*60);W tym przykładzie okres przechowywania określono na 30 dni (43200 min), a odstęp między każdą migawką wynosi 60 min.
Jako, że przy tworzeniu raportu wykorzystywane są widoki Active Session History, wymagane jest posiadanie licencji Diagnostic Pack. Jeśli jej nie posiadasz, pozostaje Ci użycie pakietu Statspack, który nie dostarcza niestety takiej automatyki jak raporty AWR.
Generowanie raportu
Aby wygenerować raport należy uruchomić skrypt awrrpt.sql znajdujący się w katalogu $ORACLE_HOME/rdbms/admin
cd $ORACLE_HOME/rdbms/admin
sqlplus / as sysdba
SQL> @awrrpt.sqlPo uruchomieniu zdecyduj, czy preferujesz wynik w formie tekstu czy struktury HTML, oraz wskaż zakres migawek jaki będziesz chciał analizować (przedział czasu).
Enter value for num_days: 1
Listing the last day's Completed Snapshots
Instance DB Name Snap Id Snap Started Snap Level
------------ ------------ ---------- ------------------ ----------
cdblab01 CDBDBLAB01 18330 20 Sep 2023 00:00 1
18331 20 Sep 2023 01:00 1
18332 20 Sep 2023 02:00 1
18333 20 Sep 2023 03:00 1
18334 20 Sep 2023 04:00 1
18335 20 Sep 2023 05:00 1
18336 20 Sep 2023 06:00 1
18337 20 Sep 2023 07:00 1
[...]
Specify the Begin and End Snapshot Ids
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Enter value for begin_snap: 18336
Begin Snapshot Id specified: 18336
Enter value for end_snap: 18337
End Snapshot Id specified: 18337Po zakończeniu pobierania danych, raport zostanie wyświetlony na ekranie. Pierwsza sekcja zawiera informacje dotyczące nazwy bazy, hosta oraz opcjonalnie kontenerów PDB zawartych w bazie.
DB Name DB Id Unique Name DB Role Edition Release RAC CDB
------------ ----------- ----------- ---------------- ------- ---------- --- ---
CDBDBLAB01 3446739 cdblab01 PRIMARY EE 19.0.0.0.0 NO YES
Instance Inst Num Startup Time User Name System Data Visible
------------ -------- --------------- ------------ --------------------
cdblab01 1 24-Jun-23 18:04 SYS YES
Container DB Id Container Name Open Time
--------------- --------------- ---------------
79466073 PDB$SEED 24-Jun-23 18:04
544672419 CDB$ROOT 24-Jun-23 18:04
3580336812 PDBLABDB 24-Jun-23 18:04
Host Name Platform CPUs Cores Sockets Memory(GB)
---------------- -------------------------------- ---- ----- ------- ----------
Aixlab100 AIX-Based Systems (64-bit) 64 8 216.00W kolejnej, możemy zapoznać się z czasami wykonania analizowanych migawek, liczbie sesji oraz średniej liczbie kursorów w sesjach:
Snap Id Snap Time Sessions Curs/Sess PDBs
--------- ------------------- -------- --------- -----
Begin Snap: 18336 20-Sep-23 06:00:45 361 5.4 3
End Snap: 18337 20-Sep-23 07:00:51 330 5.2 3
Elapsed: 60.10 (mins)
DB Time: 1,106.98 (mins)W tym momencie zwróć proszę uwagę na wartość metryki DB Time. Jest to statystyka, która jest sumą czasu zużytego na działanie wszystkich procesów bazy Oracle oraz sumą czasów oczekiwania.
Już na tym etapie możemy wyciągnąć pewnie wnioski. Porównując przedział czasu jaki upłynął pomiędzy wykonanymi migawkami (elapsed time), z wartością DB Time, opisującą aktywność bazy, możemy stwierdzić, że jeżeli wartość DB Time jest znacznie większa od wartości elepsed time, niektóre sesje oczekiwały na zwolnienie zasobów.
W tym przypadku pomimo, iż analizujemy przedział 60 minut, wartość DB Time wykazuje ponad 1000 minut. Może to oznaczać, że analizowana baza była w tym czasie zajęta lub nawet przeciążona.
Kolejną sekcją dającą ogólny pogląd na temat wydajności, jest Instance Efficiency Percentages (Procentowa wydajności instancji). Zawiera ona tzw. „współczynniki trafień”, jak również procentową wartość proporcji zapytań wykonanych do przeanalizowanych (Execute to Parse). Jak można się przekonać z sugestii (Target 100%), idealną wartością docelową parametrów jest 100%.
Sekcja ta pokazuje, że prawie 99% analiz ma charakter miękki, na co wskazuje metryka Soft Parse %. To bardzo dobry wynik, który mówi, że baza Oracle wykorzystuje ponownie przygotowane wcześniej plany zapytań SQL. Ogólna zasada polega na tym, że zawsze należy minimalizować liczbę twardych analiz w produkcyjnej bazie danych. Ta redukcja zapewnia korzyść w postaci minimalizacji obciążenia procesora podczas wykonywania kosztownych analiz.
Następną interesującą metryką jest Parse CPU to Parse Elapsd (stosunek czasu analizy składni do czasu procesora). W tym przypadku jest to około 22%. Fakt ten pokazuje, że baza czekała na pewne zasoby podczas analizowania instrukcji SQL. Z doświadczenia wiem, że akurat ta wartość często przyjmuje małe wartości. W tym wypadku nie oznacza to znaczących nieprawidłowości.
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 99.99 Redo NoWait %: 100.00
Buffer Hit %: 97.67 In-memory Sort %: 100.00
Library Hit %: 99.73 Soft Parse %: 98.76
Execute to Parse %: 91.18 Latch Hit %: 99.87
Parse CPU to Parse Elapsd %: 22.18 % Non-Parse CPU: 99.62
Flash Cache Hit %: 0.00Przejdźmy do kolejnej sekcji raportu a mianowicie Top 10 Foreground Events (10 pierwszoplanowych zdarzeń). Zawiera ona informacje o obszarach, w których zajętych było najwięcej zasobów.
Poniższy przykład ilustruje, że najwięcej zasobów było wykorzystanych podczas przeszukiwania indeksów db file sequential read. W obciążonym systemie obsługującym dużą liczbę transakcji (takim jak ten) wysoka wartość tej metryki jest sytuacją normalną, ale już np. duże wartości w SQL*Net message from dblink mogą świadczyć, że baza przeszukiwała dane dostępne w zewnętrznych zasobach i najprawdopodobniej napotkała problem z wydajnością sieci.
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Total Wait Avg % DB Wait
Event Waits Time (sec) Wait time Class
------------------------------ ----------- ---------- --------- ------ --------
DB CPU 11.4K 17.2
db file sequential read 10,769,892 6999.4 649.90us 10.5 User I/O
direct path read 1,126,591 5149.2 4.57ms 7.8 User I/O
db file scattered read 1,148,518 3498 3.05ms 5.3 User I/O
direct path read temp 2,463,087 2757.3 1.12ms 4.2 User I/O
SQL*Net message from dblink 494,308 2334.2 4.72ms 3.5 Network
SQL*Net more data from dblink 2,023,625 2037.2 1.01ms 3.1 Network
direct path write temp 930,859 1428.7 1.53ms 2.2 User I/O
latch free 1,974,192 1083.2 548.67us 1.6 Other
control file sequential read 1,753,380 707 403.20us 1.1 System I
Profil obciążenia bazy (Load Profile)
Ta sekcja dostarcza szczegółowych danych na temat rodzajów operacji bazodanowych jakie były wykonywane, oraz ile zasobów zużyły. Istotne są w tu częstotliwości wykonywanych operacji wejścia-wyjścia (Physical reads / writes) oraz twardych analiz składni zapytań (Hard parses). Jeśli zauważysz duże wartości w sekcji hard parses, może to oznaczać, że zapytania nie wykorzystują zmiennych bindowanych. W przypadku tego typu problemów z systemami produkcyjnymi, powinieneś fakt ten zgłosić do zespołu projektowego.
Tu należy się szersze wyjaśnienie , czym są zmienne bindowane?
Ilustruje to poniższy przykład. Przypuśćmy, że uruchomimy następujące cztery zapytania:
SELECT * FROM EMPLOYEES WHERE EMPLOYEE_ID=10;
SELECT * FROM EMPLOYEES WHERE EMPLOYEE_ID=15;
SELECT * FROM EMPLOYEES WHERE EMPLOYEE_ID=19;
SELECT * FROM EMPLOYEES WHERE EMPLOYEE_ID=20;Baza danych opracuje osobny plan dla każdego z zapytań. Taka sytuacja nie jest optymalna z punktu widzenia wydajności, dlatego aby się przed tym uchronić powinniśmy użyć wspomnianych wcześniej zmiennych bindowanych.
Utwórzmy taką zmienną:
variable x number;i przypiszmy do niej wartość:
begin
:x:=10;
end;Teraz możemy odwołać się do tej zmiennej w zapytaniach używając składni:
SELECT * FROM EMPLOYEES WHERE EMPLOYEE_ID=:X;Możemy odpytywać bazę wielokrotnie używając powyższego zapytania, za każdym razem podając inną wartość zmiennej. Z punktu widzenia optymalizatora, będzie to wciąż to samo zapytanie. W uproszczeniu mówiąc, optymalizator kosztowy wykorzysta ten sam plan wykonania, niezależnie od wartości zmiennej bindowanej. Zgłębiając temat bardziej okazuje się, że przygotowany zostanie zestaw kilku planów, ale mechanizm ten szerzej opisałem w oddzielnym artykule: Adaptive Cursor Sharing.
Wracając jednak do dalszej analizy raportów AWR: Jeżeli analizując sekcję „Load Profile”, stwierdzisz wysoką częstotliwość logowań (User Logons), może oznaczać, że aplikacja za każdym razem tworzy nowe połączenie, czyli wykonuje zapytanie i rozłącza sesję. Taka sytuacja, wykonana z wielu jednocześnie uruchomionych klientów może potencjalnie wpłynąć na obciążenie systemu bazodanowego.
Load Profile Per Second Per Transaction Per Exec Per Call
~~~~~~~~~~~~~~~ --------------- --------------- --------- ---------
DB Time(s): 18.4 0.9 0.01 0.03
DB CPU(s): 3.2 0.2 0.00 0.01
Background CPU(s): 0.1 0.0 0.00 0.00
Redo size (bytes): 9,658,868.4 445,126.1
Logical read (blocks): 971,544.6 44,773.4
Block changes: 1,680.4 77.4
Physical read (blocks): 178,511.2 8,226.6
Physical write (blocks): 14,240.7 656.3
Read IO requests: 7,355.6 339.0
Write IO requests: 1,348.7 62.2
Read IO (MB): 2,789.2 128.5
Write IO (MB): 222.5 10.3
IM scan rows: 0.0 0.0
Session Logical Read IM: 0.0 0.0
User calls: 594.7 27.4
Parses (SQL): 178.8 8.2
Hard parses (SQL): 2.2 0.1
SQL Work Area (MB): 58.9 2.7
Logons: 7.7 0.4
User logons: 7.1 0.3
Executes (SQL): 2,026.5 93.4
Rollbacks: 8.4 0.4
Transactions: 21.7Kolejna sekcja warta uwagi to Top 10 Foreground Events by Total Wait Time. Zawiera ona informacje o zdarzeniach odpowiedzialnych za najdłuższe oczekiwania.
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Total Wait Avg % DB Wait
Event Waits Time (sec) Wait time Class
------------------------------ ----------- ---------- --------- ------ --------
DB CPU 11.4K 17.2
db file sequential read 10,769,892 6999.4 649.90us 10.5 User I/O
direct path read 1,126,591 5149.2 4.57ms 7.8 User I/O
db file scattered read 1,148,518 3498 3.05ms 5.3 User I/O
direct path read temp 2,463,087 2757.3 1.12ms 4.2 User I/O
SQL*Net message from dblink 494,308 2334.2 4.72ms 3.5 Network
SQL*Net more data from dblink 2,023,625 2037.2 1.01ms 3.1 Network
direct path write temp 930,859 1428.7 1.53ms 2.2 User I/O
latch free 1,974,192 1083.2 548.67us 1.6 Other
control file sequential read 1,753,380 707 403.20us 1.1 System ITa część raportu wskazuje potencjalne źródło problemów z bazą, przy czym już zazwyczaj dwie pierwsze pozycje są odpowiedzialne za większość kłopotów wydajnościowych.
W przypadku prawidłowo działającej bazy, na początku listy powinny znajdować się zdarzenia związane z procesorem i dyskami, jak w naszym przypadku. Jeżeli jednak znajdą się tam zdarzenia z klasy enq: TX – row lock contention lub latch free, zazwyczaj będą one oznaczać rywalizację o zasoby.
Time Model Statistics (Statystyki modelu czasu)
Statystyki modelu czasu dają wgląd w to, gdzie faktycznie spędzany jest czas przetwarzania w interwale migawki. Jeżeli czas twardej analizy (hard parse elapsed time) jest bardzo długi, musisz dokładniej zbadać ten problem.
Time Model Statistics DB/Inst: CDBDBLAB01/cdblab01 Snaps: 18336-18337
-> DB Time represents total time in user calls
-> DB CPU represents CPU time of foreground processes
-> Total CPU Time represents foreground and background processes
-> Statistics including the word "background" measure background process
time, therefore do not contribute to the DB time statistic
-> Ordered by % of DB time in descending order, followed by Statistic Name
% of % of Total
Statistic Name Time (s) DB Time CPU Time
------------------------------------------ ------------------ ------- ----------
sql execute elapsed time 65,734.7 99.0
DB CPU 11,415.6 17.2 97.6
PL/SQL execution elapsed time 1,165.2 1.8
inbound PL/SQL rpc elapsed time 482.5 .7
connection management call elapsed time 372.9 .6
parse time elapsed 192.3 .3
hard parse elapsed time 121.9 .2
RMAN cpu time (backup/restore) 33.6 .1 .3
hard parse (sharing criteria) elapsed time 11.9 .0
PL/SQL compilation elapsed time 1.9 .0
repeated bind elapsed time 1.8 .0
sequence load elapsed time 0.8 .0
failed parse elapsed time 0.5 .0
hard parse (bind mismatch) elapsed time 0.4 .0
DB time 66,418.6
background elapsed time 2,429.7
background cpu time 280.0 2.4
total CPU time 11,695.6
------------------------------------------------------Najdłużej wykonywane zapytania SQL (Top SQL Statements)
Ta sekcja raportu zawiera listę najdłużej wykonywanych instrukcji SQL. Można tu wychwycić konkretne zapytania sprawiające problem i posługując się ich numerem ID przejść do analizy ich planów.
Top SQL with Top Events DB/Inst: CDBDBLAB01/cdblab01 Snaps: 18336-18337
-> Top SQL statements by DB Time along with the top events by DB Time for
those SQLs.
-> % Activity is the percentage of DB Time due to the SQL.
-> % Event is the percentage of DB Time due to the event that the SQL is
waiting on.
-> % Row Source is the percentage of DB Time due to the row source for the
SQL waiting on the event.
-> Executions is the number of executions of the SQL that were sampled in
ASH.
SQL ID Plan Hash Executions % Activity
----------------------- -------------------- -------------------- --------------
% Row
Event % Event Top Row Source Source
------------------------------ ------- --------------------------------- -------
Container Name
-------------------------------------------
22drvv11nb5r6 5125497296 1 4.95
CPU + Wait for CPU 4.93 HASH - GROUP BY 2.66
select t.numer nr ,a.numer ponu ,case when o.punu i
then case when b.NUMER_KL in (select * from d
PDBLABDB
2685axh6avbvc 758157989 1 4.95
CPU + Wait for CPU 3.73 HASH - GROUP BY 1.33
create table TBL_INMP TABLESPACE USERS_A as select
source, id, od_d, dt_zg, paczka, Artykuł nie wyczerpuje pełnych możliwości jakie płyną z analizy raportów AWR. Może być za to wstępem w poszukiwaniach problematycznych obszarów w działaniu systemów bazodanowych.
Pomimo, iż raporty AWR mogą początkowo wydawać się zawiłe, stanowią niezastąpione narzędzie administratorów baz, pomagając im utrzymywać środowisko w doskonałej kondycji i minimalizować ryzyko problemów wydajnościowych.
