26.5 Quick-and-Dirty Tracing

I have found that in many situations, PL/SQL developers don't have the time or the access to tools to perform comprehensive tracing. Instead, they just need to get more information out of a specific package or program, and they need it right away.

Let's take a look at the options you have for some "quick-and-dirty" tracing. First of all, there is DBMS_OUTPUT.PUT_LINE, a built-in which generates output from within a PL/SQL program. For example, if I executed in SQL*Plus the following block:

BEGIN
   FOR emp_rec IN
      (SELECT ename, sal FROM emp ORDER BY sal DESC)
   LOOP
      DBMS_OUTPUT.PUT_LINE
         ('Employee ' || emp_rec.ename || ' earns ' ||
          TO_CHAR (emp_rec.sal) || ' dollars.');
   END LOOP;
END;
/

I would see the following output when the program terminated:

Employee KING earns 5000 dollars.
Employee SCOTT earns 3000 dollars.
Employee JONES earns 2975 dollars.
Employee ADAMS earns 1100 dollars.
Employee JAMES earns 950 dollars.

You will only see trace information from DBMS_OUTPUT in SQL*Plus if you issue the following command:

SQL> set serveroutput on

This will enable the package within SQL*Plus. You can also set the buffer which contains trace information to its maximum size of 1MB as follows:

SQL> set serveroutput on size 1000000

Finally, if you are running Oracle Server 7.3 and above, you can also request that output from DBMS_OUTPUT.PUT_LINE be "wrapped" so that leading blanks are not trimmed and long lines are wrapped within the SQL*Plus linesize:

SQL> set serveroutput on size 1000000 format wrapped

So DBMS_OUTPUT does give you the flexibility of embedding trace calls inside your program, but only seeing the output when you have SET SERVEROUTPUT ON. It is, unfortunately, an all-or-nothing proposition with this package. You see no messages or you see all messages. Using DBMS_OUTPUT.PUT_LINE "in the raw" as a trace mechanism therefore leaves much to be desired. (Well, to be honest, when talking about the inadequacies of DBMS_OUTPUT, one would also have to mention that it can only display a maximum of 255 bytes per call, that it does not display Booleans or combinations of data, and that it will not work in the Oracle Developer/2000 environment nor in Oracle WebServer.)[2]

[2] See Chapter 7 of my book on packages, Advanced Oracle PL/SQL Programming with Packages, for details about the usage of DBMS_OUTPUT.PUT_LINE.

Ideally, you would like to be able to set up a trace mechanism so that you can see information about only this package or that procedure. The best way to do that is to set up a "toggle" within a package. Let's step through a simple example to make the technique clear.

Suppose I have a package which assigns a value to a package variable (which must be defined in the package specification) using dynamic SQL execution. (This is similar to the indirect referencing available in Oracle Forms with COPY and NAME_IN.) The specification and body of such a package is shown below:

/* filename on companion disk: dynvar.spp */
CREATE OR REPLACE PACKAGE dynvar
IS
   PROCEDURE assign (var_in IN VARCHAR2, val_in IN VARCHAR2);
   FUNCTION val (var_in IN VARCHAR2) RETURN VARCHAR2;
END dynvar;
/
CREATE OR REPLACE PACKAGE BODY dynvar
IS
   PROCEDURE assign (var_in IN VARCHAR2, val_in IN VARCHAR2)
   IS
      cur INTEGER;
      fdbk INTEGER;
   BEGIN
      cur := DBMS_SQL.OPEN_CURSOR;
      DBMS_SQL.PARSE (cur,
         'BEGIN ' || var_in || ' := :val; END;', DBMS_SQL.NATIVE);
      DBMS_SQL.BIND_VARIABLE (cur, 'val', val_in, 2000);
      fdbk := DBMS_SQL.EXECUTE (cur);
      DBMS_SQL.CLOSE_CURSOR (cur);
   END;

   FUNCTION val (var_in IN VARCHAR2) RETURN VARCHAR2
   IS
      cur INTEGER;
      fdbk INTEGER;
      retval VARCHAR2(2000);
   BEGIN
      cur := DBMS_SQL.OPEN_CURSOR;
      DBMS_SQL.PARSE
         (cur, 'BEGIN :val := ' || var_in || '; END;', DBMS_SQL.NATIVE);
      DBMS_SQL.BIND_VARIABLE (cur, 'val', var_in, 2000);
      fdbk := DBMS_SQL.EXECUTE (cur);
      DBMS_SQL.VARIABLE_VALUE (cur, 'val', retval);
      DBMS_SQL.CLOSE_CURSOR (cur);
      RETURN retval;
   END;

END dynvar;
/

Here is a little test package and some program calls in SQL*Plus to give you a sense of how it would work:

CREATE OR REPLACE PACKAGE TSTVAR
IS
    str1 varchar2(2000);
    str2 varchar2(2000);
END;
/

SQL> exec dynvar.assign ('tstvar.str1', 'abc')

SQL> exec dbms_output.put_line (tstvar.str1)
abc

SQL> exec dbms_output.put_line (dynvar.val ('tstvar.str1'))
abc

This package seems to work just fine. When working with dynamic SQL and PL/SQL, however, the trickiest aspect of the package might not be building it, but using it. The user of dynvar must construct the package variable's name properly and if she gets it wrong, she will get all sorts of interesting but confusing errors. Let's add a trace feature to dynvar so that when a user has trouble, she can very selectively activate trace just for this package and the dynamic management of package globals.

First, I will add my toggle to the package specification:

CREATE OR REPLACE PACKAGE dynvar
IS
   PROCEDURE assign (var_in IN VARCHAR2, val_in IN VARCHAR2);
   FUNCTION val (var_in IN VARCHAR2) RETURN VARCHAR2;

   PROCEDURE trc;
   PROCEDURE notrc;
   FUNCTION tracing RETURN BOOLEAN;

END dynvar;
/

I turn on trace for this package with the following command:

SQL> exec dynvar.trc

Similarly, I can turn off trace with this command:

SQL> exec dynvar.notrc

The implementation of this toggle in the package body is very straightforward:

CREATE OR REPLACE PACKAGE BODY dynvar
IS
   g_trc BOOLEAN := FALSE;
   PROCEDURE trc IS BEGIN g_trc := TRUE; END;
   PROCEDURE notrc IS BEGIN g_trc := FALSE; END;
   FUNCTION tracing RETURN BOOLEAN IS BEGIN RETURN g_trc; END;

   . . .
END dynvar;

I establish a private global variable to hold the trace setting (default is "off"). When you call dynvar.trc, the variable is set to TRUE or "on." Now the question is this: how do I put this toggle to use inside the assign and val programs? Right after the BEGIN statement in each program, I will add a conditional clause. If tracing is turned on, then I display a message:

CREATE OR REPLACE PACKAGE BODY dynvar
IS
   PROCEDURE assign (var_in IN VARCHAR2, val_in IN VARCHAR2)
   IS
      cur INTEGER;
      fdbk INTEGER;
   BEGIN
      IF tracing
      THEN
         DBMS_OUTPUT.PUT_LINE
            ('dynvar assigning ' || val_in || ' to ' || var_in);
      END IF;

      /* same dynamic PL/SQL as before */
   END;

   FUNCTION val (var_in IN VARCHAR2) RETURN VARCHAR2
   IS
      /* same declarations as before */
   BEGIN
      IF debuging
      THEN
         DBMS_OUTPUT.PUT_LINE ('dynvar retrieving value of ' || var_in);
      END IF;

      /* same dynamic PL/SQL as before */
   END;

END dynvar;
/

With this new version of the dynvar package installed, I can then turn on trace and get feedback each time either of the package's programs are executed:

SQL> set serveroutput on
SQL> exec dynvar.trc

SQL> exec dynvar.assign ('tstvar.str1', 'abc')
dynvar assigning abc to tstvar.str1

SQL> exec p.l(dynvar.val ('tstvar.str1'))
dynvar retrieving value of tstvar.str1
abc

Of course in the "real world," you will want to enhance the information displayed with the context in which these programs were called (perhaps a date-time stamp and so forth). This should, however, give you a flavor of the basic technique and how to employ it.

NOTE: Intrigued by dynvar? You will find more information about dynamic PL/SQL in Oracle Built-in Packages. You can also overload the dynvar package to perform assignments and retrievals for dates, numbers, and so on in their native formats.