Protokollgrüsse aus der Datenbank – Logging aus PL/SQL

Datenbanken sind ja dazu da, Daten zu speichern. Die Daten werden in irgendeiner Form verarbeitet. Das kann sein vor dem Speichern in der Datenbank, in dem die Daten von anderen Systemen zusammengesammelt und – gestellt werden und dann in die Datenbank geladen werden. Es kann auch sein, dass die Daten innerhalb der Daten weiter verarbeitet, z.B. aggregiert, werden. Diese Verarbeitung übernimmt ein Batch, der vorzugsweise nachts läuft und im Idealfall für vor den Bürozeiten beendet ist, so dass pünktlich zum Arbeitsbeginn die akteullen Daten zur Verfügung stehen.

So ein Batch kann aus verschiedenen Scripten auf unterschiedlichen Servern bestehen, aber auch aus einem Script innerhalb der Datenbank. Das können SQL-Scripte sein, aber auch Programmcode, also in ORACLE’s Programmiersprache PL/SQL geschrieben.
Wichtig für so ein Batch sind Protokolle über den Ablauf. Darin kann der DevOps-Engineer sehen, ob alles fehlerfrei verarbeitet wurde, wie lange der Batch gedauert usw.

Protokollieren ist in einem Shellscript sehr einfach, man lenkt echo-Ausgaben zwischen den verarbeitenden Scritten in ein Logfile aus – fertig.
Aber wie geht das aus der Datenbank heraus? Im Normalfall, startet man sqlplus und für darin entweder ein SQL-Script, also irgendwelche Insert-Update-Delete-Sequenzen, aus oder man startet ein PL/SQL-Schnipsel, entweder als stored procedure oder function – standalone oder in einem Package hinterlegt – oder als anonymen Block. Die Ausgaben bei solchen Scripten sind nur soundsoviel Rows inserted, updated oder deleted oder „function (oder procedure) successful finished oder es gab irgendeinen Fehler.

Log-Einträge beim Ausführen eines Scripts in sqlplus

Für SQL-Scripts mag das vielleicht reichen, aber bei der Ausführung von etwas komplexeren PL/SQL-Objekten möchte man schon wissen, was gerade wie verarbeitet wurde oder wo die Verarbeitung gerade steht usw.
D.h. man braucht Funktionen oder Prozeduren, die im PL/SQL-Code aufgerufen werden.
Man könnte DBMS_OUTPUT verwenden.Allerdings würde dann alles in der sqlplus-Session ausgegeben werden. Und nicht alle Datentypen können mit DBMS_OUTPUT ausgegeben werden. Und wenn man nicht die richtigen Einstellungen hat, sind die Ausgaben futsch. Das Gleiche gilt für Ausgaben in Prozeduren, die als Job ausgeführt werden.

Deswegen musste ich mir etwas anderes überlegen, und dabei ist der logFileMgr entstanden. Dies ist ein Package, mit dem man in definierte Logfiles, die irgendwo auf dem Datenbankserver liegen können, schreiben kann. Zusätzlich kann man seine Ausgaben in verschiedene Log Levels unterteilen, je nach Bedeutung der Ausgabe und ähnlich den Log Levels in Linux:

  • Level 1 – „alert“
  • Level 2 – „critical“
  • Level 3 – „error“
  • Level 4 – „warning“
  • Level 5 – „notice“
  • Level 6 – „information“
  • Level 7 – „debug“

Level-1-Meldungen sind also Meldungen, die schwerwiegende Fehlerzustände anzeigen, Level-7-Meldungen sind dafür da, um Debugmeldungen auszugeben.
Nun kann man für einen PL/SQL-Prozedur-Lauf in einem Konfigurationsfile ein Log Level angeben, z.B: 4 (warning). Damit werden alle Protokollausgaben grösser als 4 ignoriert, alle Ausgaben mit einem Log Level kleiner oder gleich 4 werden ausgegeben. Auf diese Art und Weise ist es nun möglich, Stored Procedures zu entwickeln, die alle Ausgaben von kritisch bis Debug enthalten. Der DevOps-Engineer, der den Betrieb verantwortet, kann nun den für ihn im Betrieb ausreichenden Log Level in der Konfiguration setzen, z.B. 5 (notice). Sollte es beim Ausführen der Prozedur zu Fehlern kommen, kann der Log Level einfach auf 7 (debug) gesetzt und anhand der nun ausgegebenen Debug-Informationen der Fehler gesucht werden.

Die Konfigurationsdatei, in der man die Logfiles und das Ausgabeverhalten beschreibt, kann ebenfalls irgendwo auf dem Datenbankserver, egal ob UNIX/Linux oder Windows, abgelegt werden.

###################################
#  Description:
#  ============
#  Example for a Log Configuration
#
#   File:            logging.cfg
#   Author:          Andy Kielhorn
#   Company:         AkiCom
###################################
#
# Logging for PL/SQL batch TESTLOG
#
TESTLOG_LOGLEVEL=7
TESTLOG_LOGFILE=/opt/oracle/admin/log/testlog.log
TESTLOG_LOGFORMAT=ALL
#
# Logging for PL/SQL module WATCHDOG
#
WATCHDOG_LOGLEVEL=4
WATCHDOG_LOGFILE=/opt/watchdog/log/watchDogDeamon.log
WATCHDOG_LOGFORMAT=ALL

Die Datei kann mehrere Konfigurationen für verschiedene PL/SQL-„Batches“ enthalten. Pro „Batch“ oder Modul gibt es drei Parameter, die immer mit dem Namen des Batches oder dem Modul beginnen.

Log Level

Mit dem Parameter der Form <Modulname>_LOGLEVEL= [1|2|3|4|5|6|7] stellt man den Log Level ein. D.h. wie schon beschrieben, es werden alle Ausgaben mit einem Log Level, der kleiner oder gleich dem hier angegebenen ist, ausgegeben.

Logfile

Mit dem Parameter der Form <Modulname>_LOGFILE=<Log File mit Pfad> gibt man den Namen und den Speicherort des Logfiles auf dem Server an.

Logformat

Der Parameter
<Modulname>_LOGFORMAT=[ALL|NAME|TIME|HOUR|DAY|SHORT] gibt das Ausgabeformat für den Zeitstempel auf der linken Seite der Ausgabe fest

Log-Ausgaben mit logFileMgr

Bei Logformat NAME wird kein Zeitstempel ausgegeben, bei HOUR und SHORT wird kein Datum ausgegeben, während bei DAY die Uhrzeit fehlt.

Um das Logging zu starten muss die Funktion logInit aufgerufen werden, dabei muss der Pfad zur Konfigurationsdatei, der Name der Konfigurationsdatei und der Name des Moduls, dessen Konfiguration geladen werden soll. Danach stehen verschiedene writeLog-Prozeduren zur Verfügung, mit denen man Log-Einträge in der Protokolldatei erzeugen kann. Zu dem gibt es noch eine Prozedur raiseError, die einen Log-Eintrag erzugt und danach einen Fehler „raised“.

Alle Log Level sowie alle Log-Formate sind als Konstanten in der Package Spezifikation hinterlegt.

CREATE OR REPLACE PACKAGE logFileMgr IS
   /* *****************************************************************************
   * Description
   * ============
   *  This package enables logging in UNIX files system
   *
   *   File:          pkg_akitools_logfilemgr_ph.sql
   *   Modified at:   $Date: 2020-01-01 08:00:00 +0200 (Mi, 01 Jan 2020) $
   *   Checked in by: $Author: AKielhorn $
   *   Revision:      $Revision: 100 $
   *   Author:        Andy Kielhorn
   *   Company:       AkiCom
   *****************************************************************************
   */
   
   /* ====================================================================================
                                         Constants
     =====================================================================================

      ************************************************************************************
                                 L O G G I N G L E V E L S                               
       The logging system introduces different levels (logging levels) of the protocol 
       scope. These are based on the logging levels of the operating system Linux and 
       are defined in the following.
       It applies that all messages will be written to logfile that correspond to the 
       set level and the one below it. 
       For example you set Level 4, so all messages from level 1 to level 4 will be 
       writtento logfile                   
      ************************************************************************************

      Level 1  - "alert"

       With this logging level, a module only outputs messages that are acted upon 
       immediately otherwise the system will suffer a production standstill.
       This message must be forwarded to the person responsible for the system 
       immediately. 
   */
   c_alert CONSTANT PLS_INTEGER := 1;
   
   /* Level 2 - "critical"

      Messages of this logging level indicate a critical status.
      Here, too, the person responsible for the system should be informed.
   */
   c_critical CONSTANT PLS_INTEGER := 2;
   
   /* Level 3 - "error"

      Messages with this logging level log errors in a module.
   */
   c_error CONSTANT PLS_INTEGER := 3;
   
   /* Level 4 - "warning"

     The messages classified by the module as warnings are logged here.
   */
   c_warning CONSTANT PLS_INTEGER := 4;
   
   /* Level 5 - "notice"

      In this level, normal but important information of the modules are logged
   */
   c_notice CONSTANT PLS_INTEGER := 5;
   
   /* Level 6 - "information"

      This level denotes simple information of no major importance, which
      can also be ignored.
   */
   c_info CONSTANT PLS_INTEGER := 6;
   
   /* Level 7 - "debug"

      Debug messages are the least relevant messages and are the most important
      for checking freshly written software for possible errors or for tracking down
      exploited by errors in existing software.
   */
   c_debug CONSTANT PLS_INTEGER := 7;
   
   /* Options for the left site of logging message */
   /* only module name */
   logFormatName    CONSTANT VARCHAR2(10) := 'NAME';
   /* only day and night */
   logFormatTime    CONSTANT VARCHAR2(10) := 'TIME';
   /* only time */
   logFormatHour    CONSTANT VARCHAR2(10) := 'HOUR';
   /* only day */
   logFormatDay     CONSTANT VARCHAR2(10) := 'DAY';
   /* all */
   logFormatAll     CONSTANT VARCHAR2(10) := 'ALL';
   /* only name and time -&gt; short*/
   logFormatShort CONSTANT VARCHAR2(10) := 'SHORT';
   
   /* Errors that can occured during file operations */
   logInvalidPath       CONSTANT    NUMBER := -1;
   logInvalidMode       CONSTANT    NUMBER := -2;
   logInvalidFileHandle CONSTANT    NUMBER := -3;
   logInvalidOperation  CONSTANT    NUMBER := -4;
   logReadError         CONSTANT    NUMBER := -5;
   logWriteError        CONSTANT    NUMBER := -6;
   logInternalError     CONSTANT    NUMBER := -7;
   logNoCFGFile         CONSTANT    NUMBER := -8;
   logLogConfigFound    CONSTANT    NUMBER := -9;
   logWrongOpenMode     CONSTANT    NUMBER := -10;
   logNoDataFound       CONSTANT    NUMBER := -100;
   
   
  /* ******************************************************************************************
     * Function:    logInit
     * Description: initialisation of logging,
     *              read logging configuration
     *
     * Parameter:   i_moduleName    - Name of module logging is initiate for
     *              i_logCfgPath    - Path of Logging configuration file
     *              i_logCfgFile    - Logging configuration file
     *
     * Returnvalue: 0 = No errors, else Error 
     ******************************************************************************************
   */
   FUNCTION logInit( i_moduleName  IN VARCHAR2,
                     i_logCfgPath  IN VARCHAR2 DEFAULT '/tmp',
                     i_logCfgFile  IN VARCHAR2 DEFAULT 'logging.cfg') RETURN NUMBER;

    /* ********************************************************************************************************
       * Procedure:      writeLog
       * 
       * Description:    procedure logs all given information in table message_log
       *
       * Parameters:     i_v_moduleName        - name of calling module
       *                 i_n_moduleCodeLine    - line number in code of calling module
       *                                         for messages with given parameters
       *                 i_n_loggingLevel      - logging level of message
       *                 i_v_messageText       - free style message
       *                 i_b_setAppInfo        - TRUE = set application info (DBMS_APPLICATION_INFO)
       ********************************************************************************************************
    */
   PROCEDURE writeLog (i_v_moduleName       IN VARCHAR2,
                       i_n_moduleCodeLine   IN NUMBER,
                       i_n_loggingLevel     IN PLS_INTEGER,
                       i_v_messageText      IN VARCHAR2,
                       i_b_setAppInfo       IN BOOLEAN DEFAULT FALSE);
                       
   /* ********************************************************************************************************
      * Procedure:    writeLog
      * Description:  Procedure logs all given information in table message_log
      *
      * Parameters:   i_n_moduleName        -  name of calling module
      *               i_n_moduleCodeLine    -  line number in code of calling module
      *                                        for messages with given parameters
      *               i_n_loggingLevel      -  logging level of message
      *               i_v_messageText       -  free style message
      *               i_n_dbErrorID         -  Error-ID of DB
      *               i_v_dbErrorText       -  error message
      ********************************************************************************************************
    */

   PROCEDURE writeLog (i_v_moduleName       IN VARCHAR2,
                       i_n_moduleCodeLine   IN NUMBER,
                       i_n_loggingLevel     IN PLS_INTEGER,
                       i_v_messageText      IN VARCHAR2,
                       i_n_dbErrorID        IN NUMBER,
                       i_v_dbErrorText      IN VARCHAR2);
                       
    /* ********************************************************************************************************
       * Procedure:    raiseError
       * Description:  Procedure logs all given information in table message_log and raise DB error
       *
       * Parameters:   i_n_moduleName        -  name of calling module
       *               i_n_moduleCodeLine    -  line number in code of calling module
       *                                        for messages with given parameters
       *               i_n_loggingLevel      -  logging level of message
       *               i_v_messageText       -  free style message
       *               i_n_dbErrorID         -  Error-ID of database
       *               i_v_dbErrorText       -  error message
       ********************************************************************************************************
    */
   PROCEDURE raiseError (i_v_moduleName       IN VARCHAR2,
                         i_n_moduleCodeLine   IN NUMBER,
                         i_n_loggingLevel     IN PLS_INTEGER,
                         i_v_messageText      IN VARCHAR2,
                         i_n_dbErrorID        IN NUMBER,
                         i_v_dbErrorText      IN VARCHAR2);                                           

END LogFileMgr;

Das Schema, das den logFileMgr enthält, benötigt SELECT-Zugriff auf die View DBA_DIRECTORIES, ausserdem das Recht CREATE ANY DIRECTORY.
Damit das Package datenbankweit benutzt werden kann, sollte man ein public Synonym für das Package erzeugen und die Execute-Rechte an Public vergeben.
Nun kann man die Funktionen des logFileMgr in seinem eigenen PL/SQL-Quellcode benutzen, wie z.B. hier:

CREATE OR REPLACE PROCEDURE testLog
IS

 /* *****************************************************************************
    * Description
    * ============
    *  This procedure shows how to use LogFileMgr
    *
    *   File:          proc_akitools_testLog.sql
    *   Modified at:   $Date: 2020-01-01 08:00:00 +0200 (Mi, 01 Jan 2020) $
    *   Checked in by: $Author: AKielhorn $
    *   Revision:      $Revision: 100 $
    *   Author:        Andy Kielhorn
    *   Company:       AkiCom
    *****************************************************************************
 */
   
    retCode   NUMBER;
BEGIN
    retCode :=
        logFileMgr.logInit (i_moduleName   => $$PLSQL_UNIT,
                            i_logCfgPath   => '/opt/oracle/admin/log/config',
                            i_logCfgFile   => 'logging.cfg');
    logFileMgr.writeLog (
        i_v_moduleName       => $$PLSQL_UNIT,
        i_n_moduleCodeLine   => $$PLSQL_LINE,
        i_n_loggingLevel     => logFileMgr.c_debug,
        i_v_messageText      => '# LogInit returncode: ' || retCode);
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_info,
                         i_v_messageText      => '> Start Batch TestLog');
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_alert,
                         i_v_messageText      => '+ This is an alert message');
    logFileMgr.writeLog (
        i_v_moduleName       => $$PLSQL_UNIT,
        i_n_moduleCodeLine   => $$PLSQL_LINE,
        i_n_loggingLevel     => logFileMgr.c_critical,
        i_v_messageText      => '+ This is a critical message');
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_error,
                         i_v_messageText      => '! This is an error message',
                         i_n_dbErrorID        => -1412,
                         i_v_dbErrorText      => SQLERRM (-1412));
    logFileMgr.writeLog (
        i_v_moduleName       => $$PLSQL_UNIT,
        i_n_moduleCodeLine   => $$PLSQL_LINE,
        i_n_loggingLevel     => logFileMgr.c_warning,
        i_v_messageText      => '+ This is a warning message');
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_notice,
                         i_v_messageText      => '+ This is a notice message');
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_info,
                         i_v_messageText      => '+ This is an info message');
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_debug,
                         i_v_messageText      => '+ This is a debug message');
    logFileMgr.writeLog (i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_info,
                         i_v_messageText      => '< End Batch TestLog');
 EXCEPTION 
   WHEN OTHERS THEN
    logFileMgr.raiseError(i_v_moduleName       => $$PLSQL_UNIT,
                         i_n_moduleCodeLine   => $$PLSQL_LINE,
                         i_n_loggingLevel     => logFileMgr.c_error,
                         i_v_messageText      => '! This is an error message',
                         i_n_dbErrorID        => SQLCODE,
                         i_v_dbErrorText      => SQLERRM);                 
END testLog;

Die Prozedur schreibt Log-Einträge in das Protokoll /opt/oracle/admin/log/testlog.log.

01.02.2022 20:33:49 TESTLOG (26) &lt;7>: # LogInit returncode: 0
01.02.2022 20:33:49 TESTLOG (30) &lt;6>: > Start Batch TestLog
01.02.2022 20:33:49 TESTLOG (34) &lt;1>: + This is an alert message
01.02.2022 20:33:49 TESTLOG (39) &lt;2>: + This is a critical message
01.02.2022 20:33:49 TESTLOG (43) &lt;3>: ! This is an error message
01.02.2022 20:33:49 TESTLOG (43) &lt;3>: ! Error -1412: ORA-01412: Länge gleich Null ist für diesen Datentyp nicht gestattet
01.02.2022 20:33:49 TESTLOG (50) &lt;4>: + This is a warning message
01.02.2022 20:33:49 TESTLOG (54) &lt;5>: + This is a notice message
01.02.2022 20:33:49 TESTLOG (58) &lt;6>: + This is an info message
01.02.2022 20:33:49 TESTLOG (62) &lt;7>: + This is a debug message
01.02.2022 20:33:49 TESTLOG (66) &lt;6>: &lt; End Batch TestLog

Der logFileMgr zusammen mit einem Installationsscript, der Testprozedur und einem Beispiel für die Log-Konfiguration können im Download-Bereich heruntergeladen werden.
Ich hoffe, dass der logFileMgr an der einen oder anderen Stelle eingesetzt wird und nützlich ist.
Über ein Feedback und Verbesserungsvorschläge würde ich mich freuen.

Dieser Beitrag wurde unter ORACLE - PLSQL veröffentlicht. Setze ein Lesezeichen auf den Permalink.

Schreibe einen Kommentar

Deine E-Mail-Adresse wird nicht veröffentlicht. Erforderliche Felder sind mit * markiert