debuggingThis is a featured page

1 Debugging using Messages

Here are some ways to save/display messages to debug your code.

1.A Write to the Alert Log

From Jonathan Lewis post on oracle-l list (and re-printed with his permission)
dbms_system.ksdwrt(1,'test') writes to alert log
dbms_system.ksdwrt(2,'test') writes to session's trace file
dbms_system.ksdwrt(3,'test') writes to both
see also
dbms_system.ksdddt - writes a date-time stamp
dbms_system.ksdind(N) - indents text using ":' characters
dbms_system.ksdfls - flushes the write to file 1.A.i Example J Executing as SYS
begin
dbms_system.ksdwrt(3,'________________');
dbms_system.ksdwrt(1,'Writing Alert.Log file') ;
dbms_system.ksdwrt(2,'Writing Trace File');
dbms_system.ksdwrt(3,'Writing Both Alert and trace file') ;
dbms_system.ksdddt; -- writes a date-time stamp
dbms_system.ksdind(11); -- indents text using ":' characters
dbms_system.ksdfls; -- flushes the write to file
dbms_system.ksdwrt(1,'Writing Alert.Log file') ;
dbms_system.ksdwrt(2,'Writing Trace File');
dbms_system.ksdwrt(3,'Writing Both Alert and trace file') ;
end;
/
In Trace File OUTPUT
*** 2004-11-01 13:15:49.315
________________
Writing Alert.Log file
Writing Both Alert and trace file
*** 2004-11-01 13:15:49.495
:::::::::::Writing Alert.Log file
Writing Both Alert and trace file
In Alertlog file OUTPUT
Mon Nov 01 13:16:46 2004
________________
Writing Trace File
Writing Both Alert and trace file
Writing Trace File
Writing Both Alert and trace file

1.B Displaying debug messages using DBMS_OUTPUT package J

Enables the display of messages from stored procedures, packages and triggers.

This is the most used way to debug using messages, if you want to see intermediate results, or display other error messages.

On Sql*Plus you must enable output with the following command SET SERVEROUTPUT,
to automatically display this messages.
1.B.i Basic DBMS_OUTPUT ExampleJ The most common usage is
create OR REPLACE procedure test
is
begin
FOR A IN 1..10 LOOP
dbms_output.put_line('vALUE IS '||A||' '||TO_CHAR(SYSTIMESTAMP,'DD-MON-
YYYY HH24:MI:SSxFF'));
END LOOP;
end;
/
EXEC TEST;
vALUE IS 1 21-FEB-2005 12:38:03.390000000
vALUE IS 2 21-FEB-2005 12:38:03.390000000
vALUE IS 3 21-FEB-2005 12:38:03.390000000
vALUE IS 4 21-FEB-2005 12:38:03.390000000
vALUE IS 5 21-FEB-2005 12:38:03.390000000
vALUE IS 6 21-FEB-2005 12:38:03.390000000
vALUE IS 7 21-FEB-2005 12:38:03.390000000
vALUE IS 8 21-FEB-2005 12:38:03.390000000
vALUE IS 9 21-FEB-2005 12:38:03.390000000
vALUE IS 10 21-FEB-2005 12:38:03.390000000
Procedimiento PL/SQL terminado con Úxito.
1.B.ii SET SERVEROUTPUTJ This command is important for this package, because enables and configures output of DBMS_OUTPUT messages in sql*plus.
SET SERVEROUT[PUT] {ON | OFF} [SIZE {n |
UNL[IMITED]}] [FOR[MAT] {WRA[PPED] | WOR[D_WRAPPED]
| TRU[NCATED]}]
OFF suppresses output.
SIZE bytes can be buffered, n cannot be less than 2000 or greater than 1,000,000
SIZE UNLIMITED (default).
WRAPPED wraps the server output within the line size specified by SET LINESIZE.
WORD_WRAPPED wraps the server output within the line size specified by SET LINESIZE to words.
TRUNCATED Truncates the server output within the line size specified by SET LINESIZE.
SQL*Plus left justifies each line, skipping all leading white spaces.

SQL> EXEC DBMS_OUTPUT.PUT_LINE('1234567890 1234567890');
1234567890 1234567890
SQL> set serveroutput on format truncated
SQL> EXEC DBMS_OUTPUT.PUT_LINE('1234567890 1234567890');
1234567890 1234567890
SQL> set linesize 5
SQL> EXEC DBMS_OUTPUT.PUT_LINE('1234567890 1234567890');
12345
SQL> set serveroutput on format word_wrapped
SQL> EXEC DBMS_OUTPUT.PUT_LINE('1234567890 1234567890');
12345
67890
12345
67890
SQL> set serveroutput on format wrapped
SQL> EXEC DBMS_OUTPUT.PUT_LINE('1234567890 1234567890');
12345
67890
1234
56789
0
1.B.iii DBMS_OUTPUT package J 1.B.iii.a DBMS_OUTPUT.NEW_LINE; puts an end-of-line marker. 1.B.iii.b DBMS_OUTPUT.PUT_LINE, DBMS_OUTPUT.PUT DBMS_OUTPUT.PUT _LINE( cMessage ), inserts a message and one end of line,
DBMS_OUTPUT.PUT the same than DBMS_OUTPUT.PUT_LINE, But without end of line, needa new line to display.
BEGIN
DBMS_OUTPUT.PUT('1');
DBMS_OUTPUT.PUT('2');
DBMS_OUTPUT.PUT_LINE('3');
DBMS_OUTPUT.PUT('4');
DBMS_OUTPUT.NEW_LINE;
DBMS_OUTPUT.PUT('5');
END;
/
123
4
5
1.B.iii.c DBMS_OUTPUT.DISABLE Disables calls to DBMS_OUTPUT packages functions, and purges the buffer of any remaining information.
EXEC DBMS_OUTPUT.DISABLE;
EXEC TEST; 1.B.iii.d DBMS_OUTPUT.ENABLE Enable after you use the disable function. (don't replace SERVEROUTPUT functionality on sql*plus)
EXEC DBMS_OUTPUT.ENABLE(1000000);
EXEC TEST;
vALUE IS 1
vALUE IS 2
vALUE IS 3
1.B.iii.e DBMS_OUTPUT.GET_LINE DBMS_OUTPUT.GET_LINE (line OUT VARCHAR2,status OUT INTEGER);
I'll suggest use GET_LINES instead.

This procedure retrieves a single line of buffered information.
GET_LINE(S) returns "lines" as delimited by "newlines". Every call to PUT_LINE or NEW_LINE generates a line that is returned by GET_LINE(S).
You repeat calls to GET_LINE until status comes back as nonzero. For better performance, you should use calls to GET_LINES Procedure which can return an array of lines.
The maximum length is 255 bytes.

Beware previous DBMS_OUTPUT.PUT_LINE messages will not be displayed

declare
cMessage varchar2(4000);
nStatus number;
begin
dbms_output.put_line('DBMS_OUTPUT.PUT_LINE BEFORE');
dbms_output.get_line(cMessage ,nStatus );
dbms_output.put_line('DBMS_OUTPUT.PUT_LINE AFTER');
end;
/
DBMS_OUTPUT.PUT_LINE AFTER

declare
cMessage varchar2(4000);
nStatus number :=1;
a number :=0;
begin
dbms_output.put_line('DBMS_OUTPUT.PUT_LINE BEFORE 1');
dbms_output.put_line('DBMS_OUTPUT.PUT_LINE BEFORE 2');
dbms_output.put_line('DBMS_OUTPUT.PUT_LINE BEFORE 3');
dbms_output.put_line('DBMS_OUTPUT.PUT_LINE BEFORE 4');
WHILE a<10 LOOP
a := a+1;
dbms_output.get_line(cMessage ,nStatus );
dbms_output.put_line(a||'-Message:'||cMessage||' Status:'||nStatus||chr(10) );
END LOOP;
end;
/
10-Message:9-Message:8-Message:7-Message:6-Message:5-Message:4-Message:3-Message
:2-Message:1-Message
:DBMS_OUTPUT.PUT_LINE BEFORE 1 Status:0
Status:0
Status:0
Status:0
Status:0
Status:0
Status:0
1.B.iii.f DBMS_OUTPUT.GET_LINESJ retrieves an array of lines from the buffer.
DBMS_OUTPUT.GET_LINES ( lines OUT CHARARR, numlines IN OUT INTEGER);
lines.- Returns an array of lines of buffered information.CHARARR is a table of VARCHAR2(255). The maximum length of each line in the array is 255 bytes.
numlines.- Number of lines you want to retrieve from the buffer.

DECLARE
tCHARARR DBMS_OUTPUT.CHARARR;
nLines NUMBER;
BEGIN
FOR i IN 1..10
LOOP
DBMS_OUTPUT.PUT_LINE ('Line: '||i);
END LOOP;
nLines := 100;
DBMS_OUTPUT.GET_LINES ( tCHARARR, nLines);

FOR I in 1..nLines
LOOP
BEGIN
DBMS_OUTPUT.PUT_LINE( '('||I||')' || NVL (tCHARARR(I),'nothing') );
EXCEPTION
WHEN OTHERS
THEN
DBMS_OUTPUT.PUT_LINE (I || ':' || sqlerrm );
END;
END LOOP;
EXCEPTION
WHEN OTHERS THEN
DBMS_OUTPUT.PUT_LINE ('Exception, status=' || nLines);
DBMS_OUTPUT.PUT_LINE (SQLERRM );
END;
/
(1)Line: 1
(2)Line: 2
(3)Line: 3
(4)Line: 4
(5)Line: 5
(6)Line: 6
(7)Line: 7
(8)Line: 8
(9)Line: 9
(10)Line: 10
Procedimiento PL/SQL terminado con Úxito.

1.C DBMS_APPLICATION_INFO package Registering long operationsJ

This has two uses to find what is doing a session
To inform other sessions what a session is actually doing, this is done setting values on memory views, you don’t need to commit to get other user session, can read that value. This values are too used for other purposes, for example on oracle tuning.
To register the status of a specific long operation, there you can register the total of work, and the current % you had done
This introduces a record for every new value on rindex parameter.
Here is an example, it first introduces the record, saying it is on 55% and after 10 seconds it ends in 100%.
On Session1 we execute
DECLARE
prindex PLS_INTEGER:= dbms_application_info.set_session_longops_nohint;
pSlno PLS_INTEGER := NULL;
BEGIN
dbms_application_info.set_session_longops
(rindex=>prindex,
slno=> pSlno,
op_name=>'long operation name',
target=>null, /*or any number useful as reference */
context=>null, /*or any number useful as reference */
sofar=>55, /* menas 50% done */
totalwork=>100, /* total 100% */
target_desc=>'daily run', /*any text description */
units=>'%');

DBMS_LOCK.SLEEP(10); --wait

dbms_application_info.set_session_longops
(rindex=>prindex,
slno=> pSlno,
op_name=>'long operation name ',
target=>null, /*or any number useful as reference */
context=>null, /*or any number useful as reference */
sofar=>100, /* menas 50% done */
totalwork=>100, /* total 100% */
target_desc=>'daily run', /*any text description */
units=>'%');
end;
/
On Session 2, we will verify the contents of v$session_longops
SELECT MESSAGE,START_TIME,LAST_UPDATE_TIME
FROM V$SESSION_LONGOPS
WHERE OPNAME='long operation name '
/
long operation name : daily run : 55 out of 100 % done
05/11/05 05/11/05
On Session 2, 10 seconds later.
SELECT MESSAGE,START_TIME,LAST_UPDATE_TIME
FROM V$SESSION_LONGOPS
WHERE OPNAME='long operation name '
/
long operation name : daily run : 100 out of 100 % done
05/11/05 05/11/05
This data will remain in that view until you restart your database.

Using the packages provided with this book, you can do the same in this way.
exec m.K_DEBUG.long_op_begin('long operation name ',null,null,55,100, 'daily run','%');
exec m.K_DEBUG.long_op_status( 100);

1.D Autonomous Transactions J

To debug, you can use autonomous transactions, this is a procedure you call from another procedure, and this procedure can execute a commit, without committing the data from the calling procedure, because the autonomous transactions has a different session.
You must be aware that this is only for debugging temporarily or exceptionally, New connections take several resources, and every autonomous transactions creates a new connection.
I had created two procedures on K_DEBUG to implement his use. Only two things you must keep in mind the PRAGMA AUTONOMOUS_TRANSACTION, and a commit or rollback at the end of the procedure.
The only required is the cComment, and optionally you can specify a flag to filter and the origin for the module you are calling from;
You have to check the script at the end of this book to fully understand it. 1.D.i To Table J PROCEDURE DEBUG_FILE( cComment VARCHAR2, cFlag VARCHAR2 DEFAULT NULL,
cOrigin VARCHAR2 DEFAULT NULL );
EXEC K_DEBUG.DEBUG_TABLE( ‘test’);
ROLLBACK;
SELECT COMMENTARY FROM M.T_DEBUG;
TEST
1.D.ii To File J PROCEDURE DEBUG_TABLE( cComment VARCHAR2, cFlag VARCHAR2 DEFAULT NULL,cOrigin VARCHAR2 DEFAULT NULL );
EXEC M.K_DEBUG.DEBUG_FILE( ‘test’);
ROLLBACK;
En el archivo se generará:
SID:137 Corr:102 DATE:08-NOV-2005 03:56:43,968000000 USER:CACHUN
COMENTARY:test Flag: Origin:


No user avatar
juancarlosreyesp
Latest page update: made by juancarlosreyesp , Sep 30 2008, 9:49 PM EDT (about this update About This Update juancarlosreyesp Edited by juancarlosreyesp

1417 words added

view changes

- complete history)
Keyword tags: None
More Info: links to this page
There are no threads for this page.  Be the first to start a new thread.