Instrumentation: DBMS_APPLICATION_INFO

Instrumentation has something that I have come to rely on fairly heavily. I believe I first read about it on asktom, but the one that really spurred me on was this post on instrumentation on his personal blog.

Initially, I couldn't really wrap my head around instrumentation. I don't know why it was so difficult; I had a similar problem with sessions when I first started my career. I look back now and it just seems so obvious.

Now that I am doing datawarehouse work, nothing is fast. Fast to me is now one hour to load 30 or 40 million records. No more split second queries for me.

We currently use no tools. It's straight PL/SQL. Instrumentation of the code is ideal. Actually, it's more instrumentation to aid monitoring. The tool most easily used is provided by Oracle in the DBMS_APPLICATION_INFO package.

There are three subprograms that I use most, SET_MODULE, SET_ACTION and most importantly SET_SESSION_LONGOPS. I hadn't started using it until this year, I mainly stuck to the first two. SET_SESSION_LONGOPS is now part of my procedure/function template I've created in JDeveloper.

What it allows you to do is set a row in the v$session_longops view (I know it's not actually putting the row in the view...it's the underlying table, but I digress). You can then monitor how your job is doing.

Here's an example:

dbms_application_info.set_session_longops
  ( rindex => g_index,
    slno => g_slno,
    op_name => 'GETTING MEMBER DATA',
    sofar => 0,
    totalwork => l_table.COUNT + 1,
    target_desc => 'GETTING MEMBER DATA' );

g_index and g_slno are global variables in the package. l_table is a PL/SQL TABLE OF VARCHAR2.

Now you can monitor the progress of your job in v$session_longops!

Here's the query I use:

SELECT 
  username,
  sid,
  serial#,
  TO_CHAR( start_time, 'MM/DD/YYYY HH24:MI:SS' ) start_ti,
  time_remaining rem,
  elapsed_seconds ela,
  ROUND( ( sofar / REPLACE( totalwork, 0, 1 ) ) * 100, 2 ) per,
  sofar,
  totalwork work,
  message,
  target_desc
FROM v$session_longops
WHERE start_time >= SYSDATE - 1 
ORDER BY start_time DESC

Now you too can sit for hours and watch your job move incrementally forward!

But seriously, it does help tremendously to know where a job is at. You can further use the SET_MODULE and SET_ACTION calls to see a specific point in the processing (inside a loop).

Here's the code in context:

PROCEDURE get_member_data
IS
  l_exists INTEGER;
  TYPE table_of_lobs IS TABLE OF VARCHAR2(3);
  l_table TABLE_OF_LOBS := TABLE_OF_LOBS( 'COM', 'ORG' );
  l_count INTEGER := 0;
BEGIN
  --check to see if there is enrollment data, if not, move on
  SELECT COUNT(*)
  INTO l_exists
  FROM members
  WHERE rownum < 2;
  
  IF l_exists = 1 THEN--data exists, truncate and reload
  
    g_index := dbms_application_info.set_session_longops_nohint;
      
    EXECUTE IMMEDIATE 'TRUNCATE TABLE member_stg';

    g_audit_key := p_audit.begin_load
                    ( p_targettable => 'MEMBER_STG',
                      p_loadsource => 'MEMBER_SOURCE',
                      p_loadstatus => 'PRE',
                      p_loadprogram => 'GET_MEMBER_DATA',
                      p_commenttext => 'INSERT' );

    dbms_application_info.set_session_longops
      ( rindex => g_index,
        slno => g_slno,
        op_name => 'GETTING MEMBERS',
        sofar => 0,
        totalwork => l_table.COUNT + 1,
        target_desc => 'GETTING MEMBERS' );

  FOR i IN 1..l_table.COUNT LOOP
    l_count := l_count + 1;

    INSERT INTO member_stg
    SELECT *
    FROM members;

    g_total_rows_affected := g_total_rows_affected + sql%rowcount;

    COMMIT;

    dbms_application_info.set_session_longops
      ( rindex => g_index,
        slno => g_slno,
        op_name => 'GETTING MEMBERS',
        sofar => l_count,
        totalwork => l_table.COUNT + 1,
        target_desc => 'GETTING MEMBERS' );
  
  END LOOP;

  p_audit.end_load
    ( p_auditkey => g_audit_key,
      p_loadstatus => 'SUC',
      p_rowsuccess => g_total_rows_affected );
  
  gather_table_stats
    ( p_tablename => 'MEMBER_STG',
      p_schemaname => 'MYHOME' );

  dbms_application_info.set_session_longops
    ( rindex => g_index,
      slno => g_slno,
      op_name => 'GETTING MEMBERS',
      sofar => l_count + 1,
      totalwork => l_table.COUNT + 1,
      target_desc => 'GETTING MEMBERS' );

  END IF;

EXCEPTION
  WHEN others THEN
    p_audit.failed_load
      ( p_auditkey => g_audit_key,
        p_comments => SQLCODE || ' ' || SQLERRM );
    RAISE;

END get_member_data;