Wednesday, March 05, 2014

Simulate tail -f logger_logs table - instrument PL/SQL

debugf used to be the instrumentation tool on my kit before.

At November 7, 2013, Tom Kyte said: "debug.f is really really really old :) . I recommend Logger to do PL/SQL instrumentation."

To install and use logger 2.0, please see https://github.com/tmuth/Logger---A-PL-SQL-Logging-Utility

There are 2 good debugf features that Logger 2.0 doesn't have.

1. tail -f debug_trace_file.
2. debug.f("%s %s", l_a, l_b); -- similar to C printf format string.

Today I will show you how to simulate "tail -f" on logger_logs table.

Call example

SQL> 

set linesize 120

select * from table(u$log.log_tail);

--Test, open another session.

SQL>

begin
 for i in 1..15
 loop
   logger.log(i||' : '||rpad('.',i,'.'));
   dbms_lock.sleep(1);
 end loop;
end;
/

To exit, press Ctrl + C.

Setup and installation.

--DDL

connect sys

grant execute on dbms_lock to utility;

create or replace view utility.logger_tail_v
as
select 
  TIME_STAMP||'.'||
  SCOPE||'.'||
  MODULE||'.'||
  ACTION||'.'||
  USER_NAME||'.'||
  TEXT||':'||
  CLIENT_IDENTIFIER||
--  CALL_STACK||
  UNIT_NAME||
  LINE_NO||
  SCN||
  EXTRA log_text, id
from logger_logs;

@u$log.sql

alter package utility.u$log compile;
grant execute on utility.u$log to public;
create or replace public synonym u$log for utility.u$log;


-- Create Package u$log.  file u$log.sql


CREATE OR REPLACE PACKAGE u$log AS

/***
tail -f logger_logs;
***/

  cursor gc_log_src is
  select log_text,id  from logger_tail_v;

  TYPE log_src_tab IS TABLE OF gc_log_src%ROWTYPE;
  FUNCTION log_tail return log_src_tab PIPELINED DETERMINISTIC;

END;
/


CREATE OR REPLACE PACKAGE BODY                 u$log
/***
Goal: 1. tail -f logger_logs table,

Who| Date         | What
Charlie(Yi) | 12-June-2008 | Create the package.

alter package utility.u$log compile;
grant execute on utility.u$log to public;
create or replace public synonym u$log for utility.u$log;

***/
/*
| Copyright Information Here
|
| File name:
|
| Overview:
|
| Author(s):
|
| Modification History:
|  Date        Who          What
| 23-Dec-2013: Charlie(Yi): Instrument with Logger, to replace debugf,
| 08-Nov-2010: Charlie(Yi): Create the function.


It meets user requirements
It is maintainable
It runs fast enough to minimize user frustration

!!! Pl/SQL development workflow, Four steps of preparing an application !!!

 - Validate program requirements
  # ask lots of questions
  # what users ask for is not always the easiest way to solve a problem
  # consider other approaches, include business processes and programming algorithms
 - Implement header of the program
  # good name for the program, accurately represent the purpose of the program
  # inputs and outputs
  # overload sub-procedure ?
 - Define the test cases
  # Verify it works
  # how will I know when I am done with this program
 - Build test code

Reference:
  http://jira/jira/
|
|
*/
IS
 gs_module varchar2(30);

 PROCEDURE initialize_pkg
 IS
 BEGIN
   gs_module := 'package_name';
   --gc_scope_prefix constant VARCHAR2(31) := lower($$PLSQL_UNIT) || '.';
   gs_module := lower($$PLSQL_UNIT);
   DBMS_APPLICATION_INFO.SET_MODULE( gs_module,'init' );
 END initialize_pkg;

 PROCEDURE commit_tx
 IS
 BEGIN
    logger.log('soft commit');
    --rollback;
    commit;
 END commit_tx;

 FUNCTION log_tail
   return log_src_tab PIPELINED DETERMINISTIC
 /*
 | Copyright Information Here
 |
 | File name:
 |
 | Overview: simulate tail -f on logger_log table.
 |

Call example:

select * from table(u$log.log_tail);

select text,id from table(u$log.log_tail);

 |
 | Author(s): Charlie Yi Zhu 木匠.
 |
 | Modification History:
 Date         Who          What
 04-Mar-2014: Charlie(Yi): Create the table function.

 */
 IS
  -- PRAGMA AUTONOMOUS_TRANSACTION;

  l_scope logger_logs.scope%type;
  l_params logger.tab_param;
  ls_action varchar2(30);
  l_cnt simple_integer := 0;
  l_row_cnt pls_integer;
  l_piece simple_integer := 0;
  l_chunk simple_integer := 10000;
  l_max_id number; l_int_id number;

  PROCEDURE initialize
  IS
  BEGIN
    ls_action := 'log_tail';
    l_scope := gs_module ||'.'|| ls_action;
    DBMS_APPLICATION_INFO.SET_module(gs_module, ls_action);
    DBMS_APPLICATION_INFO.set_client_info( gs_module||'.'||ls_action );
    l_row_cnt := 0;
    logger.log('START', l_scope);
  END initialize;

  PROCEDURE cleanup
  IS
  BEGIN
     DBMS_APPLICATION_INFO.SET_MODULE(gs_module,Null);
     DBMS_APPLICATION_INFO.set_client_info( ' ' );
     logger.log('END', l_scope);
  END cleanup;

 BEGIN
  initialize;
  /*
  Main body of program
  */

  logger.append_param(l_params, 'l_cnt', l_cnt);
  logger.log('xxxxx', l_scope, null, l_params);

  select Nvl(Max(id),0) into l_max_id from logger_logs;
  logger.log('Start id: '||l_max_id, l_scope, null, l_params);

  Loop
   FOR lc_stage IN (
    select --+ index_asc(a logger_logs_pk)
     log_text, id
    from logger_tail_v a
    where id > l_max_id
    order by id ASC
   )
   LOOP
    l_int_id := lc_stage.id;
    pipe ROW(lc_stage);
   END LOOP;
   --logger.log('Last max id: '||l_int_id, l_scope, null, l_params);
   dbms_lock.sleep(1);
   l_max_id := l_int_id;
  End Loop;

  logger.log(l_row_cnt||' rows returned', l_scope, null, l_params);

   cleanup;
   RETURN;

 EXCEPTION
  when NO_DATA_NEEDED then
      cleanup;
      return;
  WHEN OTHERS
  THEN
     /* Don't forget to clean up here, too! */
     cleanup;

     /* Standard error logging mechanism */
     logger.log_error('Unhandled Exception', l_scope, null, l_params);
     --RollBack;
     raise;
 END log_tail;

BEGIN
  initialize_pkg;
END;
/

No comments: