17 August, 2010

Trying to understand LAST_CALL_ET -- 2

In my previous post I showed how LAST_CALL_ET does not get reset by each invocation of a seperate SQL from a run of the DBMS_STATS.GATHER_SCHEMA_STATS procedure.

Here, I show that this is not restricted to Stored Procedures. I run an anonymous PLSQL block and monitor the session from another terminal.
First, this is the block that I run :

SQL> !cat run_anon_PLSQL_with_SQLs.sql
declare
loop_cntr number;
row_count number;

begin
row_count := 0;
for loop_cntr in 1 .. 100
loop
select count(*)
into row_count
from
(select count(*) from dba_objects union all select count(*) from dba_objects) ;
dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1);
end loop;
end;
/

23:23:06 SQL> @run_anon_PLSQL_with_SQLs
Counted : 2
.....
Counted : 2

PL/SQL procedure successfully completed.

23:25:27 SQL>


I then monitor it from another session. These are some of the snapshots :

SQL> !cat sess_sql_statement.sql
rem Display SQL statement being executed by a session

select to_char(sysdate,'DD-MON HH24:MI:SS') Collection_datestamp, x.last_call_et, x.status, x.sql_id,
y.sql_text
from v$session x, v$sqlarea y
where x.sql_address = y.address
and x.sql_hash_value = y.hash_value
and x.sid = &session_id
/

SQL>
SQL> @sess_sql_statement
Enter value for session_id: 145
old 6: and x.sid = &session_id
new 6: and x.sid = 145

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:23:22 9 ACTIVE 073f1t1h96dub
declare loop_cntr number; row_count number; begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects) ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;


SQL>

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:23:37 24 ACTIVE 710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:23:51 39 ACTIVE 073f1t1h96dub
declare loop_cntr number; row_count number; begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects) ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:03 51 ACTIVE 710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)


COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:28 75 ACTIVE 073f1t1h96dub
declare loop_cntr number; row_count number; begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects) ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:35 84 ACTIVE 710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:52 99 ACTIVE 710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:25:13 120 ACTIVE 073f1t1h96dub
declare loop_cntr number; row_count number; begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects) ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

COLLECTION_DATE LAST_CALL_ET STATUS SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:25:26 135 ACTIVE 073f1t1h96dub
declare loop_cntr number; row_count number; begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects) ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

SQL> select sid, status, last_call_et, sql_id from v$session where sid=145;

SID STATUS LAST_CALL_ET SQL_ID
---------- -------- ------------ -------------
145 INACTIVE 24

SQL> /

SQL> /

SID STATUS LAST_CALL_ET SQL_ID
---------- -------- ------------ -------------
145 INACTIVE 27

SQL>
Thus, as long as the session is in an ACTIVE state (i.e. running the anonymous PLSQL block), the LAST_CALL_ET is continously incremented and does not get reset -- whether by the SQL executed in the block or the call to DBMS_LOCK.SLEEP. You will also notice that the SQL_ID reported against the session alternates between the PLSQL block and the SQL that it executes.

Further evidence that there really were 100 executions of the SQL but 1 execution of the PLSQL block :

SQL> select sql_id, sql_fulltext, executions from v$sqlstats where sql_id in ('073f1t1h96dub','710604h01ux6c');

SQL_ID SQL_FULLTEXT EXECUTIONS
------------- -------------------------------------------------------------------------------- ----------
073f1t1h96dub declare 1
loop_cntr number;
row_count number;

begin
row_count := 0;
for loop_cntr in 1 .. 100
loop
select count(*)
into row_count
from
(select count(*) from dba_objects union all select count(*) from dba_objects) ;

dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1);
end loop;
end;

710604h01ux6c SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) 100
FROM DBA_OBJECTS)


SQL>
Therefore : When the session you are monitoring by LAST_CALL_ET is running PLSQL (whether an anonymous block or a stored procedure), be careful to check LAST_CALL_ET -- it may be the runtime of the PLSQL, not the individual SQL executions within the PLSQL. It does not get reset by each SQL execution.


In the next part I will show whether LAST_CALL_ET relates to FETCH calls.

.
.
.

1 comment:

mindblogger said...

so what you are trying to say here is,
in a PL/SQL block, there can be several DML and select queries being fire from a session who has fire that 1 PL/SQL block or procedure. so the last_call_et can be seen increase as long as it stay active. So can i say that value is the total time (how long it has been running, (elapsed time) since the session stared with the block?

and it is not about the total completion time the block used to complete right?

can i say that the total elapsed time during inactive state means the client (that session) have to do a commit to complete the execution?