Ejecuciones anuales que provocan timeout -cap. II
Continuación del capítulo anterior. Link
Una vez que tenemos realizado un primer reajuste, vamos a ejecutar la consulta de manera mensual a ver cómo se comporta
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 1.72 1.73 0 0 0 0
Execute 1 0.00 0.00 0 84 2 0
Fetch 4 111.23 111.23 0 611839 0 31
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 112.96 112.97 0 611923 2 31
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 374
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
31 31 31 TEMP TABLE TRANSFORMATION (cr=611924 pr=0 pw=0 time=111241166 us starts=1)
Los tiempos no son buenos, casi dos minutos para devolver 31 filas y con una lectura de más de medio millón de bloques.
Vamos a revisar el árbol de ejecución a ver si vemos algo raro
30658 30658 30658 FILTER (cr=0 pr=0 pw=0 time=34826178 us starts=15579725)
30658 30658 30658 VIEW (cr=0 pr=0 pw=0 time=29335545 us starts=15579725 cost=2 size=26 card=1)
62284468 62284468 62284468 TABLE ACCESS FULL SYS_TEMP_0FD9D6953_3C582193 (cr=0 pr=0 pw=0 time=17474932 us starts=15579725 cost=2 size=40 card=2)
1 1 1 HASH JOIN SEMI (cr=105 pr=0 pw=0 time=670 us starts=1 cost=36 size=94 card=1)
1 1 1 MERGE JOIN CARTESIAN (cr=76 pr=0 pw=0 time=424 us starts=1 cost=24 size=61 card=1)
Lo que intuía lo que realicé en el primer reajuste, el with está jugando malas pasadas.
Voy a generar el explain plan de la query a ver si hay accesos extraños como conversiones o funciones internas de oracle que ocasionen accesos incorrectos.
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("RV_HIGH_VALUE"="C"."PAR_DES_CORTA")
4 - access("RV_LOW_VALUE"="B"."PAR_DES_CORTA")
5 - filter("RV_HIGH_VALUE" IS NOT NULL AND "RV_DOMAIN"='PARTIDAS_IBOST_REE')
11 - filter( EXISTS (SELECT 0 FROM (SELECT /*+ CACHE ("T1") */ "C0" "RV_LOW_VALUE","C1" "RV_LOW_VALUE_CODIGO","C2" "RV_HIGH_VALUE","C3"
"RV_HIGH_VALUE_CODIGO" FROM "SYS"."SYS_TEMP_0FD9D6954_3C582193" "T1") "PARTIDAS_IBOST_REE" WHERE 948<>:B1 AND "RV_LOW_VALUE_CODIGO"=:B2
AND "RV_HIGH_VALUE_CODIGO"=:B3 AND "RV_LOW_VALUE_CODIGO"<>948) AND EXISTS (SELECT 0 FROM "LIQUIDACIONES"."CG_REF_CODES"
"C","LIQUIDACIONES"."CG_REF_CODES" "B","LIQUIDACIONES"."CG_REF_CODES" "A" WHERE "C"."RV_HIGH_VALUE">="A"."RV_HIGH_VALUE" AND
"A"."RV_LOW_VALUE"="B"."RV_LOW_VALUE" AND "A"."RV_DOMAIN"='VERSIONES_REE' AND "B"."RV_DOMAIN"='DOM_VERSION_REE_FACTURACION' AND
"C"."RV_LOW_VALUE"=:B4 AND "C"."RV_DOMAIN"='VERSIONES_REE') OR "LDF_RMP_PAR_CODIGO"="TPC_PAR_CODIGO" AND NOT EXISTS (SELECT 0 FROM
(SELECT /*+ CACHE ("T1") */ "C0" "RV_LOW_VALUE","C1" "RV_LOW_VALUE_CODIGO","C2" "RV_HIGH_VALUE","C3" "RV_HIGH_VALUE_CODIGO" FROM
"SYS"."SYS_TEMP_0FD9D6954_3C582193" "T1") "PARTIDAS_IBOST_REE" WHERE "RV_LOW_VALUE_CODIGO"=:B5))
12 - access("T"."PCI_TML_CODIGO"="TPC"."TPC_TML_CODIGO")
13 - filter(("T"."PCI_IFL_CODIGO"=6 OR "T"."PCI_IFL_CODIGO"=8) AND "T"."PCI_TML_CODIGO"<>8)
Pues parece que si, ahí vemos un acceso extraño a consecuencia del with. Hay que replantearse la consulta sin utilizar el with y hacer un acceso lo más limpio posible a los datos.
Después de analizar y dar muchas vueltas de como podríamos enfocar la consulta para que acceda de manera correcta a los datos, se me ocurrió "doblar" la consulta para romper el exists.
Ejecutamos la query de manera diaria y de manera mensual, a ver que sucede...
Diaria
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 2.40 2.40 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 1.09 1.09 0 107426 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 3.49 3.49 0 107426 0 2
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 374
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
2 2 2 SORT GROUP BY (cr=107427 pr=0 pw=0 time=1093940 us starts=1 cost=2227 size=344 card=4)
Mensual
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 4.64 4.64 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 4 5.87 5.87 0 151784 0 31
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 10.51 10.52 0 151784 0 31
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 374
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
31 31 31 SORT GROUP BY (cr=151788 pr=0 pw=0 time=5874992 us starts=1 cost=4890 size=344 card=4)
Pues nada mal la verdad, la diaria y la mensual son casi inmmediatas, así que fantástico. ¡Casi lo tenemos!
Falta ver como se comporta de maneral anual.