Možná to opět o delší odmlce vypadá, že mi přejelo auto nebo jsem snad dokonce přišel o lásku k Oracle
Ne, nic takového se neděje. Akorád mezi vztah já a Oracle se dostala švédština. A všichni víme, že k tomu aby byl den dokonalý mu chybí dobrejch 5-6 hodin..
Měl jsem poustu tipů na články, spoustu věcí na zkoušení - za dobu nepsaní jsem se spoustu věcí o Oracle dozvěděl, spoustu zapomnil.. atd. A dokonce mam na blogu spoustu nedokončených věcí a pokusím se s tim něco udělat. Nicméně v Oracle jsem narazil na něco, co je neuvěřitelně SEXY a musím to dostat z hlavy a mé srdce bije zrychleným tepem
Takže here we go!
Nevím jaké procent lidí, co čtou tenhle blog si něco vybaví při čísle 10046. Pokud nic, tak za domací úkol doplnit
Co znají si automaticky vybaví následující:
ALTER SESSION SET EVENTS '10046 trace name context forever,level 12'
Když už to programátor viděl xkrát za svuj život a podobný výstup si umí vytáhnout z různých view, tak to prostě použivá a nepřemýšlí nad tím, jak moc cool to je. Ovšem trace eventu 10046 neni zdaleka jedniné, co jde tracovat a ovlivňovat. Dlouho jsem hledal nějaký list a nenašel
Paradoxně mi v tomhle pomohla švédština kdy jsem přes brutal force vypisoval chybové hlášky z SQLERRM a vypisoval si švédskou chybu a anglický překlad. V rámci brutal force jsem objevil spoustu zajímavých chybových hlášek, které jsem nikdy neviděl a asi ani nikdy neuvidím. Ale narazil jsem taky na list toho co je možné tracovat – konkrétně jsou to hodnoty mezi 55 a xxx. Z takových těch zajímavých věcí je to deadlock, hashjoin (to je mazec, možná někdy napíšu nějaký článek) a pak trace event 10053 ze kterého jsem si sednul na prdel.
A nyní co to dělá:
Tracuje to CBO optimalizátor. A to do takové úrovně, že to píše všechny transformace které to zkouší, všechny možné rewrites, takové ty věci jako tranzitivní uzávěry, vykostění predikátu, následuje spočitání nákladu na jednotlivé přístupové cesty – s tím, že to vypíše estimate řádku, pamět, costy (a to ještě před zaokouhlením !), všechny parametry optimalizátoru, hinty, a pak postupně přijde něco co je uplně nejvíce cool – permutace v optimalizačním plánu a výpisy costu pro jednotlivé vypermutované plány + případně důvod zamítnutí, včetně takových věcí jako, že to Oracle killne uprostředka protože už to přelezlo přes cost prozatím nejlepšího nalezeného plánu, je tam vidět jak si při optimalizaci CBO spouští sql na dynamic sampling. Prostě kurva mazec !
Asi si dovedete představit jak mi bylo - ještě líp než když se mi v pondělí povedlo na třetí hodině švédštiny vykoktat švédsky učitelce kompliment, že má nádherné modré oči a hezký úsměv ;) Tohle asi bude trošku rozsáhlé, protože ty logy a výstupy z trace jsou velké, takže tenhle článek je první a hodně high level co to vlastně je:
Nejprve zjistit kde jsou trace logy:
select value,name from v$parameter2 where name like 'user%dump%des%';
U mě je to C:\app4\AZOR\diag\rdbms\orcl12\orcl12\trace. Dobře a ted
ALTER SESSION SET EVENTS ‘10053 trace name context forever,level 1′;
A nyní nějaké SQL a začněme tím úplně nejjednodušším:
select * from dual;
A pak ideálně nic již nedělat, exit ze session nebo vypnout. A nyní co ten soubor obsabuje :
- Hlavičku (verze Oracle, OS, umístění, počet CPU, velikost paměti..)
Trace file C:\APP4\AZOR\diag\rdbms\orcl12\orcl12\trace\orcl12_ora_4932.trc
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
Windows NT Version V6.1 Service Pack 1
CPU : 8 - type 8664, 4 Physical Cores
Process Affinity : 0x0x0000000000000000
Memory (Avail/Total): Ph:3546M/8043M, Ph+PgF:2830M/8042M
Instance name: orcl12
Redo thread mounted by this instance: 1
Oracle process number: 9
Windows thread id: 4932, image: ORACLE.EXE (SHAD)
- Informace o SESSION – id, modul, action..
*** 2015-03-18 22:16:18.321
*** SESSION ID:(60.7) 2015-03-18 22:16:18.321
*** CLIENT ID:() 2015-03-18 22:16:18.321
*** SERVICE NAME:(SYS$USERS) 2015-03-18 22:16:18.321
*** MODULE NAME:(sqlplus.exe) 2015-03-18 22:16:18.321
*** ACTION NAME:() 2015-03-18 22:16:18.321
- Query blocky a jejich pojmenování
Registered qb: SEL$1 0x170b24b8 (PARSER)
---------------------
QUERY BLOCK SIGNATURE
---------------------
signature (): qb_name=SEL$1 nbfros=1 flg=0
fro(0): flg=4 objn=142 hint_alias="DUAL"@"SEL$1"
SPM: statement not found in SMB
SPM: capture of plan baseline is OFF
V tomhle případě je tam jeden query blok (SEL$1). A dole hláška SPM Zkratka neni dole vysvětlena, ale podle kontextu to bude SQL Plan Management (dbm_spm).
- Check na ADOP (automaic degree of parallelism)
**************************
Automatic degree of parallelism (AUTODOP)
**************************
Automatic degree of parallelism is disabled: Parameter.
Jen informace o tom, že je to vypnuto.
- Seznam a vysvětlení zkratek, které jsou použity (bohužel né všechny)
*******************************************
Legend
The following abbreviations are used by optimizer trace.
CBQT - cost-based query transformation
JPPD - join predicate push-down
OJPPD - old-style (non-cost-based) JPPD
FPD - filter push-down
PM - predicate move-around
CVM - complex view merging
SPJ - select-project-join
SJC - set join conversion
SU - subquery unnesting
OBYE - order by elimination
OST - old style star transformation
ST - new (cbqt) star transformation
CNT - count(col) to count(*) transformation
JE - Join Elimination
JF - join factorization
SLP - select list pruning
DP - distinct placement
qb - query block
LB - leaf blocks
DK - distinct keys
LB/K - average number of leaf blocks per key
DB/K - average number of data blocks per key
CLUF - clustering factor
NDV - number of distinct values
Resp - response cost
Card - cardinality
Resc - resource cost
NL - nested loops (join)
SM - sort merge (join)
HA - hash (join)
CPUSPEED - CPU Speed
IOTFRSPEED - I/O transfer speed
IOSEEKTIM - I/O seek time
SREADTIM - average single block read time
MREADTIM - average multiblock read time
MBRC - average multiblock read count
MAXTHR - maximum I/O system throughput
SLAVETHR - average slave I/O throughput
dmeth - distribution method
1: no partitioning required
2: value partitioned
4: right is random (round-robin)
128: left is random (round-robin)
8: broadcast right and partition left
16: broadcast left and partition right
32: partition left using partitioning of right
64: partition right using partitioning of left
256: run the join in serial
0: invalid distribution method
sel - selectivity
ptn - partition
AP - adaptive plans
***************************************
- Parametry optimalizátory – všechny, včetně nastavení + fixy a jejich stav
To jako úplně vypisovat nebudu, je toho fakt hodně. Co je fajn, je že jsou tam vypsány i nedokumentované parametry. Což dělá tenhe trace sámo o sobě zajímavým
- Pak následují pokusy o transformace query blocků
Considering Query Transformations on query block SEL$1 (#0)
**************************
Query transformations (QT)
**************************
JF: Checking validity of join factorization for query block SEL$1 (#0)
JF: Bypassed: not a UNION or UNION-ALL query block.
ST: not valid since star transformation parameter is FALSE
TE: Checking validity of table expansion for query block SEL$1 (#0)
TE: Bypassed: No partitioned table in query block.
CBQT bypassed for query block SEL$1 (#0): no complex view, sub-queries or UNION (ALL) queries.
CBQT: Validity checks failed for a5ks9fhw2v9s1.
CSE: Considering common sub-expression elimination in query block SEL$1 (#0)
*************************
Common Subexpression elimination (CSE)
*************************
CSE: CSE not performed on query block SEL$1 (#0).
OBYE: Considering Order-by Elimination from view SEL$1 (#0)
***************************
Order-by elimination (OBYE)
***************************
OBYE: OBYE bypassed: no order by to eliminate.
CVM: Considering view merge in query block SEL$1 (#0)
OJE: Begin: find best directive for query block SEL$1 (#0)
OJE: End: finding best directive for query block SEL$1 (#0)
query block SEL$1 (#0) unchanged
Considering Query Transformations on query block SEL$1 (#0)
**************************
Query transformations (QT)
**************************
JF: Checking validity of join factorization for query block SEL$1 (#0)
JF: Bypassed: not a UNION or UNION-ALL query block.
ST: not valid since star transformation parameter is FALSE
TE: Checking validity of table expansion for query block SEL$1 (#0)
TE: Bypassed: No partitioned table in query block.
CBQT bypassed for query block SEL$1 (#0): no complex view, sub-queries or UNION (ALL) queries.
CBQT: Validity checks failed for a5ks9fhw2v9s1.
CSE: Considering common sub-expression elimination in query block SEL$1 (#0)
*************************
Common Subexpression elimination (CSE)
*************************
CSE: CSE not performed on query block SEL$1 (#0).
SU: Considering subquery unnesting in query block SEL$1 (#0)
********************
Subquery Unnest (SU)
********************
SJC: Considering set-join conversion in query block SEL$1 (#0)
*************************
Set-Join Conversion (SJC)
*************************
SJC: not performed
PM: Considering predicate move-around in query block SEL$1 (#0)
**************************
Predicate Move-Around (PM)
**************************
PM: PM bypassed: Outer query contains no views.
PM: PM bypassed: Outer query contains no views.
query block SEL$1 (#0) unchanged
FPD: Considering simple filter push in query block SEL$1 (#0)
??
apadrv-start sqlid=11730480049179961089
CSE: Considering common sub-expression elimination in query block SEL$1 (#0)
*************************
Common Subexpression elimination (CSE)
*************************
CSE: CSE not performed on query block SEL$1 (#0).
:
call(in-use=1136, alloc=16344), compile(in-use=54968, alloc=58616), execution(in-use=2632, alloc=4032)
Upřímně nevím co to dělá tady. Že od 10g Oracle permutuje bloky nikoliv celé sql jsem již někde postřehl. Oracle vzdal permutace na celém sql, protože pro takové SQL jako generuje například Siebel (150+ tabulek a joinu) jsou často permutace nemožné (ostatně ani faktoriál 10ti neni malé číslo – 362880, pokud si pamatuji tak před timhle přístupem bylo maximum 60000 a nazdar bazar). Takže raději rozsekání na části, ty permutovat a pak případně permutovat proti sobě. Proč ale přepisy nedělá na urovní celého sql netuším :(, ač si umím představit, že většina z nich nepůjde udělat přes hranice query bloku, tak něco by určitě šlo. Na mém select from dual nemá co vymyslet – zkusil a neuspěl.
- Kontrola peek variables na cursoru
Tam jen zeje hláška, že nic. Nic být ani nemůže, nemam žádnou bid variable
- Výpis SQL po transformaci, tzn ten který pujde na permutování
Final query after transformations:******* UNPARSED QUERY IS *******
SELECT "DUAL"."DUMMY" "DUMMY" FROM "SYS"."DUAL" "DUAL"
kkoqbc: optimizing query block SEL$1 (#0)
call(in-use=1136, alloc=16344), compile(in-use=64416, alloc=66952), execution(in-use=2632, alloc=4032)
kkoqbc-subheap (create addr=0x00000000170BF760)
Žádné transformace se nepovedly, takže stejné sql jako originál.
- Výpis systémových statistik
-----------------------------
SYSTEM STATISTICS INFORMATION
-----------------------------
Using NOWORKLOAD Stats
CPUSPEEDNW: 3264 millions instructions/sec (default is 100)
IOTFRSPEED: 4096 bytes per millisecond (default is 4096)
IOSEEKTIM: 10 milliseconds (default is 10)
MBRC: NO VALUE blocks (default is 8)
Table Stats::
Table: DUAL Alias: DUAL
#Rows: 1 #Blks: 1 AvgRowLen: 2.00 ChainCnt: 0.00
Na tabulce dual není nic zajímavého
Jeden řádek, délka 2, žádné chainy.
- Analýza přístupu do tabulky
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for DUAL[DUAL]
SPD: Return code in qosdDSDirSetup: NOCTX, estType = TABLE
Table: DUAL Alias: DUAL
Card: Original: 1.000000 Rounded: 1 Computed: 1.00 Non Adjusted: 1.00
Access Path: TableScan
Cost: 2.00 Resp: 2.00 Degree: 0
Cost_io: 2.00 Cost_cpu: 7271
Resp_io: 2.00 Resp_cpu: 7271
Best:: AccessPath: TableScan
Cost: 2.00 Degree: 1 Resp: 2.00 Card: 1.00 Bytes: 0
Na tabulce dual není nic zajímavého. Stejně má Oracle jen možnost full table scan, žádný index tam neni.
OPTIMIZER STATISTICS AND COMPUTATIONS
PJE: Bypassed; QB has a single table SEL$1 (#0)
Oracle dokonce ani nezkoušel permutovat, nemá s čím, máme jen jednu tabulku, takže taky nic.
kkeCostToTime: using io calibrate stats maxpmbps=200(MB/s)
block_size=8192 mb_io_count=1 mb_io_size=8192 (bytes)
tot_io_size=0(MB) time=0(ms)
kkeCostToTime: using io calibrate stats maxpmbps=200(MB/s)
block_size=8192 mb_io_count=1 mb_io_size=8192 (bytes)
tot_io_size=0(MB) time=0(ms)
Starting SQL statement dump
user_id=0 user_name=SYS module=sqlplus.exe action=
sql_id=a5ks9fhw2v9s1 plan_hash_value=272002086 problem_type=3
----- Current SQL Statement for this session (sql_id=a5ks9fhw2v9s1) -----
select * from dual
sql_text_length=19
sql=select * from dual
----- Explain Plan Dump -----
----- Plan Table -----
============
Plan Table
============
-------------------------------------+-----------------------------------+
| Id | Operation | Name | Rows | Bytes | Cost | Time |
-------------------------------------+-----------------------------------+
| 0 | SELECT STATEMENT | | | | 2 | |
| 1 | TABLE ACCESS FULL | DUAL | 1 | 2 | 2 | 00:00:01 |
-------------------------------------+-----------------------------------+
Uf, pak už print other_xml a tedy print outline hintu a to je vše. Takže to byl spíše takový rychlý popis tak tento trace file vypadá. Oracle neměl na takhle jednoduchém sql žádnout možnost optimalizace, transformace, permutace a předem byl předurčen jít full table scanem. Nicméně doufám, že jsem na to ukázal pár zajímavých věcí, ačkoliv to zajímavější ještě přijde, v nějaké v příštích postů bych rád prověřil vždycky nějakou zajímavou část.
A nyní bez zkladu co mi praštilo do oka:
S tímhle číslem 10053 si tu doufám, ještě užijeme spoustu legrace na blogu, je to fakt vymazlená věcička. Hébičkám zdar!