Das Phänomen ist offenbar relativ bekannt, war mir aber bisher nicht begegnet (oder in Erinnerung geblieben): ein Icinga-Test zur Bestimmung des Füllgrads eines Tablespaces erreichte zuletzt Laufzeiten von über einer Minute, was zu Timeouts und Icinga-Fehlern führte. Schnell zu bestimmen war, dass das eigentliche Problem im Zugriff auf DBA_FREE_SPACE lag. Aber warum reagierte diese Dictionary-View so träge? Zur Prüfung habe ich zunächst einen Blick in die Definition in DBA_VIEWS geworfen, aber den hätte ich mir sparen können, denn ein Plan mit rowsource statistics zeigte die gleichen Informationen - und lieferte darüber hinaus die entscheidenden Details. Hier ein entsprechendes Beispiel, das ich mit 12.1.0.2 erstellt habe, und das sich in diesem Release noch einmal interessanter verhält als in 11.2, wo mir das Phänomen ursprünglich begegnet war:
select /*+ gather_plan_statistics */
tablespace_name
, count(*)
from dba_free_space
group by tablespace_name
TABLESPACE_NAME COUNT(*)
------------------------------ ----------
SYSAUX 4
USERS 915
SYSTEM 1
Abgelaufen: 00:00:16.49
Plan hash value: 2867613348
-----------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 3 |00:00:17.80 | 828K| 373K| | | |
| 1 | HASH GROUP BY | | 1 | 2 | 3 |00:00:17.80 | 828K| 373K| 1452K| 1452K| 760K (0)|
| 2 | VIEW | DBA_FREE_SPACE | 1 | 68 | 920 |00:00:00.03 | 828K| 373K| | | |
| 3 | UNION-ALL | | 1 | | 920 |00:00:00.03 | 828K| 373K| | | |
| 4 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 6 | 2 | | | |
| 5 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 6 | 2 | | | |
| 6 | INDEX FULL SCAN | I_FILE2 | 1 | 3 | 3 |00:00:00.01 | 1 | 1 | | | |
|* 7 | TABLE ACCESS CLUSTER | FET$ | 3 | 1 | 0 |00:00:00.01 | 5 | 1 | | | |
|* 8 | INDEX UNIQUE SCAN | I_TS# | 3 | 1 | 3 |00:00:00.01 | 2 | 0 | | | |
|* 9 | TABLE ACCESS CLUSTER | TS$ | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
|* 10 | INDEX UNIQUE SCAN | I_TS# | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
| 11 | NESTED LOOPS | | 1 | 3 | 16 |00:00:00.01 | 19 | 6 | | | |
| 12 | NESTED LOOPS | | 1 | 3 | 16 |00:00:00.01 | 15 | 6 | | | |
|* 13 | TABLE ACCESS FULL | TS$ | 1 | 2 | 3 |00:00:00.01 | 6 | 2 | | | |
|* 14 | FIXED TABLE FIXED INDEX| X$KTFBFE (ind:1) | 3 | 2 | 16 |00:00:00.01 | 9 | 4 | | | |
|* 15 | INDEX UNIQUE SCAN | I_FILE2 | 16 | 1 | 16 |00:00:00.01 | 4 | 0 | | | |
| 16 | NESTED LOOPS | | 1 | 63 | 904 |00:00:00.17 | 828K| 373K| | | |
| 17 | NESTED LOOPS | | 1 | 188 | 904 |00:00:00.17 | 828K| 373K| | | |
|* 18 | HASH JOIN | | 1 | 20 | 102 |00:00:00.01 | 10 | 1 | 1483K| 1483K| 695K (0)|
|* 19 | TABLE ACCESS FULL | TS$ | 1 | 2 | 3 |00:00:00.01 | 6 | 0 | | | |
|* 20 | TABLE ACCESS FULL | RECYCLEBIN$ | 1 | 24 | 102 |00:00:00.01 | 4 | 1 | | | |
|* 21 | FIXED TABLE FULL | X$KTFBUE | 102 | 9 | 904 |00:00:17.54 | 828K| 373K| | | |
|* 22 | INDEX UNIQUE SCAN | I_FILE2 | 904 | 1 | 904 |00:00:00.01 | 4 | 1 | | | |
| 23 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 302 | 2 | | | |
| 24 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 302 | 2 | | | |
| 25 | MERGE JOIN CARTESIAN | | 1 | 73 | 306 |00:00:00.01 | 5 | 0 | | | |
| 26 | INDEX FULL SCAN | I_FILE2 | 1 | 3 | 3 |00:00:00.01 | 1 | 0 | | | |
| 27 | BUFFER SORT | | 3 | 24 | 306 |00:00:00.01 | 4 | 0 | 6144 | 6144 | 6144 (0)|
|* 28 | TABLE ACCESS FULL | RECYCLEBIN$ | 1 | 24 | 102 |00:00:00.01 | 4 | 0 | | | |
| 29 | TABLE ACCESS CLUSTER | UET$ | 306 | 1 | 0 |00:00:00.01 | 297 | 2 | | | |
|* 30 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 306 | 1 | 91 |00:00:00.01 | 206 | 2 | | | |
|* 31 | TABLE ACCESS CLUSTER | TS$ | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
|* 32 | INDEX UNIQUE SCAN | I_TS# | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
-----------------------------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------------------------------------------
7 - filter("F"."FILE#"="FI"."RELFILE#")
8 - access("F"."TS#"="FI"."TS#")
9 - filter("TS"."BITMAPPED"=0)
10 - access("TS"."TS#"="F"."TS#")
13 - filter(("TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0 AND INTERNAL_FUNCTION("TS"."ONLINE$")))
14 - filter(("TS"."TS#"="KTFBFETSN" AND INTERNAL_FUNCTION("CON_ID")))
15 - access("KTFBFETSN"="FI"."TS#" AND "KTFBFEFNO"="FI"."RELFILE#")
18 - access("TS"."TS#"="RB"."TS#")
19 - filter(("TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0 AND INTERNAL_FUNCTION("TS"."ONLINE$")))
20 - filter(("RB"."TS#" IS NOT NULL AND "RB"."FILE#" IS NOT NULL AND "RB"."BLOCK#" IS NOT NULL))
21 - filter((INTERNAL_FUNCTION("CON_ID") AND "KTFBUESEGBNO"="RB"."BLOCK#" AND "KTFBUESEGFNO"="RB"."FILE#" AND
"KTFBUESEGTSN"="RB"."TS#"))
22 - access("RB"."TS#"="FI"."TS#" AND "KTFBUEFNO"="FI"."RELFILE#")
28 - filter(("RB"."TS#" IS NOT NULL AND "RB"."FILE#" IS NOT NULL AND "RB"."BLOCK#" IS NOT NULL))
30 - access("U"."TS#"="RB"."TS#" AND "U"."SEGFILE#"="RB"."FILE#" AND "U"."SEGBLOCK#"="RB"."BLOCK#")
filter(("U"."TS#"="FI"."TS#" AND "U"."SEGFILE#"="FI"."RELFILE#"))
31 - filter("TS"."BITMAPPED"=0)
32 - access("TS"."TS#"="U"."TS#")
Note
-----
- this is an adaptive plan
Auffällig sind mehrere Punkte:
- 16 Sekunden sind ziemlich viel für die Ermittlung dieses Ergebnisses.
- die Laufzeit entfällt fast komplett auf eine der vier über UNION ALL verknüpften Teilabfragen.
- in der langsamen Teilabfrage erfolgt ein Zugriff auf RECYCLEBIN$.
- es handelt sich um einen adaptiven Plan.
Im 11.2er System habe ich durch einen Blick in den Recyclebin festgestellt, dass dort tatsächlich mehr als 1500 Varianten einer Hilfstabelle lagen, die regelmäßig gelöscht wurde, ohne dass ein Purge des Objekts erfolgte. Nach Durchführung einer Purge-Operation für die Objekt-Inkarnationen (die leider nicht komplett automatisiert erfolgen kann, weil ein PURGE TABLE [object_name] nur die älteste Inkarnation löscht) läuft die Query wieder in weniger als einer Sekunde und das Problem ist gelöst (zumal die Test-Logik angepasst wurde, die für das Löschen der Tabelle verantwortlich war).
In 12.1.0.2 ist die Lage allerdings eine andere: hier hat der Optimizer nach wenigen Ausführungen genügend Material gesammelt, um die geeignetere Version des adaptiven Plans zu verwenden:
Plan hash value: 2991530507
-----------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 3 |00:00:00.19 | 8462 | 3669 | | | |
| 1 | HASH GROUP BY | | 1 | 2 | 3 |00:00:00.19 | 8462 | 3669 | 1452K| 1452K| 740K (0)|
| 2 | VIEW | DBA_FREE_SPACE | 1 | 922 | 920 |00:00:00.04 | 8462 | 3669 | | | |
| 3 | UNION-ALL | | 1 | | 920 |00:00:00.04 | 8462 | 3669 | | | |
| 4 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 6 | 1 | | | |
| 5 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 6 | 1 | | | |
| 6 | INDEX FULL SCAN | I_FILE2 | 1 | 3 | 3 |00:00:00.01 | 1 | 0 | | | |
|* 7 | TABLE ACCESS CLUSTER | FET$ | 3 | 1 | 0 |00:00:00.01 | 5 | 1 | | | |
|* 8 | INDEX UNIQUE SCAN | I_TS# | 3 | 1 | 3 |00:00:00.01 | 2 | 0 | | | |
|* 9 | TABLE ACCESS CLUSTER | TS$ | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
|* 10 | INDEX UNIQUE SCAN | I_TS# | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
| 11 | NESTED LOOPS | | 1 | 16 | 16 |00:00:00.01 | 19 | 7 | | | |
| 12 | NESTED LOOPS | | 1 | 16 | 16 |00:00:00.01 | 15 | 7 | | | |
|* 13 | TABLE ACCESS FULL | TS$ | 1 | 2 | 3 |00:00:00.01 | 6 | 1 | | | |
|* 14 | FIXED TABLE FIXED INDEX| X$KTFBFE (ind:1) | 3 | 10 | 16 |00:00:00.01 | 9 | 6 | | | |
|* 15 | INDEX UNIQUE SCAN | I_FILE2 | 16 | 1 | 16 |00:00:00.01 | 4 | 0 | | | |
| 16 | NESTED LOOPS | | 1 | 904 | 904 |00:00:08.75 | 8135 | 3658 | | | |
|* 17 | HASH JOIN | | 1 | 904 | 904 |00:00:08.74 | 8131 | 3656 | 1087K| 1087K| 1288K (0)|
|* 18 | HASH JOIN | | 1 | 102 | 102 |00:00:00.01 | 10 | 0 | 1483K| 1483K| 913K (0)|
|* 19 | TABLE ACCESS FULL | TS$ | 1 | 2 | 3 |00:00:00.01 | 6 | 0 | | | |
|* 20 | TABLE ACCESS FULL | RECYCLEBIN$ | 1 | 102 | 102 |00:00:00.01 | 4 | 0 | | | |
|* 21 | FIXED TABLE FULL | X$KTFBUE | 1 | 1000 | 7548 |00:00:00.13 | 8121 | 3656 | | | |
|* 22 | INDEX UNIQUE SCAN | I_FILE2 | 904 | 1 | 904 |00:00:00.01 | 4 | 2 | | | |
| 23 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 302 | 3 | | | |
| 24 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 302 | 3 | | | |
| 25 | MERGE JOIN CARTESIAN | | 1 | 306 | 306 |00:00:00.01 | 5 | 1 | | | |
| 26 | INDEX FULL SCAN | I_FILE2 | 1 | 3 | 3 |00:00:00.01 | 1 | 0 | | | |
| 27 | BUFFER SORT | | 3 | 102 | 306 |00:00:00.01 | 4 | 1 | 6144 | 6144 | 6144 (0)|
|* 28 | TABLE ACCESS FULL | RECYCLEBIN$ | 1 | 102 | 102 |00:00:00.01 | 4 | 1 | | | |
| 29 | TABLE ACCESS CLUSTER | UET$ | 306 | 1 | 0 |00:00:00.01 | 297 | 2 | | | |
|* 30 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 306 | 1 | 91 |00:00:00.01 | 206 | 2 | | | |
|* 31 | TABLE ACCESS CLUSTER | TS$ | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
|* 32 | INDEX UNIQUE SCAN | I_TS# | 0 | 1 | 0 |00:00:00.01 | 0 | 0 | | | |
-----------------------------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------
7 - filter("F"."FILE#"="FI"."RELFILE#")
8 - access("F"."TS#"="FI"."TS#")
9 - filter("TS"."BITMAPPED"=0)
10 - access("TS"."TS#"="F"."TS#")
13 - filter(("TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0 AND INTERNAL_FUNCTION("TS"."ONLINE$")))
14 - filter(("TS"."TS#"="KTFBFETSN" AND INTERNAL_FUNCTION("CON_ID")))
15 - access("KTFBFETSN"="FI"."TS#" AND "KTFBFEFNO"="FI"."RELFILE#")
17 - access("KTFBUESEGTSN"="RB"."TS#" AND "KTFBUESEGFNO"="RB"."FILE#" AND "KTFBUESEGBNO"="RB"."BLOCK#")
18 - access("TS"."TS#"="RB"."TS#")
19 - filter(("TS"."CONTENTS$"=0 AND "TS"."BITMAPPED"<>0 AND INTERNAL_FUNCTION("TS"."ONLINE$")))
20 - filter(("RB"."TS#" IS NOT NULL AND "RB"."FILE#" IS NOT NULL AND "RB"."BLOCK#" IS NOT NULL))
21 - filter(("CON_ID"=0 OR "CON_ID"=3))
22 - access("RB"."TS#"="FI"."TS#" AND "KTFBUEFNO"="FI"."RELFILE#")
28 - filter(("RB"."TS#" IS NOT NULL AND "RB"."FILE#" IS NOT NULL AND "RB"."BLOCK#" IS NOT NULL))
30 - access("U"."TS#"="RB"."TS#" AND "U"."SEGFILE#"="RB"."FILE#" AND "U"."SEGBLOCK#"="RB"."BLOCK#")
filter(("U"."TS#"="FI"."TS#" AND "U"."SEGFILE#"="FI"."RELFILE#"))
31 - filter("TS"."BITMAPPED"=0)
32 - access("TS"."TS#"="U"."TS#")
Note
-----
- statistics feedback used for this statement
- this is an adaptive plan
In step 17 wird der NESTED LOOPS Join durch einen HASH JOIN ersetzt, so dass der kostspielige Zugriff auf X$KTFBUE nur einmalig erfolgt (außerdem sieht man die durch das statistics feedback hervorgerufenen Cardinality-Korrekturen). Mit dem adaptiven Plan ist das Problem also nach kurzer Zeit keines mehr. Für ältere Releases bleibt aber festzuhalten, dass ein mit vielen Objekten gefüllter Recyclebin negative Auswirkungen auf die Query-Performance für Abfragen gegen DBA_FREE_SPACE hat. Das Problem ist, wie schon erwähnt, nicht unbekannt - nachdem ich mein Ergebnis hatte, habe ich bei
Martin Widlake einen Artikel gleichen Inhalts gefunden (und es gibt weitere Artikel ähnlichen Inhalts). Weniger bekannt dürfte aber sein, dass die Schwierigkeit in 12c für alle praktischen Fragen als behoben betrachtet werden kann.