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.

.
.
.