Skip to Main Content

Breadcrumb

May 4th

Question and Answer

Tom Kyte

Thanks for the question, Pradeep.

Asked: January 29, 2002 - 10:50 am UTC

Last updated: July 10, 2008 - 1:02 pm UTC

Version: 8.1.7

Viewed 10K+ times! This question is

You Asked

How do you interpret LAST_CALL_ET field from the v$session view? What is the significance of this number field?

Can I get the execution time by getting the difference between LOGON_TIME and SYSDATE?

How do I find the buffer_gets,logical reads for the individual sql statements? Beacuse the number in V$sqlarea shows for the whole session.

and Tom said...

last_call_et shows you how long the active session has been active. If you search this site for

last_call_et v$session

you'll find my showsql script which uses this value. the output might look like:

--------------------
OPS$TKYTE(51,42794) ospid = 13111 command = 3 program = sqlplus@aria (TNS V1-V3) dedicated server=13112
Tuesday 11:00 Tuesday 11:00 last et = 0
SELECT USERNAME || '(' || SID || ',' || SERIAL# || ') ospid
= ' || PROCESS || ' command = ' || COMMAND || ' program = '
|| PROGRAM USERNAME,TO_CHAR(LOGON_TIME,' Day HH24:MI') LOGON_T
IME,TO_CHAR(SYSDATE,' Day HH24:MI') CURRENT_TIME,SQL_ADDRESS,LAS
T_CALL_ET,SID,PADDR FROM V$SESSION WHERE STATUS = 'ACTIVE' A
ND RAWTOHEX(SQL_ADDRESS) != '00' AND USERNAME IS NOT NULL ORDE
R BY LAST_CALL_ET
--------------------
WEB$CBURGESS(23,5120) ospid = 13059 command = 0 program = httpd@aria (TNS V1-V3) dedicated server=13083
Tuesday 11:00 Tuesday 11:00 last et = 14
BEGIN
owa.init_cgi_env(:n__,:nm__,:v__);
END;
--------------------
OPS$ORA817(26,18701) ospid = 12933 command = 0 program = sqlplus@aria (TNS V1-V3) dedicated server=12947
Tuesday 11:00 Tuesday 11:00 last et = 38
SELECT DECODE(SA.GRANTEE#,1,'PUBLIC',U1.NAME) "GRANTEE",U2.NAME
"GRANTED_ROLE",DECODE(OPTION$,1,'YES','NO') "ADMIN_OPTION" FRO
M SYSAUTH$@ORACLE8.WORLD SA,DEFROLE$@ORACLE8.WORLD UD,USER$@ORAC
LE8.WORLD U1,USER$@ORACLE8.WORLD U2 WHERE SA.GRANTEE# = UD.USER
# (+) AND SA.PRIVILEGE# = UD.ROLE# (+) AND U1.USER# = SA.G
RANTEE# AND U2.USER# = SA.PRIVILEGE# MINUS SELECT DECODE(SA.GR
ANTEE#,1,'PUBLIC',U1.NAME) "GRANTEE",U2.NAME "GRANTED_ROLE",DECO
DE(OPTION$,1,'YES','NO') "ADMIN_OPTION" FROM SYSAUTH$ SA,DEFRO
LE$ UD,USER$ U1,USER$ U2 WHERE SA.GRANTEE# = UD.USER# (+) AN
D SA.PRIVILEGE# = UD.ROLE# (+) AND U1.USER# = SA.GRANTEE# AN
D U2.USER# = SA.PRIVILEGE#
--------------------
OPS$ORA817(30,38969) ospid = 12876 command = 0 program = sqlplus@aria (TNS V1-V3) dedicated server=12891
Tuesday 11:00 Tuesday 11:00 last et = 38
SELECT ID FROM WWV_CORNERS WHERE LEADER = :b1
ops$tkyte@ORA8I.WORLD>

so that shows that last query has been active for 38 seconds.



You can get the LOGGED IN time, which may or may not be the execution time, via that method. You can get CPU used by that session from v$sesstat.


You would use TKPROF and SQL_TRACE to get the buffer gets (which are logical reads) for individual statements (or set autotrace on in sqlplus)



Rating

  (13 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Additional possibility

Connor McDonald, January 29, 2002 - 6:12 pm UTC

LAST_CALL_ET appears to also reflect the last occurrence of when the STATUS changed. Thus is status is "INACTIVE", last_call_et will tell you approximately how long that session has been inactive (as well as the aforementioned active scenario)

Tom Kyte
January 30, 2002 - 7:17 am UTC

Yes, it is.

It is the time since the last call started and the time since the last call finished.

A reader, January 24, 2003 - 11:41 am UTC

Hi Tom,

Is Value in LAST_CALL_ET in Second?

Thanks,


Tom Kyte
January 24, 2003 - 12:54 pm UTC

yup

Last_Call_et for Background Processes

Vivek Sharma, April 02, 2003 - 7:30 am UTC

Hi Tom,

I was checking the last_call_et for all the active sessions when I noticed that the last_call_et for all the background processes (sid 1 to 7) are continuosly increasing and are very high. The output of the v$session for these processes is as under :

LAST_CALL_ET SQL_ADDR SID SERIAL# OSUSER
------------ -------- ---------- ---------- ---------------
787820 00 5 1 ora8
787820 8F7FA548 6 1 ora8
787820 8F7FBD30 7 1 ora8
787821 00 1 1 ora8
787821 00 2 1 ora8
787821 00 3 1 ora8
787821 00 4 1 ora8

If these are in seconds, does it mean that the processes (SMON, PMON) are not doing their work on regular interval.
Secondly when I checked the sql_text of sid 6 from v$salarea it shows

select f.file#, f.block#, f.ts#, f.length from fet$ f, ts$ t where t.ts#=f.ts# and t.dflextpct!=0

Can u pls explain this.

Thanks in advance.
Vivek Sharma



Tom Kyte
April 02, 2003 - 8:17 am UTC

backgrounds are always active.


ops$tkyte@ORA920> select (sysdate-startup_time)*24*60*60 from v$instance;

(SYSDATE-STARTUP_TIME)*24*60*60
-------------------------------
                         151888

<b>time in seconds the instance is up...</b>


ops$tkyte@ORA920> select last_call_et, program, status from v$session;

LAST_CALL_ET PROGRAM                                          STATUS
------------ ------------------------------------------------ --------
      151903 oracle@tkyte-pc (PMON)                           ACTIVE
      151903 oracle@tkyte-pc (DBW0)                           ACTIVE
      151903 oracle@tkyte-pc (LGWR)                           ACTIVE
      151903 oracle@tkyte-pc (CKPT)                           ACTIVE
      151903 oracle@tkyte-pc (SMON)                           ACTIVE
      151903 oracle@tkyte-pc (RECO)                           ACTIVE
      151903 oracle@tkyte-pc (CJQ0)                           ACTIVE
      151903 oracle@tkyte-pc (QMN0)                           ACTIVE
           0 sqlplus@tkyte-pc (TNS V1-V3)                     ACTIVE

9 rows selected.

<b>last call et is time in seconds that the backgrounds have been work -- roughly the same..</b>


They do their work on regular intervals but like this:


  loop forever
      do work
      goto sleep for some interval or until someone wakes me up
  end loop


So, just like if you submit a plsql block:


loop
   do work
   dbms_lock.sleep(60);
end loop;

it would always be active.


explain what?  that is just the last query it ran.  SMON was looking for dictionary managed tablespaces that might be in need of free space coalescing. 

Last_Call_et for Background Processes

Vivek Sharma, April 02, 2003 - 7:59 am UTC

Hi Tom,

I was checking the last_call_et for all the active sessions when I noticed that the last_call_et for all the background processes (sid 1 to 7) are continuosly increasing and are very high. The output of the v$session for these processes is as under :

LAST_CALL_ET SQL_ADDR SID SERIAL# OSUSER
------------ -------- ---------- ---------- ---------------
787820 00 5 1 ora8
787820 8F7FA548 6 1 ora8
787820 8F7FBD30 7 1 ora8
787821 00 1 1 ora8
787821 00 2 1 ora8
787821 00 3 1 ora8
787821 00 4 1 ora8

If these are in seconds, does it mean that the processes (SMON, PMON) are not doing their work on regular interval.
Secondly when I checked the sql_text of sid 6 from v$salarea it shows

select f.file#, f.block#, f.ts#, f.length from fet$ f, ts$ t where t.ts#=f.ts# and t.dflextpct!=0

Can u pls explain this.

Thanks in advance.
Vivek Sharma



Robert, April 02, 2003 - 12:28 pm UTC


What is this process doing ?

Goh Seong Hin, July 01, 2004 - 6:47 am UTC

Dear Tom,

   I notice that one of the process has been running for 5 hours and I run the following command to check what it is doing.

From v$session, the sid shows active and last_call_et = 24406. User is running the report (ar60run) and it is still running for 24406 secs.

       SID    SERIAL# PROGRAM                                          SQL_ADDR
---------- ---------- ------------------------------------------------ --------
TO_CH TO_CH LAST_CALL_ET D
----- ----- ------------ -
       180       7471 ar60run@oradatabase (TNS V1-V3)                  CC935D0C
11:09 17:55        24406 A  


I checked the v$sess_io, the consistent_gets increase from time to time. Meaning to say that this SID is retrieving data.


       SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES
---------- ---------- --------------- -------------- -------------
CONSISTENT_CHANGES
------------------
       180      81666       124599304       30339775             2
            246421


SQL> /

       SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES
---------- ---------- --------------- -------------- -------------
CONSISTENT_CHANGES
------------------
       180      81670       124610129       30345473             2
            246421
                         


However, when I checked the v$sql, the buffer_gets and disk_reads field DOESN'T INCREASE for few minutes but the v$sess_io is keep on increasing. ok. move next to find out what is in v$session_wait

BUFFER_GETS DISK_READS EXECUTIONS
----------- ---------- ----------
SELECT  wnd.name DO_NO1,  wnd.name DO_NO2, TRUNC(wnd.confirm_date) DO_DATE1, ooh
.order_number ORDER_NO1, ool.line_id, ROUND((NVL(ool.unit_selling_price,0) * NVL
(ool.shipped_quantity,0)), 2) sales_total, jrs.name SALESREP1 FROM  oe_order_hea
ders_all ooh, oe_order_lines_all ool, wsh_new_deliveries wnd, wsh_dlvy_deliverab
les_v wddv, jtf_rs_salesreps jrs    WHERE ooh.header_id = wddv.source_header_id
AND ooh.header_id = ool.header_id AND wddv.source_line_id = ool.line_id AND ool.
org_id = 1 AND ooh.org_id = wddv.organization_id AND wddv.delivery_id = wnd.deli
very_id AND jrs.salesrep_id = ooh.salesrep_id AND jrs.org_id = ooh.org_id and oo
h.order_number not like '3%' AND TRUNC ( wnd.confirm_date ) BETWEEN : P_DO_DATE_

SQL_TEXT
--------------------------------------------------------------------------------
BUFFER_GETS DISK_READS EXECUTIONS
----------- ---------- ----------
FROM AND : P_DO_DATE_TO AND NOT EXISTS ( SELECT DISTINCT a.interface_line_attrib
ute1 FROM ra_customer_trx_lines_all a WHERE a.interface_line_attribute1 = SUBSTR
 ( ooh.order_number , 1 , 30 ) AND a.interface_line_attribute3 = SUBSTR ( wnd.na
me , 1 , 30 ) ) GROUP BY wnd.name , TRU
   20015209    1331820          2   

It is doing 'db file sequential read' in v$session_wait with WAITED SHORT TIME at state. This is one of the table in data file but when I try to look for the actual row it try to select.

select owner, segment_name, segment_type, tablespace_name
   from dba_extents
   where file_id = 300
  and 12657 between block_id and block_id + 8 -1;
  
no rows found.  

I check the v$sess_io again and it is still increasing. What is actually going on to this process ? Can you assist me in identifying what is this process doing and find out the root cause of the long running process. (I coudn't even find any thing running in v$session_longops). Thanks.

RGds
SHGoh
 

Tom Kyte
July 01, 2004 - 11:10 am UTC

it is running that query and the stats are getting updated at different times is all. nothing mysterious here.

v$session_longops tracks long running "things". this query is doing sequential reads -- which are very very very very short things.

this looks like a query that is abusing indexes, doing lots of logical io's via indexes when a nice juicy full scan would be more appropriate.

why v$sql.buffer_gets is so low

DRODRI, August 20, 2004 - 4:53 am UTC

Hi

I have a heavy job running (dbms_job) and stucks in a query however if I see the buffer_gets of that SQL the value is so low... If I query v$sess_io I see the real I/O

SQL> select * from v$sess_io where sid = 16;

       SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES CONSISTENT_CHANGES
---------- ---------- --------------- -------------- ------------- ------------------
        16        191        23166825        1582847         16535            1692997

SQL> r
  1* select * from v$sess_io where sid = 16

       SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES CONSISTENT_CHANGES
---------- ---------- --------------- -------------- ------------- ------------------
        16        191        23170886        1582985         16535            1693003


If I query v$sql


SQL> select sql_text, buffer_gets
  2  from v$session a, v$sql b
  3  where a.sql_Address = b.address
  4  and a.sql_hash_Value = b.hash_Value
  5  and a.sid = 16;

SQL_TEXT                                                         BUFFER_GETS
---------------------------------------------------------------- -----------
SELECT ISH_CONPRE TDE_CONPRE,ISH_FECINV TDE_FECINV,ISH_REFSER TD         887
E_REFSER,ISH_TIPSER TDE_TIPSER,ISH_THAGEN TDE_MODGEN,ISH_CHAGEN
TDE_CHAGEN,ISH_CODEMP TDE_CODEMP,ISH_CODEMPPROREC TDE_CODEMPPROR
EC,ISH_CODREC TDE_CODREC,ISH_TIPCON TDE_TIPCON,ISH_RESCON TDE_RE
SCON,ISH_RESPEN TDE_RESPEN,DSR_CODTHA TDE_MODDET,DSR_CODCHA TDE_
CODCHA,DECODE(DSR_TURDSR,'R','PENDIENTE','O','PENDIENTE','CONFIR
MADO') TURNO,SUM(DSR_NUMUNI) UNIDADES   FROM SISTEMAS_RESERVA_DS
R,DETALLES_SERVICIO_RESERVADO,INVENTARIOS_SERVICIO_HOTEL  WHERE
SRD_LOCATA = DSR_LOCATA  AND SRD_ITMDSR = DSR_SEQITM  AND SRD_RE
FSER = DSR_REFSER  AND SRD_ITMSRE = DSR_ITMSRE  AND SRD_TIPSER =
 DSR_TIPSER  AND SRD_CODEMP = DSR_CODEMP  AND DSR_CONPRE = ISH_C
ONPRE  AND DSR_FECINI <= ISH_FECINV  AND (DSR_FECFIN - 1 ) >= IS
H_FECINV  AND DSR_REFSER = ISH_REFSER  AND DSR_TIPSER = ISH_TIPS
ER  AND DSR_MODGEN = ISH_THAGEN  AND DSR_CHAGEN = ISH_CHAGEN  AN
D DSR_CODEMPPROMAY = ISH_CODEMP  AND DSR_CODEMPPROREC = ISH_CODE
MPPROREC  AND DSR_CODREC = ISH_CODREC


SQL> select sql_text, buffer_gets
  2  from v$session a, v$sql b
  3  where a.sql_Address = b.address
  4  and a.sql_hash_Value = b.hash_Value
  5  and a.sid = 16;

SQL_TEXT                                                         BUFFER_GETS
---------------------------------------------------------------- -----------
SELECT ISH_CONPRE TDE_CONPRE,ISH_FECINV TDE_FECINV,ISH_REFSER TD         887
E_REFSER,ISH_TIPSER TDE_TIPSER,ISH_THAGEN TDE_MODGEN,ISH_CHAGEN
TDE_CHAGEN,ISH_CODEMP TDE_CODEMP,ISH_CODEMPPROREC TDE_CODEMPPROR
EC,ISH_CODREC TDE_CODREC,ISH_TIPCON TDE_TIPCON,ISH_RESCON TDE_RE
SCON,ISH_RESPEN TDE_RESPEN,DSR_CODTHA TDE_MODDET,DSR_CODCHA TDE_
CODCHA,DECODE(DSR_TURDSR,'R','PENDIENTE','O','PENDIENTE','CONFIR
MADO') TURNO,SUM(DSR_NUMUNI) UNIDADES   FROM SISTEMAS_RESERVA_DS
R,DETALLES_SERVICIO_RESERVADO,INVENTARIOS_SERVICIO_HOTEL  WHERE
SRD_LOCATA = DSR_LOCATA  AND SRD_ITMDSR = DSR_SEQITM  AND SRD_RE
FSER = DSR_REFSER  AND SRD_ITMSRE = DSR_ITMSRE  AND SRD_TIPSER =
 DSR_TIPSER  AND SRD_CODEMP = DSR_CODEMP  AND DSR_CONPRE = ISH_C
ONPRE  AND DSR_FECINI <= ISH_FECINV  AND (DSR_FECFIN - 1 ) >= IS
H_FECINV  AND DSR_REFSER = ISH_REFSER  AND DSR_TIPSER = ISH_TIPS
ER  AND DSR_MODGEN = ISH_THAGEN  AND DSR_CHAGEN = ISH_CHAGEN  AN
D DSR_CODEMPPROMAY = ISH_CODEMP  AND DSR_CODEMPPROREC = ISH_CODE
MPPROREC  AND DSR_CODREC = ISH_CODREC


I dont understand why v$sql does not get updated?¿ 

Tom Kyte
August 20, 2004 - 11:13 am UTC

the v$ views get updated on different cycles - some constantly (like session statistics ) some at the end of a call.

In fact - some statistics -- like CPU time are not updated until the end of a call either (you won't see the cpu time for this session going up.

Please clarify

Andrey, February 11, 2005 - 6:27 am UTC

Dear Tom!
Please clarify for me, what does it mean "end of the call"
I measured "CPU used by this session" and "recursive cpu" in sessions started from dbms_job. It always shows 0. In usual sessions, if i take snap from v$mystat after and before doing something, it works well, but in jobs it not.
In dbms_job package makes never ending calls?

Tom Kyte
February 11, 2005 - 8:19 pm UTC

in jobs -- the call IS the job, no cpu reported until after the "call" completes - the job.

so, if you try to capture the cpu in the job, you will get "0"

Idle connections not flushed

Mariano, November 24, 2005 - 2:54 pm UTC

Tom,
I'm checking some web pages in PHP that use ref cursors to retrieve a result set. The pages are done but I see that new connections are always added everytime someone executes the process. This is ok because it must be set on the PHP side.

However, after a while when no one is using the system in the v$session all sessions remain inactive and they do not disappear.
My question: is there any parameter on Oracle's side we must set in order to clean away this idle connections?

Best regards

Tom Kyte
November 24, 2005 - 5:18 pm UTC

that is entirely under the control of the middle tier software, that middle tier must ask "please disconnect me", it would be considered "rude" if we did it for them :)

Great info on last_call_et - does it relate to an idle_time profile setting?

FredJMuggs, November 26, 2005 - 2:31 pm UTC

A session's idle time can be limited with a profile setting.
Is the last_call_et used to figure idle_time?

Tom Kyte
November 26, 2005 - 4:40 pm UTC

not sure if they use that directly - but it would equate to the same number - when the status = inactive or none, and last_call_et exceeds your idle time, you would be subject to sniping.

Buffer Gets

Giri, November 27, 2005 - 2:19 am UTC

What exactly does the value Buffer_gets in v$sql mean?

Tom Kyte
November 27, 2005 - 9:57 am UTC

number of times a buffer was gotten from the buffer cache in response to executing that query.

What does command=0 in v$session mean?

reader, December 08, 2005 - 11:58 am UTC


Can last_call_et increment faster than clock?

A reader, July 10, 2008 - 12:55 pm UTC

Tom,
I recently saw something which I cannot explain. I opened a SQL*Plus session from a client to database server and conneted as user ABC. I did select sysdate from dual; in the SQL*Plus window and left it like that.

Now from my desktop I started monitoring the SQL*Plus session using the query:

select
inst_id, sid,username,status,schemaname,
machine,terminal,program,
logon_time,last_call_et,service_name,
server
from gv$session where username='ABC';

I am using gv$session since it is a RAC database. I observed that everything else was alright except that the last_call_et counter was incrementing about twice as fast as the wall clock. In 10 minutes, the last_call_et had gone to about 1200, in half hour it was close to 3600 and so on.

I cannot reproduce this now but it did happen once. Was I dreaming or is there an explanation? Oracle 10.2.0.3.

Thanks...
Tom Kyte
July 10, 2008 - 1:02 pm UTC

sounds dream like - if it happened, it would have been "wrong" (eg: a bug)