Skip to Main Content
  • Questions
  • query to find all sqlstatements taking more then a certain amount of time

Breadcrumb

Question and Answer

Chris Saxon

Thanks for the question, sunil.

Asked: August 17, 2001 - 2:40 pm UTC

Last updated: February 18, 2010 - 7:41 pm UTC

Version: 8.1.6.0

Viewed 10K+ times! This question is

You Asked

Hi,

I would like the following Information as output from the query

SID,
SERIAL#,
USERNAME,
STARTTIME,
SQLSTATEMENT the client is executing

for all queries that are taking more then a certain amount of time
(say around 5 Minute) to execute.

For queries taking more then 5Minutes , i want the SqlStatement and other details like who is executing this statement, and what time the query started .

Sunil Nettyam

and Tom said...

try this:

ops$tkyte@ORA8I.WORLD> column dur format a20
ops$tkyte@ORA8I.WORLD> select sid, serial#, username, to_char(sysdate-last_call_et/24/60/60,'hh24:mi:ss') started,
2 trunc(last_call_et/60) || ' mins, ' || mod(last_call_et,60) ||
' secs' dur,
3 (select sql_text from v$sql where address = sql_address ) sql_text
4 from v$session
5 where username is not null
6 and last_call_et > 5*60
7 and status = 'ACTIVE'
8 /


Rating

  (12 ratings)

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

Comments

Time Consuming Queries

Sunil B Nettyam, August 17, 2001 - 6:10 pm UTC

Hi,

Some time in our database some of the querise just hang. They stay there even after a long time. These consume lots of system Resources.
With the help of the query you gave now we are able to identify the bad performing queries and kill them and study and rewrite the queries.

Tom Kyte
August 17, 2001 - 8:41 pm UTC

Just fyi: to get the FULL text of the query (this gets the first 1000 characters) see the v$sql_text_with_newlines view.

most useful query to help us figure out the performance problem

Pauline, August 17, 2001 - 10:15 pm UTC

I could not find v$sql_text_with_newlines using 8.1.7
SQL> sho user
USER is "SYS"SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle8i Enterprise Edition Release 8.1.7.2.0 - Production
PL/SQL Release 8.1.7.2.0 - Production
CORE    8.1.7.0.0       Production
TNS for Solaris: Version 8.1.7.2.0 - Production
NLSRTL Version 3.4.1.0.0 - Production

5 rows selected.

SQL> desc v$sql_text_with_newlines
ERROR:
ORA-04043: object v$sql_text_with_newlines does not exist

Could you tell me why?
 

Tom Kyte
August 18, 2001 - 8:42 am UTC

sorry about that

V$SQLTEXT_with_newlines

ops$tkyte@ORA817.US.ORACLE.COM> desc v$sqltext_with_newlines;
 Name                                Null?    Type
 ----------------------------------- -------- ------------------------
 ADDRESS                                      RAW(4)
 HASH_VALUE                                   NUMBER
 COMMAND_TYPE                                 NUMBER
 PIECE                                        NUMBER
 SQL_TEXT                                     VARCHAR2(64)

I added an extra underscore 

but not working

Mohammed Ahmed, August 18, 2001 - 9:31 am UTC

the script do not run under

Oracle8 Enterprise Edition Release 8.0.5.2.1

It gives error message:

ERROR at line 4:
ORA-00936: missing expression

May be due to the select in place of colum name


Tom Kyte
August 18, 2001 - 9:46 am UTC

Yes, the select (select...) is new with 8.1.

This works in 8.0 and before

select a.sid, a.serial#, a.username,
to_char(sysdate-a.last_call_et/24/60/60,'hh24:mi:ss') started,
trunc(a.last_call_et/60) || ' mins, ' || mod(a.last_call_et,60) ||
' secs' dur,
b.sql_text
from v$sql b, v$session a
where a.username is not null
and a.last_call_et > 5*60
and a.status = 'ACTIVE'
and a.sql_address = b.address
/

Sean, May 23, 2003 - 12:38 pm UTC

"
V$SQLTEXT_with_newlines

ops$tkyte@ORA817.US.ORACLE.COM> desc v$sqltext_with_newlines;
 Name                                Null?    Type
 ----------------------------------- -------- ------------------------
 ADDRESS                                      RAW(4)
 HASH_VALUE                                   NUMBER
 COMMAND_TYPE                                 NUMBER
 PIECE                                        NUMBER
 SQL_TEXT                                     VARCHAR2(64)
"

can HASH_VALUE use to identified an unique queries statement? Becuase STATSPACK only gives the Hash Value for a query.
Having that said, I have tried the following query, found the hash value and then use the view to find whole query. The outcome was very confussion:

select (select
    decode(extent_management,'LOCAL','*','') from dba_tablespaces where
    tablespace_name =  b.tablespace_name)
        || nvl(b.tablespace_name, nvl(a.tablespace_name,'UNKOWN')) name,
             kbytes_alloc kbytes,
             kbytes_alloc-nvl(kbytes_free,0) used,
             nvl(kbytes_free,0) free,
             ((kbytes_alloc-nvl(kbytes_free,0))/ kbytes_alloc)*100  pct_used,
             nvl(largest,0) largest,
             nvl(kbytes_max,kbytes_alloc) Max_Size,
             decode( kbytes_max, 0, 0, (kbytes_alloc/kbytes_max)*100)   pct_max_used
  from ( select sum(bytes)/1024 Kbytes_free,
                            max(bytes)/1024 largest,
                            tablespace_name
             from  sys.dba_free_space
             group by tablespace_name ) a,
       ( select sum(bytes)/1024 Kbytes_alloc,
                            sum(maxbytes)/1024 Kbytes_max,
                            tablespace_name
             from sys.dba_data_files
             group by tablespace_name

        select sum(bytes)/1024 Kbytes_alloc,
                            sum(maxbytes)/1024 Kbytes_max,
                            tablespace_name
             from sys.dba_temp_files
             group by tablespace_name )b
  where a.tablespace_name (+) = b.tablespace_name
  order by &1
/

SQL> select *
  2        from (
  3      select piece,address, hash_value,
  4             lag(sql_text) over (partition by address, hash_value order by piece) ||
  5             sql_text ||
  6             lead(sql_text) over (partition by address, hash_value order by piece)
  7                sql_text
  8        from v$sqltext_with_newlines
  9             )
 10       where hash_value=4167100631
 11  /

     PIECE ADDRESS  HASH_VALUE
---------- -------- ----------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
         0 81178600 4167100631
select (select
    decode(extent_management,'LOCAL','*','') from dba_tablespaces where
    tablespace_name =  b.tablespace_name)

         1 81178600 4167100631
select (select
    decode(extent_management,'LOCAL','*','') from dba_tablespaces where
    tablespace_name =  b.tablespace_name)
        || nvl(b.tablespace_name, nvl(a.tablespace_name,'UNKOWN')) nam

         2 81178600 4167100631
 dba_tablespaces where
    tablespace_name =  b.tablespace_name)
        || nvl(b.tablespace_name, nvl(a.tablespace_name,'UNKOWN')) name,
             kbytes_alloc kbytes,
             kbytes_alloc-n

         3 81178600 4167100631

        || nvl(b.tablespace_name, nvl(a.tablespace_name,'UNKOWN')) name,
             kbytes_alloc kbytes,
             kbytes_alloc-nvl(kbytes_free,0) used,
             nvl(kbytes_free,0) free,


         4 81178600 4167100631
e,
             kbytes_alloc kbytes,
             kbytes_alloc-nvl(kbytes_free,0) used,
             nvl(kbytes_free,0) free,
             ((kbytes_alloc-nvl(kbytes_free,0))/ kbytes_alloc)*100

         5 81178600 4167100631
vl(kbytes_free,0) used,
             nvl(kbytes_free,0) free,
             ((kbytes_alloc-nvl(kbytes_free,0))/ kbytes_alloc)*100  pct_used,
             nvl(largest,0) largest,
             nv

         6 81178600 4167100631
           ((kbytes_alloc-nvl(kbytes_free,0))/ kbytes_alloc)*100  pct_used,

     PIECE ADDRESS  HASH_VALUE
---------- -------- ----------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
             nvl(largest,0) largest,
             nvl(kbytes_max,kbytes_alloc) Max_Size,
             decode( kbytes

         7 81178600 4167100631
  pct_used,
             nvl(largest,0) largest,
             nvl(kbytes_max,kbytes_alloc) Max_Size,
             decode( kbytes_max, 0, 0, (kbytes_alloc/kbytes_max)*100)   pct_max_used
  from

         8 81178600 4167100631
l(kbytes_max,kbytes_alloc) Max_Size,
             decode( kbytes_max, 0, 0, (kbytes_alloc/kbytes_max)*100)   pct_max_used
  from ( select sum(bytes)/1024 Kbytes_free,


         9 81178600 4167100631
_max, 0, 0, (kbytes_alloc/kbytes_max)*100)   pct_max_used
  from ( select sum(bytes)/1024 Kbytes_free,
                            max(bytes)/1024 largest,
                            tablespa

        10 81178600 4167100631
 ( select sum(bytes)/1024 Kbytes_free,
                            max(bytes)/1024 largest,
                            tablespace_name
             from  sys.dba_free_space
             group

        11 81178600 4167100631
   max(bytes)/1024 largest,
                            tablespace_name
             from  sys.dba_free_space
             group by tablespace_name ) a,
       ( select sum(bytes)/1024 Kbytes_

        12 81178600 4167100631
ce_name
             from  sys.dba_free_space
             group by tablespace_name ) a,
       ( select sum(bytes)/1024 Kbytes_alloc,

     PIECE ADDRESS  HASH_VALUE
---------- -------- ----------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
                            sum(maxbytes)/1024 Kbytes_max

        13 81178600 4167100631
 by tablespace_name ) a,
       ( select sum(bytes)/1024 Kbytes_alloc,
                            sum(maxbytes)/1024 Kbytes_max,
                            tablespace_name
             from

        14 81178600 4167100631
alloc,
                            sum(maxbytes)/1024 Kbytes_max,
                            tablespace_name
             from sys.dba_data_files
             group by tablespace_name


        15 81178600 4167100631
,
                            tablespace_name
             from sys.dba_data_files
             group by tablespace_name
             union all
        select sum(bytes)/1024 Kbytes_alloc,


        16 81178600 4167100631
sys.dba_data_files
             group by tablespace_name
             union all
        select sum(bytes)/1024 Kbytes_alloc,
                            sum(maxbytes)/1024 Kbytes_max,


        17 81178600 4167100631
      union all
        select sum(bytes)/1024 Kbytes_alloc,
                            sum(maxbytes)/1024 Kbytes_max,
                            tablespace_name
             from sys.dba_te

        18 81178600 4167100631

     PIECE ADDRESS  HASH_VALUE
---------- -------- ----------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
                         sum(maxbytes)/1024 Kbytes_max,
                            tablespace_name
             from sys.dba_temp_files
             group by tablespace_name )b
  where a.tabl

        19 81178600 4167100631
                    tablespace_name
             from sys.dba_temp_files
             group by tablespace_name )b
  where a.tablespace_name (+) = b.tablespace_name
  order by '%'

        20 81178600 4167100631
mp_files
             group by tablespace_name )b
  where a.tablespace_name (+) = b.tablespace_name
  order by '%'


21 rows selected.

SQL>
-------

If you put them together by PIECE, then it does not match the original.
 

Tom Kyte
May 24, 2003 - 9:37 am UTC

hash is not enough.

a single hash value will point to all child cursors.

two queries CAN have the same hash value.


The hash value plus the leading edge of the query provided by statspack is generally more then sufficient however to track down the entire query.


your query was in 20 pieces apparently.

Your query to retrieve the query retrieved 20 rows. Each row had the prior and next row in it. You ended up with about 58 pieces therefore.

just

select sql_text from v$sqltext_with_newlines
where hash = ..... order by piece;


Sean, May 23, 2003 - 12:45 pm UTC

Never mind, I figured it out:

SQL> select sql_text from v$sqltext_with_newlines where HASH_VALUE=4167100631 order by piece;
 

What about statements within procedures?

Terry, March 09, 2005 - 2:41 am UTC

I've found that by monitoring using last_call_et, I get notifications for statements running for a long time when it's actually the enclosing procedure that has been running that long. Is there any way to see how long an indivual SQL statement is taking, even if it's part of a stored procedure?

Tom Kyte
March 09, 2005 - 7:45 am UTC

the last_call_et is the timing for the LAST CALL to the database (which would be the enclosing plsql call yes).

The problem with "how long has that sql statement taken" is that given the code:


for x in C
loop
fetch C into l_rec;
exit when....
end loop;

the sql statement's execution in general is interleaved with the plsql code -- they are going back and forth and back and forth and back and forth. It is not just "run this sql". So, unless you are tracing, it is not really possible to see the SQL time.

If you have a truly long running SQL

for x in ( select * from t, t, t, t ) -- 4 way cartesian join
loop
fetch .... --- that first fetch is going to perhaps take "some time"


v$session_longops could be useful.

last_call_et

Parag Jayant Patankar, March 09, 2005 - 8:50 am UTC

Hi Tom,

When I am exeucting your query it is giving me following output 

19:08:52 SQL> l
  1  select sid, serial#, username,
  2  to_char(sysdate-last_call_et/24/60/60,'hh24:mi:ss') started,
  3  trunc(last_call_et/60) || ' mins, ' || mod(last_call_et,60) ||' secs' dur, last_call_et,
  4  (select substr(sql_text,1,50) from v$sql where address = sql_address )
  5  sql_text
  6  from v$session
  7* where username is not null
19:09:02 SQL> /

       SID    SERIAL# USERNAME                       STARTED  DUR                  LAST_CALL_ET
---------- ---------- ------------------------------ -------- -------------------- ------------
SQL_TEXT
--------------------------------------------------
         7        401 OPS$ATLAS                      19:08:45 0 mins, 3 secs                  3
select * from tdz17 order by a6000

        14        132 SYSTEM                         19:08:48 0 mins, 0 secs                  0
select sid, serial#, username, to_char(sysdate-las


19:09:04 SQL> /

       SID    SERIAL# USERNAME                       STARTED  DUR                  LAST_CALL_ET
---------- ---------- ------------------------------ -------- -------------------- ------------
SQL_TEXT
--------------------------------------------------
         7        401 OPS$ATLAS                      19:10:00 0 mins, 0 secs                  0
select * from tdz17 order by a6000

        14        132 SYSTEM                         19:10:00 0 mins, 0 secs                  0
select sid, serial#, username, to_char(sysdate-las

Now my questions are

1. Why started time getting changed in two outputs, it should remain fix in two outputs. Started time changed from 19:08.45 to 19:10:00.

Same case for duration and last_call_et also. First output showing more duration while second output is showing duration 0 mins 0 secs

2. select .... ( select sql_text ..... ) from ...... in this your sql query can you tell me why you have written select sql_text inside select statement rather than joing this table simply with v$session ?

thanks & regards

 

Another place to look

Gary, March 09, 2005 - 6:11 pm UTC

For Terry, Another place to look is the elapsed_time column on v$sqlarea (available in 9iR2 - not sure about earlier releases).

This is the total time for the query over all its executions by any users so is a different measure to the one the original question was about. However it may help in identifying SQLs that are taking a long time to run in your system.
If you application is nicely setup (ie programs actually set the MODULE), it MAY point you in the right direction when you get an issue like "The batch run last night took forever. What was making it so slow ?".

Just what I need, how to get around subquery of sql_text -

A reader, June 25, 2007 - 8:25 pm UTC

This is great, but how do I get around the fact that
v$sqltext_with_newlines returns multiple rows?

select sid, serial#, username,
to_char(sysdate-last_call_et/24/60/60,'hh24:mi:ss') started,
trunc(last_call_et/60) || ' mins, ' || mod(last_call_et,60) ||
' secs' dur,
(select sql_text from v$sqltext_with_newlines where address = sql_address ) sql_text
from v$session
where username is not null
and last_call_et > 0*60
and status = 'ACTIVE'



(select sql_text from v$sqltext_with_newlines where address = sql_ad
dress ) sql_text
*
ERROR at line 5:
ORA-01427: single-row subquery returns more than one row

I tried adding a loop statement like in your sqlnow script but I it just put a different piece on each line and repeated the headings for each piece.


Tom Kyte
July 02, 2007 - 9:07 am UTC

don't use with newlines view??? it by definition returns multiple rows.

use v$sql like I did.

sql with newlines

A reader, July 03, 2007 - 12:07 am UTC

In your first follow up, you suggested the newlines view.
Isn't there some trick to get the entire statement?
Tom Kyte
July 03, 2007 - 10:31 am UTC

search this site for showsql.

last_call_et for sql in a loop

Sujit, February 18, 2010 - 3:35 pm UTC

I was trying to find out the time consuming sql of the system during the pick ours , by querying v$session and filtering on last_call_et. While doing that I found few sql which are pretty simple come into that list. ( All sql I am talking about is invoked from a procedure). To reproduce this scenario I have prepared following test case (please note this is just one case , there may be other type of cases also ) :
create table temp01(description varchar2(1000));
create table temp02(description varchar2(1000));

create or replace type varchar2_array as table of varchar2(1000);
create or replace type num_array as table of number;
insert into temp01 select object_name from all_objects;
insert into temp02 select object_name from all_objects;

declare
l_desc varchar2_array;
l num_array;
begin
select rownum bulk collect into l from temp01;

for i in 1..8000
loop
select description bulk collect into l_desc from temp01 where rownum<=l(i);
end loop;

for i in 1..8000
loop
select description bulk collect into l_desc from temp02 where rownum<=l(i);
end loop;


end;

While executing this pl/sql block I was monitoring last call et by below
select osuser,sql_id,last_call_et from v$session where sid=439

Looks like last_call_et is increasing gradually , and it does not reset after every sql call. Not even after sql statement change.
so looks like last_call_et is the time for PL/SQL execution , is there any way we can filter out individual sql with elapsed time greater than some specified duration.

Tom Kyte
February 18, 2010 - 7:41 pm UTC

last call et is the time of the last CALL by the client to the database.

the client called:

declare.... begin ... end;


unless and until that call - that plsql block - ends, last_call_et will increment in 3 second intervals. As long as that session remains active, last_call_et will increase.

If you want it line by line (a sql statement would be a "line" basically), you would be wanting to use the profiler builtin to the database (sql developer has the best interface to that)

or use tkprof+sql_trace (that is what I use to find low hanging fruit sql-wise in a program)

aitorito, November 11, 2019 - 12:09 pm UTC

my query:

select
to_char(sysdate-last_call_et/24/60/60,'hh24:mi:ss') started,
trunc(last_call_et/60) || ' mins, ' || mod(last_call_et,60) ||
' secs' dur,
sesion.sid,sesion.serial#,sesion.process,sesion.machine,sesion.port,sesion.program,sesion.type,sesion.module,sesion.action,sesion.event,sesion.service_name,
sesion.username ,
sql_text
from gv$sqlarea sqlarea, gv$session sesion
where sesion.inst_id = sqlarea.inst_id
and sesion.sql_hash_value = sqlarea.hash_value
and sesion.sql_address = sqlarea.address
and sesion.username is not null order by 2 desc;