Deb has come to the conclusion that, when on a long car journey, I’m not a great passenger.
“Are we nearly there yet ?” I enquire politely…usually around five minutes into a four-hour journey.
“No, not yet”, comes the patient reply.
“Are we almost nearly there yet ?”
“No, I’ll let you know when we are”, she responds with iron patience.
A few minutes pass…
“Are we almost nearly almost there ?”
At this point, I’m usually offered the option of walking the rest of the way.
It’s the same with long-running programs on the database. I want to know how far it’s gone and how far it’s got to go.
Oh, what Deb would do for an in-car equivalent of DBMS_APPLICATION_INFO.
Deb would probably have some sympathy with the DBA who gets a call from a user who has a process running and is, essentially, asking “are we nearly there yet ?”
Fortunately, with a bit of foresight and the judicious application of a little DBMS_APPLICATION_INFO magic, the answer to this question is right there in V$SESSION, or even V$SESSION_LONGOPS.
How far have we got ?
DBMS_APPLICATION_INFO provides the facility to set values in the client_info, module and action columns of the V$SESSION view programatically.
If we have a job that’s performing a number of different operations sequentially, we could do something like this :
set serveroutput on size 1000000
DECLARE
l_module_name VARCHAR2(30) := 'task_progress.sql';
BEGIN
DBMS_APPLICATION_INFO.SET_CLIENT_INFO( client_info => q'[Mike's Test App]');
DBMS_APPLICATION_INFO.SET_MODULE(
module_name => l_module_name,
action_name => 'Getting to work...');
--
-- Pretend to do some work
--
DBMS_LOCK.SLEEP(10);
--
-- Update the progress
--
DBMS_APPLICATION_INFO.SET_ACTION('Time for a ciggie');
--
-- All work and no play...
--
DBMS_LOCK.SLEEP(10);
--
-- Is it that time already ?
--
DBMS_APPLICATION_INFO.SET_ACTION('Put the kettle on');
--
-- More hard labour
--
DBMS_LOCK.SLEEP(10);
--
-- Back to work
--
DBMS_APPLICATION_INFO.SET_ACTION('Home time !');
END;
/
To monitor this, we need to know which session to look for in V$SESSION and then check the progress in a separate session.
To find out which session we’re looking for, we need to know the audsid of the session we’re monitoring. So, before we kick off the program we need to :
SELECT userenv('sessionid') FROM dual;
This gives us the value of the audsid column in V$SESSION for the session we’re monitoring.
Once we’ve started execution of the program in the session, we then need to switch to the monitoring session and run :
SELECT client_info, module, action FROM v$session WHERE audsid = 1234 / CLIENT_INFO MODULE ACTION -------------------- -------------------- -------------------- Mike's Test App task_progress.sql Getting to work... SQL> / CLIENT_INFO MODULE ACTION -------------------- -------------------- -------------------- Mike's Test App task_progress.sql Time for a ciggie SQL> / CLIENT_INFO MODULE ACTION -------------------- -------------------- -------------------- Mike's Test App task_progress.sql Put the kettle on SQL> / CLIENT_INFO MODULE ACTION -------------------- -------------------- -------------------- Mike's Test App task_progress.sql Home time !
where 1234 is the output we got from userenv(‘sessionid’).
Are we nearly there yet ? – Number of records processed
If you’re processing records in a loop, you could use the loop iterator and the total number of iterations to provide progress information…
set serveroutput on size 1000000
DECLARE
l_module_name VARCHAR2(30) := 'app_info_rec.sql';
l_max PLS_INTEGER := 100000;
BEGIN
DBMS_APPLICATION_INFO.SET_CLIENT_INFO( client_info => q'[Mike's Test App]');
DBMS_APPLICATION_INFO.SET_MODULE(
module_name => l_module_name,
action_name => 'Getting to work...');
FOR i IN 1..l_max LOOP
IF MOD(i, 1000) = 0 THEN
DBMS_APPLICATION_INFO.SET_ACTION(action_name => 'Processed '||i||' of '||l_max||' records');
DBMS_LOCK.SLEEP(1);
END IF;
END LOOP;
--
-- Tidy up before we leave
--
DBMS_APPLICATION_INFO.SET_MODULE(
module_name => NULL,
action_name => NULL);
END;
/
If we switch to our monitoring session, we can see…
SELECT module, action FROM v$session WHERE audsid = 1234 / MODULE ACTION -------------------- ---------------------------------------- app_info_rec.sql Processed 43000 of 100000 record
Note to self – once you get over 10000 records processed on this example, the value we’re trying to set for action is too long for the column in V$SESSION. Fortunately, DBMS_SESSION simply truncates the ACTION value to 32 characters, hence the missing s at the end of records.
I think I’ve managed to talk my way out of that one.
Incidentally, the same applies to values you set for module ( 48 characters) and client_info (64). If ever you forget which is which, just do a describe on V$SESSION and note the length of the relevant columns.
Are we nearly there yet ? – The progress bar
Of course, if you just want details of what percentage of the total rows have been processed, you simply need to change the information you pass to the package
set serveroutput on size 1000000
DECLARE
l_module_name VARCHAR2(30) := 'app_info_test.sql';
l_max PLS_INTEGER := 100000;
l_pct_done PLS_INTEGER;
BEGIN
DBMS_APPLICATION_INFO.SET_CLIENT_INFO( client_info => q'[Mike's Test App]');
DBMS_APPLICATION_INFO.SET_MODULE(
module_name => l_module_name,
action_name => 'Getting to work...');
FOR i IN 1..l_max LOOP
IF MOD(i, 1000) = 0 THEN
l_pct_done := (i/l_max) * 100;
DBMS_APPLICATION_INFO.SET_ACTION(action_name => l_pct_done||' % complete');
DBMS_LOCK.SLEEP(1);
END IF;
END LOOP;
--
-- Tidy up before we leave
--
DBMS_APPLICATION_INFO.SET_MODULE(
module_name => NULL,
action_name => NULL);
END;
/
…and in the monitoring session…
SELECT module, action FROM v$session WHERE audsid = 1234 / MODULE ACTION -------------------- ---------------------------------------- app_info_test.sql 12 % complete
Are we almost nearly there yet?
OK, but what if you really, really want to know how much longer Oracle thinks this is going to take ?
Step forward SET_SESSION_LONGOPS. This will write the monitoring information to V$SESSION_LONGOPS and give you an estimate of the execution time remaining.
To demonstrate, here’s the source for an appropriately name procedure :
CREATE OR REPLACE PROCEDURE procrastinate_pr(
i_iterations PLS_INTEGER, i_wait_secs PLS_INTEGER,
o_msg OUT VARCHAR2)
AS
--
-- Variables for call to LONGOPS
--
l_rindex PLS_INTEGER := DBMS_APPLICATION_INFO.SET_SESSION_LONGOPS_NOHINT;
l_slno PLS_INTEGER;
l_obj PLS_INTEGER;
BEGIN
-- l_rindex := DBMS_APPLICATION_INFO.SET_SESSION_LONGOPS_NOHINT;
FOR i IN 1..i_iterations LOOP
IF MOD(i, 100) = 0 THEN
DBMS_LOCK.SLEEP(i_wait_secs);
DBMS_APPLICATION_INFO.SET_SESSION_LONGOPS(
rindex => l_rindex,
slno => l_slno,
op_name => 'Tea break',
target => l_obj,
context => 0,
sofar => i,
totalwork => i_iterations,
target_desc => 'PROCRASTINATE_PR',
units => 'rows processed');
END IF;
END LOOP;
o_msg := 'Procrastination is a thief of time...and so are a lot of other long words.';
END;
/
NOTE – V$SESSION_LONGOPS doesn’t hold the audsid, but it does hold the session sid and serial #. To get these you need to run :
SELECT sid, serial#
FROM v$session
WHERE audsid = USERENV('sessionid');
If we now call this procedure :
set serveroutput on size 1000000
DECLARE
--
-- Variables for call to PROCRASTINATE_PR
--
l_iterations PLS_INTEGER;
l_wait_secs PLS_INTEGER;
l_msg VARCHAR2(4000);
BEGIN
l_iterations := 1000;
l_wait_secs := 3;
procrastinate_pr(
i_iterations => l_iterations, i_wait_secs => l_wait_secs,
o_msg => l_msg);
--
-- We should see something in v$session_longops...
--
DBMS_OUTPUT.PUT_LINE(l_msg);
END;
/
Now in our monitoring session…
SELECT opname, target_desc, elapsed_seconds, time_remaining FROM v$session_longops WHERE sid = 25 AND serial# = 3 / OPNAME TARGET_DESC ELAPSED_SECONDS TIME_REMAINING -------------------- -------------------- --------------- -------------- Tea break PROCRASTINATE_PR 21 5 SQL> / OPNAME TARGET_DESC ELAPSED_SECONDS TIME_REMAINING -------------------- -------------------- --------------- -------------- Tea break PROCRASTINATE_PR 24 3
Obviously, you need to replace the sid and serial# values with those of the session you’re monitoring.
A point to note here – the estimated completion time is always going to be a “best guess”. In the same way that a golfer who has just completed the first 14 holes of a round in par cannot predict that they will play the next four holes in par, Oracle can only base it’s prediction on what has happened so far. The actual time it takes to complete the process will always depend on what else is happening on the database, and the server it’s running on….even if you cheat outrageously and use DBMS_LOCK.SLEEP.
We’re off on holiday next month. Flying across the Atlantic to Canada. Deb’s already started getting some things she claims we need for the trip, including for some reason, a gag. When I questioned this particular purchase, she simply said, archly, that it would help with the headaches she tends to get on long trips with me.
I’ve no idea what she’s on about…
