21. PLVlog and PLVtrc: Logging and TracingPL/Vision provides two packages to provide execution tracing and logging from within PL/SQL programs.
Both of these packages are used by other PL/Vision packages, PLVlog in particular. For example, when you handle an exception with a PLVexc handler like rec_continue , it, in turn, calls PLVlog to log the error. 21.1 PLVlog: Logging Activity in PL/SQL ProgramsThe PLVlog (PL/Vision LOGging) package offers a powerful, generic logging mechanism for PL/SQL -based applications. The need to log activity arises in a number of different settings, including logging errors, tracing execution, and auditing activity. Rather than build this functionality over and over again, you can use PLVlog to handle many different circumstances. The central features of PLVlog include:
The following sections show how to use each of the different elements of PLVlog. 21.1.1 Controlling the Log ActionPLVlog writes information to the log only when it is turned on. The package provides a standard PL/Vision toggle to control the action of the logging mechanism. The programs comprising this toggle are: PROCEDURE turn_on; PROCEDURE turn_off; FUNCTION logging RETURN BOOLEAN; One procedure to turn on logging, another to turn it off, and a final function to indicate the current state of affairs (for completeness and politeness). All the two procedures do is set the value of a private Boolean variable, but by correctly applying that Boolean inside an IF statement in PLVlog, the package's user gets to fine-tune the package's behavior. Why would you turn off logging? You might be executing a production program for a one-time batch of millions of records. If you use the normal logging built into your program, you end up with millions of lines in the log. You can't afford the performance or disk overhead, and you don't really care about the log information for this run. So instead of modifying your program (supposed it is called analyze_sales ), you simply turn off logging as shown below: SQL> exec PLVlog.turn_off; SQL> exec analyze_sales; 21.1.2 Writing to the LogYou use the put_line procedure to write a line to the log. There are two overloaded versions of put_line ; the headers are shown below: PROCEDURE put_line (context_in IN VARCHAR2, code_in IN INTEGER, string_in IN VARCHAR2 := NULL, create_by_in IN VARCHAR2 := USER, rb_to_in IN VARCHAR2 := c_default, override_in IN BOOLEAN := FALSE); PROCEDURE put_line (string_in IN VARCHAR2, rb_to_in IN VARCHAR2 := c_default, override_in IN BOOLEAN := FALSE); The second version of put_line -- the one with only three arguments -- simply calls the first version with null values for the other arguments. It is provided for convenience, when you simply want to log a string of text and not bother with all the other values. The full set of arguments to put_line is explained in the following:
If you have turned off logging with a call to PLV log.turn_off , a call to put_line will not add any information to the log (unless you override that state of affairs). PLVlog.put_line is called from several different PL/Vision packages; I'll use those programs as examples so you can see how and why put_line has so many arguments. 21.1.2.1 Using put_line
You can use all the arguments or only the minimum. Either way, the put_line logging mechanism should come in very handy. You could even use PLVlog as a lazy way to write information to a PL/SQL table! 21.1.3 Selecting the Log TypeThe PLVlog package was designed to offer maximum flexibility for logging. The usual logging mechanism requires that you write a record to a database table. This is certainly supported by PLVlog, but you can also select a different type of log, as appropriate to your needs. The log types supported by PLVlog are: database table, PL/SQL table, operating system file, and standard output (your monitor). These different types and how to work with them are explained in the following sections. PLVlog does provide a single program, sendto , that you can use to set the log type. The header for sendto is: PROCEDURE sendto (type_in IN VARCHAR2, file_in IN VARCHAR2 := NULL); where type_in is the type of log and file_in is the name of the operating system file (relevant only if you are setting the log type to PLV.file ). The type_in must be one of the repository constants defined in the PLV package: PLV.dbtab , PLV.pstab , PLV.file , or PLV.stdout . In addition to this generic type-setting procedure, PLVlog offers a procedure that specifically sets the log type. So to set the log type to a database table, you can enter either of these commands: SQL> exec PLVlog.sendto (PLV.dbtab) or: SQL> exec PLVlog. to_dbtab To set the log type to a PL/SQL table, you can enter either of these commands: SQL> exec PLVlog.sendto (PLV.pstab) or: SQL> exec PLVlog. to_pstab To set the log type to the mylog.txt operating system file, you can enter either of these commands: SQL> exec PLVlog.sendto (PLV.file, 'mylog.txt') or: SQL> exec PLVlog. to_file ('mylog.txt') Finally, to set the log type to standard output, you can enter either of these commands: SQL> exec PLVlog.sendto (PLV.stdout) or: SQL> exec PLVlog. to_stdout When you are working with database or PL/SQL table logs, there are some other programs in PLVlog that you may find useful, as I describe below. 21.1.3.1 Defining the database log tableIf you do decide to write the log to a database table, you can either use the default log table or specify a different table. When PLVlog performs an insert to the log, it uses dynamic SQL (PLVdyn), so it can construct the INSERT statement from your inputs. This approach allows you to use PLVlog for different purposes. You can even use PLVlog within the same application and Oracle connection to write to different logs! PL/Vision provides a default log table, whose structure is shown below: CREATE TABLE PLV_log (context VARCHAR2(100), code INTEGER, text VARCHAR2(2000), create_ts DATE, create_by VARCHAR2(100)); where context is the context in which the log entry was made. This might be a program name or a section within a program or an action. The code column is a numeric code. This could be an error code or a number in use in the application. The text column contains a (possibly) long line of text. The create_ts and create_by columns provide a user and date/time audit for the creation of the log entry. PLVlog provides the set_dbtab procedure to change the name of the table and/or the names of each of the columns in the log table. The header for set_dbtab is: PROCEDURE set_dbtab (table_in IN VARCHAR2 := 'PLV_log', context_col_in IN VARCHAR2 := 'context', code_col_in IN VARCHAR2 := 'code', text_col_in IN VARCHAR2 := 'text', create_ts_col_in IN VARCHAR2 := 'create_ts', create_by_col_in IN VARCHAR2 := 'create_by'); As you can see, set_dbtab provides you with the opportunity to override the default table and column names. Here are two examples of applying set_dbtab to different application circumstances:
You can use set_dbtab to change some or all of these names, but remember that the table you select for logging must have at least these five columns with the same datatypes as the default table.
21.1.3.2 Closing the fileIf you are writing to an operating system file, you need to close that file before you can see log information written to that repository. To close the PLVlog file, use the fclose procedure: PROCEDURE fclose; You do not have to specify the file name; that information has been stored inside the package. 21.1.4 Managing a PL/SQL Table LogPLVlog lets you avoid the hassles of writing to a database log during execution of your application by writing instead to a PL/SQL table. This data structure is memory-resident and owned by the session, so you don't have to deal with commits and rollbacks. Just run your application and then either display the log or copy the contents of the log to a database table with the ps2db procedure (explained below). To set the log repository to the PL/SQL table, execute either: PLVlog.to_pstab; or: PLVlog.sendto (PLV.pstab); Then, whenever a line is written to the log, it is deposited in the next available row in the PL/SQL table. The log always starts at row 1 and moves sequentially forward. The PL/SQL table that stores the log information is a table of 2,000-byte strings, defined as follows: pstablog PLVtab.vcmax_table; When a line is written to the table it is formatted as shown below: context_in || c_delim || TO_CHAR (code_in) || c_delim || string_in || c_delim || TO_CHAR (SYSDATE, PLV.datemask) || c_delim || create_by_in || c_delim where c_delim is defined to be CHR(8) (see the explanation of the put_line procedure for more information about the individual variables in this string of concatenations). This character shows up in Windows as a black box and is a useful delimiter. 21.1.4.1 Counting and clearing the PL/SQL tableWhen you are using the PL/SQL table for logging, PLVlog provides two other programs with which to manage the table: clear_pstab and pstab_count . If you want to make sure that the PL/SQL table-based log is empty, call the clear_pstab procedure as follows: PLVlog. clear_pstab; If you want to find out the number of rows currently in the log, you can call pstab_count as shown in the following IF statement (and used in the FOR loop of the showlog.sql script above): IF PLVlog.pstab_count > 0 THEN PLVlog.display; END IF; You cannot directly access the PL/SQL table log, since the table itself is defined inside the body of the package and is, therefore, private. On the other hand, you can transfer the PL/SQL table to a database table (with the ps2db procedure). You can also get_line to retrieve a specific row from the table, as discussed in the next section. 21.1.4.2 Retrieving log data from PL/SQL tableYou can unpack a log string in the PL/SQL table into individual variables with the get_line procedure, whose header is shown below: PROCEDURE get_line (row_in IN INTEGER, context_out OUT VARCHAR2, code_out OUT INTEGER, string_out OUT VARCHAR2, create_by_out OUT VARCHAR2, create_ts_out OUT DATE); You supply the row number of the PL/SQL table in which you are interested, and get_line returns the different elements of the logged message. This program is used by the ps2db procedure, and you can use it as well to parse the log information from the PL/SQL table. The following script (stored in the showlog.sql file on the companion disk) displays all the rows in the log that were entered today for the context CALC_TOTALS: DECLARE v_context PLV_log.context%TYPE; v_code PLV_log.code%TYPE; v_text PLV_log.text%TYPE; v_create_by PLV_log.create_by%TYPE; v_create_ts PLV_log.create_ts%TYPE; BEGIN /* pstab_count is explained below. */ FOR row_ind IN 1 .. PLVlog.pstab_count LOOP PLVlog.get_line (row_ind, v_context, v_code, v_text, v_create_by, v_create_ts); IF v_create_ts BETWEEN TRUNC (SYSDATE) AND TRUNC (SYSDATE+1) AND v_context = 'CALC_TOTALS' THEN p.l (v_text); END IF; END LOOP; END; /
21.1.4.3 Transferring a PL/SQL table log to a database tablePLVlog provides the ps2db procedure to transfer the contents of the PL/SQL table log to the currently defined database log table. The header for this procedure is: PROCEDURE ps2db; Why would you bother moving the contents of the log from a PL/SQL table to a database table? You might have relied on the PL/SQL table log during the execution of your application so that you didn't have to worry about commit and rollback processing. Now the test session is done and you want to move your log information to "persistent" data. The PL/SQL table goes away when your session ends. If you move the data to a database table, you can examine the contents at your leisure and with the flexibility offered by the SQL language. 21.1.5 Rolling Back with PLVlogOne of the problems with writing log information to a database table is that the information is only available once the new rows are committed to the database. This can be a problem because PLVlog is often employed to track errors -- and in many of these situations, the current transaction has failed or otherwise requires a rollback. Figure 21.1 illustrates the complexity of maintaining transaction integrity while also preserving records written to a database table log. Transaction A raises an exception. A consequence of the exception is a rollback of the entire transaction. PLVlog is then called to put a line in the log. The application then moves on to the next transaction. If transaction B also raises an exception and issues a rollback, the record written to the log is also erased. So it is necessary to issue a savepoint immediately after the write to the database log. The final complication, however, is that when the rollback of transaction B occurs, it must roll back to the post-log savepoint. Figure 21.1: Preserving log entries while rolling back transactionsThis scenario gives rise to a number of interesting challenges for a generic logging package like PLVlog: how can it avoid saving in-error transactions while saving log information? How can the post-log transaction rollback know about the savepoint? If known, how can this dynamic rollback to a variable savepoint be accomplished? And how can Plvlog make this process as transparent as possible to users of the logging mechanism? PLVlog offers an architecture to answer these questions. It is complicated and sometimes hard to follow, but it does seem to get the job done. At a high level, I want to perform steps like this: Rollback-Transaction Insert-Line-in-Log Set-Savepoint-to-Preserve-Insert Yet when you examine "Rollback-Transaction" more closely, a question arises: Do I want to perform an unqualified rollback to reject all uncommitted changes, or do I want to roll back to a particular savepoint? PL/Vision could require that the individual developers who use PLVlog simply handle all of these rollback and savepoint issues. But that approach places a high burden on my users and makes it much less likely that PLVlog will be used to its full potential -- a drawback I take kind of personally. So, instead, PLVlog offers several different toggles, settings, and commands you can use to direct PLVlog to take precisely the right actions in the right order and at the right time. First, let's go over the way PLVlog performs rollbacks and savepoints, then examine how you can control this aspect of the package's behavior. 21.1.5.1 Toggling rollback activityIf your log repository is an operating system file or PL/SQL table, the concept of a rollback simply doesn't apply. You only have to worry about this complication when you are logging directly to a database table -- which is, after all, a pretty common activity. Suppose, then, that you are using a database table log. PLVlog will still not perform any rollbacks or issue any savepoints unless you explicitly turn on this behavior. PLVlog offers a standard PL/Vision toggle. This triumvirate of programs is: PROCEDURE do_rollback; PROCEDURE nodo_rollback; FUNCTION rolling_back RETURN BOOLEAN; One procedure to turn on rollback and savepoint activity, another to turn it off (the default), and a final function to indicate the current state of affairs. All the two procedures do is set the value of a private Boolean variable, but by correctly applying that Boolean inside an IF statement in PLVlog, the package's user gets to fine-tune the package's behavior. The discussion in the following sections assumes that at some point in your session before you tried to log activity to the database, you issued this command in SQL*Plus: SQL> exec PLVlog.do_rollback or directly executed this command inside another PL/SQL program like this: BEGIN PLVlog.do_rollback; transfer_data; END; 21.1.5.2 How PLVlog manages the transactionAssuming that you have directed PLVlog to help you manage your transaction automatically when information is sent to the database log, let's take a look at how PLVlog handles the complexities. The best way to explain this process is to show you the relevant part of the body of the put_line program. The section below is executed only when logging is turned on or overridden in that call to put_line . As you can see, the discussion of rollbacks and this section of code is relevant only when the log type is a database table. 1 IF log_type = PLV.dbtab 2 THEN 3 IF rolling_back 4 THEN 5 do_rb (v_message); 6 END IF; 7 8 put_to_db 9 (context_in, code_in, string_in, create_by_in, 10 SYSDATE); 11 12 IF rolling_back 13 THEN 14 PLVrb.set_savepoint (v_savepoint); 15 END IF; Lines 8 through 10 contain the call to a private module, put_to_db , that performs the actual INSERT into the specified table. This INSERT is sandwiched between two rollback-related activities. Lines 3 and 12 apply the rollback toggle discussed in the previous section; if you have not requested PLVlog.do_rollback , then rolling_back returns FALSE and the code on lines 5 and 14 are not executed. Suppose, however, that you have executed do_rollback . Then before a line of data is inserted into your log table, put_line executes the do_rb program, which is a local module in put_line that figures out exactly which type of rollback to execute. This topic is covered in Section 21.1.5.6, "Performing different kinds of rollbacks" . After the information is inserted into the log, PLVlog calls the PLVrb.set_savepoint to set a savepoint using dynamic PL/SQL . The savepoint used ( v_savepoint ) is the current PLVlog savepoint and is discussed in the next section. By setting a savepoint immediately after the insert, PLVlog gives you a way to roll back all changes except for the last write to the log table. This savepoint is either a savepoint declared by PLVlog or a savepoint you have defined for PLVlog to use, as is explained below. 21.1.5.3 Types of rollback activityPLVlog provides a set of constants, shown in the following table, that you can use to modify the way rollbacks occur in the put_line procedure. You have probably noticed that the values for the first three "savepoints" are not valid savepoint names. Only the constant c_PLVlogsp can actually be used in a SAVEPOINT command. In fact, the other constants are only used by the do_rb program in put_line to determine which kind of ROLLBACK action to take. The do_rb procedure is explored in more detail in Section 21.1.5.6 . 21.1.5.4 Setting the default "rollback to" behaviorThe default "rollback to" savepoint of PLVlog is used when the user has turned on rollback activity and the user has not provided an alternative savepoint in the call to put_line . This savepoint is then used to determine the type of rollback to execute before inserting a line into the log. The default savepoint is initialized to the c_none constant, which means that a full, unqualified rollback is executed. To change the default "rollback to" savepoint, you can call any of the programs whose headers are shown below: PROCEDURE rb_to (savepoint_in IN VARCHAR2 := c_none); PROCEDURE rb_to_last; PROCEDURE rb_to_default; The procedures rb_to_last and rb_to_default are simply special cases of the rb_to procedure. Let's look at the impact of using these programs with the different savepoint constants and, of course, your own savepoint names.
21.1.5.5 Specifying rollbacks when calling put_lineYou can also use the rollback constants when specifying a value for the rb_to_in argument of put_line . This acts as an override to the default "rollback to" savepoint. Since we've already looked at how put_line works, let's now explore how to use the rb_to_in argument with these constants to change the rollback behavior for a specific call to put_line . Here, again, is the header for put_line (the abbreviated version): PROCEDURE put_line (string_in IN VARCHAR2, rb_to_in IN VARCHAR2 := c_default, override_in IN BOOLEAN := FALSE); The default value for the "rollback to" argument is c_default , which means that PLVlog issues a rollback according to the current default setting (explained in the next section). The following examples show the alternatives to this behavior:
In all of the above examples, the rollback activity described applies only to that single call to PLVlog.put_line . Whenever you call put_line and do not provide a value for the rb_to_in argument, PLVlog relies on the default activity you have previously defined (explained below). 21.1.5.6 Performing different kinds of rollbacksPLVlog takes a different rollback action depending on the default savepoint value. This logic is encapsulated in the local do_rb procedure inside put_line : PROCEDURE do_rb (msg_in IN VARCHAR2) IS v_sp PLV.plsql_identifier%TYPE := v_rb_to; BEGIN IF rb_to_in != c_default THEN v_sp := rb_to_in; END IF; IF v_sp = c_noaction THEN NULL; ELSIF v_sp = c_none OR v_sp IS NULL THEN PLVrb.perform_rollback (msg_in); ELSIF v_sp = c_default THEN PLVrb.rollback_to (v_sp_PLVlog, msg_in); ELSIF v_sp = c_last THEN PLVrb.rb_to_last (msg_in); ELSE PLVrb.rollback_to (v_sp, msg_in); END IF; END; Allow me to translate:
Finally, for any other savepoint values, PLVlog requests that PLVrb roll back uncommitted changes to that savepoint string. 21.1.5.7 Setting the post-insert savepointAfter the insert to the database log has taken place, PLVlog issues a savepoint if PLVlog.rolling_back returns TRUE. The purpose of this savepoint is to preserve the new log record -- even if a rollback comes surging back from activity after the call to the PLVlog.put_line procedure. The post-insert savepoint of PLVlog (referred to for the rest of this section simply as "the savepoint") is initialized to the constant c_PLVlogsp , the predefined savepoint of the package. You can change this savepoint with a call to the set_sp procedure, whose header is: PROCEDURE set_sp (savepoint_in IN VARCHAR2); 21.1.6 Displaying the LogPLVlog provides a single display procedure to display the contents of the log, whether the log is stored in the database or in a PL/SQL table. If the log is in a database table, PLVlog makes use of the PLVdyn.intab procedure. If the log is in a PL/SQL table, PLVlog uses the PLVtab.display procedure. Here is the header for the display program: PROCEDURE display (header_in IN VARCHAR2 := 'PL/Vision Log'); The header, which is optional, is used in the PL/SQL table display, but not for the display of the database table. Here is an example of using the display procedure: set the log repository to the PL/SQL table, execute the application, and then display the log. SQL> execute PLVlog.to_pstab SQL> start myapp SQL> execute PLVlog.display Contents of PL/Vision Log proc1 ORA-01476: divisor is equal to zero 12/19/1995 11:41:30 proc2 ORA-06502: PL/SQL: num or val error 12/19/1995 11:41:30 You can also view the contents of the log with SQL if the log is a database table. In the following scenario, I set the log repository to the database table, execute the application, and then display the log. SQL> execute PLVlog.to_dbtab SQL> start myapp SQL> start inlog CONTEXT CODE TEXT CREATE_TS ------- ----- ------------------------------ ----------------- proc1 -1476 ORA-01476: divisor is equal to 12/19/95 114301 zero proc2 -6502 ORA-06502: PL/SQL: numeric or 12/19/95 114301 value error where the inlog.sql script is as follows: SET ARRAYSIZE 10 column code format 999999 column context format a12 column create_ts format a17 column text format a30 SELECT context, code, text, TO_CHAR (create_ts, 'mm/dd/yy hhmiss') create_ts FROM PLV_log ORDER BY create_ts; Notice that this script uses the default logging table, PLV_log . You can, as noted above, override this default with your own table and column names. Copyright (c) 2000 O'Reilly & Associates. All rights reserved. |
|