MP Oracle Blog: Performance-Probleme beim Zugriff auf DBA_FREE

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.

2 Kommentare:

Anonym17. Juli 2015 um 09:39
"... die leider nicht komplett automatisiert erfolgen kann, weil ein PURGE TABLE [object_name] nur die älteste Inkarnation löscht ..."

Hmm.

select count(*) from user_recyclebin where original_name='TEMP';

COUNT(*)
----------
63

declare
"object not in RECYCLE BIN" exception;
pragma exception_init("object not in RECYCLE BIN", -38307);
begin
loop
begin
execute immediate 'purge table temp';
exception when "object not in RECYCLE BIN" then
exit;
end;
end loop;
end;
/

PL/SQL-Prozedur erfolgreich abgeschlossen.
dp@ESJA[598]> select count(*) from user_recyclebin where original_name='TEMP';

COUNT(*)
----------
0
AntwortenLöschen
Antworten
Martin Preiss17. Juli 2015 um 10:59
Hallo Matthias,
ja, das war etwas unglücklich formuliert: mit einer Schleife ist das natürlich kein Problem. Aber ich hätte gerne ein Kommando "drop all table temp" (über die Syntax könnte man streiten", das alle Versionen zu temp aus dem Recyclebin löscht. Das steht auf meiner Oracle-Wunschliste allerdings nicht allzu weit oben...
AntwortenLöschen
Antworten

Kommentar hinzufügen

MP Oracle Blog

Seiten

Donnerstag, Juli 16, 2015

Performance-Probleme beim Zugriff auf DBA_FREE_SPACE

2 Kommentare: