Wie kann man PL/SQL Code tunen? Diese Frage kommt in regelmäßigen Abständen auf, wenn Oracle Datenbank Applikationen getestet, analysiert und getunt werden sollen. Wenn es sich um die Analyse von “reinem” SQL Code handelt, ist die Nutzung von Ausführungspläne, SQL Traces, AWRs, SQL Access Advisor und Performance Analyzer das richtige Mittel der Wahl. Wie geht man aber bei der Analyse von PL/SQL Code vor? Wie findet man Bottlenecks im PL/SQL Code?  

Hier kommt das traditionelle Werkzeug PL/SQL Profiling oder auch PL/SQL Hierarchical Profiler zum Tragen. PL/SQL Profiler ist ein  kostenfreies, internes Interface der Oracle Datenbank, das das Ausführungsprofil eines PL/SQL-Programms nach Funktionsaufrufen gliedert und dabei SQL- und PL/SQL- Ausführungszeiten getrennt auflistet. Es ist keine spezielle Vorbereitung des Quellcodes oder des Compilers erforderlich; jedes PL/SQL-Programm kann damit überprüft werden. Um zu zeigen, wie einfach und schnell das Arbeiten damit ist, führe ich die Funktionsweise an einem kurzen Beispiel vor. 

Das Setup

Um den PL/SQL Profiler zu verwenden, sind folgende Vorbereitungen bzw Voraussetzungen erforderlich:

  1. EXECUTE Rechte auf das Package DBMS_HPROF

  2. READ und WRITE Rechte auf ein logisches Verzeichnis, in dem die Trace-Datei(en) gespeichert werden

  3. Erzeugen von Repository-Hilfstabellen, um die Informationen persistent zu speichern.

Hinweis: Das Directory kann einen beliebigen Namen haben. Bei der automatisierten Verwendung im SQL Developer allerdings ist der Verzeichnis-Name PLSHPROF_DIR Voraussetzung für die fehlerfreien Nutzung. 

Wir führen das Setup am Beispiel eines Testusers mit Namen PLTEST durch:

SQL> create directory PLSHPROF_DIR as '/home/oracle/pl';
SQL> grant all on directory plshprof_dir to pltest;
SQL> grant execute on dbms_hprof to pltest;

-- als User PLTEST 

SQL> execute DBMS_HPROF.CREATE_TABLES();

Der letzte Aufruf erzeugt die 4  Repository-Tabellen DBMSHP_TRACE_DATA, DBMSHP_RUNS, DBMSHP_FUNCTION_INFO und DBMSHP_PARENT_CHILD_INFO zum Speichern und Abfragen der Trace-Informationen in der Datenbank.

Und nun können wir mit dem Profiling beginnen. Folgendes Test-Programm soll analysiert werden.

CREATE OR REPLACE PROCEDURE testprof AUTHID DEFINER IS
  n NUMBER;

  PROCEDURE foo IS
  BEGIN
     SELECT COUNT(*) INTO n FROM scott.EMP;
     dbms_output.put_line('ausgabe: '||n);
  END foo;

BEGIN  -- test
  FOR i IN 1..3 LOOP
    foo;
  END LOOP;
END testprof;
/

Die Nutzung 

Die Verwendung des PL/SQL Profilers ist einfach und besteht nur aus dem Start des Profilers, der Programmausführung und dem Stoppen des Profilers. Das Ganze sieht dann für unser Beispiel folgendermaßen aus: 

execute dbms_hprof.start_profiling(LOCATION=>'PLSHPROF_DIR',  FILENAME=> 'run1.trc');

execute testprof;

execute dbms_hprof.stop_profiling;

Und fertig!
Wirft man einen Blick in das Verzeichnis PLSHPROF_DIR findet man eine Trace-Datei mit Namen run1.trc, die die sogenannten “Raw Profiler Output”-Informationen – also unformatierten Performance Daten – enthält.  Diese Daten sind im ASCII-Format und können zur Analyse herangezogen werden.

Einfacher geht es allerdings mit dem Linemode Programm plshprof im Verzeichnis $ORACLE_HOME/bin/. Es erzeugt formatierte und gut lesbare HTML-Berichte aus der Raw Profiler- Ausgabedatei.

Die Funktionsweise lässt sich durch einen einfachen Aufruf beschreiben: 

[oracle@de pl]$ plshprof

PLSHPROF: Release 19.0.0.0.0 - Production on Wed Nov 3 16:59:38 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

Usage: plshprof [<option>...] <tracefile1> [<tracefile2>]
  Options:
    -trace <symbol>    (no default)     specify function name of tree root
    -skip <count>      (default=0)      skip first <count> invokations
    -collect <count>   (default=1)      collect info for <count> invokations
    -output <filename> (default=<symbol>.html or <tracefile1>.html)
    -summary                            print time only

 

Wir führen plshprof mit der Trace-Datei run1.trc aus und erhalten eine HTML- Datei mit Namen run1.html.

[oracle@de pl]$ plshprof run1.trc
[7 symbols processed]
[Report written to 'run1.html']

Die Navigation über die entsprechenden Hyperlinks bieten eine sehr gute Möglichkeit, die Performance der PL/SQL- Anwendungen zu analysieren. So werden eine Reihe von Reports erstellt, die Informationen aus dem Ausgabeprotokoll des Profilers darstellen und in Zusammenhang setzen. Die folgenden Berichte sind beispielsweise ein guter Ausgangspunkt um die Analyse zu starten:

  • Function Elapsed Time (microsecs) Data sorted by Total Subtree Elapsed Time (microsecs)  

  • Function Elapsed Time (microsecs) Data sorted by Total Function Elapsed Time (microsecs)

  • SQL ID Elapsed Time (microsecs) Data sorted by SQL ID

Jeder Bericht auf Funktionsebene ist dabei nach einem bestimmten Attribut sortiert, z. B. nach Funktionszeit oder nach “Subtree”-Zeit.
Eine ausführliche Beschreibung zu allen Abschnitten des plshprof Reports findet sich im Database Developer Guide im Kapitel 15.5 plshprof Utility.

Dabei sind die Unterprogramme, die der PL/SQL Profiler analysiert, in sogenannte Namespaces unterteilt. So steht beispielsweise “__plsql_vm” für den Call der PL/SQL Virtual Machine, “__anonymous_block” für einen PL/SQL Anonymous Block und __static_sql_exec_lineline# für Statisches SQL in Zeile line#. In meinem Beispiel sieht die erste Seite eines plshprof Reports folgendermaßen aus.

Bild 1: plshprof Report – ein Ausschnitt
Insgesamt benötigt die Ausführung 317 Mikrosekunden für 15 Funktionsaufrufen. Gemessen an der absoluten Funktionszeit im zweiten Abschnitt kann man gut erkennen, dass das SQL Statement, das mit einer SQL ID gekennzeichnet ist, die meiste Zeit verbraucht und mehrfach vom Programm FOO aufgerufen wird. Darüberhinaus erhält man weitere Berichte über die Hyperlinks, um den Zeitverbrauch von SQL und PL/SQL oder der einzelnen Funktionen untereinander zu vergleichen, um nur ein paar Beispiele zu nennen.

Möchte man die Informationen aus der Trace-Datei persistent in der Datenbank speichern, um z.B. die Daten zu einem späteren Zeitpunkt weiterzuverarbeiten, ist zusätzlich ein ANALYZE erforderlich. 

SQL> var runid number
SQL> execute :runid:=DBMS_HPROF.analyze('PLSHPROF_DIR', 'run1.trc');
PL/SQL procedure successfully completed.

Jetzt sind die 4 Repository Tabellen gefüllt. Über entsprechende SQL Aufrufe lassen sich nun die Informationen beliebig auswerten. In folgendem Beispiel erhält man einen Überblick über die Testläufe. Insgesamt sind 2 Testläufe durchgeführt worden. 

SQL> select * from DBMSHP_RUNS;

     RUNID RUN_TIMESTAMP                  TOTAL_ELAPSED_TIME
---------- ------------------------------ ------------------
RUN_COMMENT
------------------------------------------------------------
  TRACE_ID
----------
         1 08-NOV-21 05.51.53.529303 PM                  317

         1

         2 08-NOV-21 06.18.34.653007 PM                 2716

         2

Nutzt man SQL Developer für die Abfrage der respository Tabellen, bekommt man folgende Ausgabe am Beispiel von DBMSHP_FUNCTION_INFO. 

Bild 2: Abfrage von DBMSHP_FUNCTION_INFO im SQL Developer

SQL Developer

Der PL/SQL Profiler lässt sich natürlich auch im Worksheet von SQL Developer verwenden. Darüberhinaus gibt es zusätzlich die Möglichkeit eine automatisierte Anwendung zu nutzen. Dazu muß man die entsprechende Prozedur, Funktion oder Package im Menü auswählen und im Worksheet den “Profiler” Button betätigen. Dieser automatisiert das Profiling und die Speicherung in den Repository Tabellen.

Wichtig ist dabei die Verwendung eines logischen Directories mit Namen PLSHPROF_DIR, um eine fehlerfreie Funktionsweise zu garantieren.

Folgender Blogeintrag und folgendes Video zeigen die Verwendung im SQL Developer:

Bild 3: PL/SQL Profiler Verwendung im SQL Developer


Bild 4: PL/SQL Profiler Auswertungen im SQL Developer

Nachtrag: Keinen Zugriff auf ein logisches Directory – was tun?

Als ich mich vor Kurzem mit meinem Kollegen über das Thema unterhalten habe, kamen wir auf Kunden zu sprechen, die nur eingeschränkte Privilegien auf ihre Oracle Umgebung haben und die vielleicht keinen Zugriff auf ein logisches Directory haben. Was kann man dann tun? Hier gibt es die Möglichkeit mit dem “altbewährten” Package DBMS_PROFILER zu arbeiten, das die Daten direkt in Datenbank-Tabellen schreibt. Der Ablauf ähnelt dem beschriebenen Vorgehen von DBMS_HPROF.
Zuerst werden die zugehörigen Repository-Tabellen PLSQL_PROFILER_RUNS, PLSQL_PROFILER_DATA und PLSQL_PROFILER_UNITS im Applikationsschema erzeugt. Dazu verwendet man das Dienstprogramms proftab.sql aus dem $ORACLE_HOME/rdbms/admin Verzeichnis.

SQL> start proftab.sql;

Danach erfolgt das Starten des Profilers, die Code-Ausführung und das Stoppen – statt mit DBMS_HPROF jetzt mit DBMS_PROFILER. Das Ganze sieht dann z.B. folgendermaßen aus:

SQL> execute dbms_profiler.start_profiler;

SQL> execute testprof;

SQL> execute dbms_profiler.stop_profiler;

Nun sind die Tabellen gefüllt und man kann die entsprechenden Abfragen durchführen. Zum Beispiel, welche Tests gibt es mit einer Abfrage auf PLSQL_PROFILER_RUNS.

SQL> select runid, run_date, run_comment from plsql_profiler_runs;      
RUNID      RUN_DATE  RUN_COMMENT
---------- --------- --------------------          
2          13-NOV-21 13-NOV-21          
1          12-NOV-21 12-NOV-21

Falls man ähnliche Unterstützung für einen HTML-Report sucht, wie in den vorangegangenen Kapiteln gezeigt wurde, kann man dazu das Skript profiler.sql verwenden. Man findet es in der My Oracle Support Note Doc ID 243755.1 oder kann es hier herunterladen. Folgender Aufruf liefert dann den zugehörigen HTML-Report für den Lauf mit Runid 1.

SQL> start profiler.sql 1
 RUNID RUN_OWNER                 RUN_DATE        RUN_COMMENT
------ ------------------------- --------------- ----------------
     1 PLTEST                    12-NOV-21 10:40 12-NOV-21
...
PROFILER file has been created:
profiler_US1_de_19.0.0.0.0_20211112_145038.html.

Hinweis: In meinem Fall benötigte der Applikationsuser das zusätzliche Privileg auf den Data Dictionary Katalog – speziell auf die View DBA_SOURCE – zuzugreifen, um damit fehlerfrei zu arbeiten.

Das Ergebnis sieht dann folgendermaßen aus:

Bild 5: profiler.sql Report – ein Ausschnitt

Weitere Informationen