-- ********************************************************************
-- * Copyright Notice   : (c)2001,2002,2003,2008 OraPub, Inc.
-- * Filename           : rtsess.sql
-- * Author             : Craig A. Shallahamer
-- * Original           : 10-may-01
-- * Last Update        : 28-May-08
-- * Description        : rtsess.sql - Response time profile -
-- *                                   Interactive, session level
-- * Usage              : start rtsess.sql ‹client identifier›
-- * 					  start rtsess.sql WLC_1
-- ********************************************************************

-- rt  = st + qt + uat
-- qt  = qiot + qnc + qot
-- rt  = st + qiot + qnc + qot + uat
--
-- where:	rt  = response time
--		qt  = queue time (wait event time + cpu system time)
--		st  = service time (cpu user time)
--		uat = unaccounted for time (tool usage error, uninstrumented time, etc.)
--		qiot= queue io time
--		qnc = queue idle time (network delay, client prog processing)
--		qot = queue other time (various wait events)

def client_id=&1

set termout on 

prompt ===================================================================
prompt Session Level Response Time Profile (client identifer = &client_id)
prompt   
prompt Step # 1
prompt
prompt You may want to ensure there is only one session related to the
prompt client identifer. Considering running sessinfo.sql or this sample SQL:
prompt
prompt select sid,serial# from v$session where client_identifier like '&client_id%';
prompt 
prompt You can set a sessions client identifier when connected as the session:
prompt   dbms_session.set_identifier('the client id');
prompt 
prompt Have the user(s) login and navigate to the performance problem and
prompt then have them wait until you tell them to run the "problem."
prompt
prompt When they are ready, press return to go to the next step.
prompt ===================================================================
accept x

-- GET SESSION INFORMATION

set termout off

--col val1 new_val s_ident noprint
--select  sid val1
--from   	v$session
--where	client_identifer = &client_id;

col val1 new_val cpu_count noprint
select  value val1
        from   v$parameter
        where  name = 'cpu_count';

-- CREATE EMPTY TABLES to hold timing details

drop table o$rtsess_ev
/
create table o$rtsess_ev as
	select	name event, to_number(0) tw_t0, to_number(0) tw_t1
	from	v$event_name
/
drop table o$rtsess_time
/
create table o$rtsess_time as
	select	to_number(0) cpu_begin,
		to_number(0) cpu_end,
		to_number(0) clock_begin,
		to_number(0) clock_end
	from	dual
/

-- Get current wait event (to be used to subtract pre-transaction time from final RT)

--col val1 new_val current_wait_event noprint
--select 	event val1
--from	v$session_wait
--where	sid = '&sid' 
--/

set termout on

--select '¤t_wait_event'|| is the current wait event for sid &sid from dual;

prompt ===================================================================
prompt Step # 2
prompt 
prompt You are about to begin response time statistics collection.
prompt
prompt After you press ENTER, initial session data will be gathered and stored.
prompt
prompt THEN you will be prompted to tell the USER to start their "problem."
prompt
prompt Now tell the user to get ready.
prompt
prompt Press ENTER to begin to load initial session data.
prompt ===================================================================
accept x

set termout on
prompt Get ready...
set termout off
exec dbms_lock.sleep(2);
set termout on
prompt ...1/3

set termout off

-- LOAD (i.e., update at time T0) TABLES

declare
	cursor sw is
		select 	event, sum(time_waited) time_waited
		from	v$session_event
		where	sid in (
					select 	sid
					from 	v$session
					where 	client_identifier like '&client_id%'
					   )
		group by event;
begin
	for sw_rec in sw loop
	  update  o$rtsess_ev
	  set     tw_t0 = sw_rec.time_waited
	  where   o$rtsess_ev.event = sw_rec.event;
	end loop;
	commit;
end;
/
set termout on
prompt ...2/3
set termout off

update	o$rtsess_time
set	cpu_begin = (	select sum(value)
                  	from   v$sess_time_model
                  	where  stat_name = 'DB CPU'
                    	and  sid in (
								select 	sid
								from 	v$session
								where 	client_identifier like '&client_id%'
									)
                  ),
	clock_begin = ( select dbms_utility.get_time 
                  	from   dual
                      )
/
set termout on
prompt ...3/3
set termout off

set termout on

prompt
prompt USER *GO*, that is, start what is painfully slow now!
prompt
prompt DBA, to end statistics collection press ENTER.

--set termout on

-- This code section tries to account for the main challange of
-- gathering RT information using the v$ views.  The main challange is
-- v$session_event is updated when the current wait event state (from
-- v$session_wait) changes.  Then the v$session_wait.time_waited gets added
-- to v$session_event.time_waited.

-- If we consider the current v$session_event.time_waited value as part of
-- response time it will probably contain time associated with the previous
-- transaction plus probably idle time (when the user was doing nothing
-- and shown as v$session_wait.event where event = 'SQL*Net message from
-- client').  We must find a way to retrieve the non-RT time so it will
-- not be considered part of the current transaction's RT.

-- The problem usually centers around the current wait event 'SQL*Net message
-- from client'.  There can be lots of time associated with this wait event
-- before a user runs the "problem."  And ALL the time will be considered queue
-- time unless we subtract its value from the user's final 'SQL*...' value.

-- There are many ways to get around this problem, but none of them is
-- perfect.  We can cleverly determine the beginning 'SQL*Net...' value by
-- waiting for the current wait event status to change and then get the
-- wait time from v$session_event.  This will become our start time for
-- that wait event, which is probably 'SQL*Net...'..

-- Also, while we can account for the pre-RT event time, we can not account
-- for the time after the transaction completes and we stop the timing.  This
-- is "user tool error" and will be added to the unaccounted for time.

-- I suspect this does not answer all your questions and may raise others.
-- This is the kind of stuff we discuss during my Oracle Performance Firefighting class.

declare
  curr_sn_time		number;
  init_sn_time		number;
  the_client_id		varchar2(100)	:= '&client_id';
begin

  select sum(time_waited)
  into	 init_sn_time
  from   v$session_event
  where	 sid in (
								select 	sid
								from 	v$session
								where	client_identifier like '&client_id%'
				)
    and  event = 'SQL*Net message from client';
  
  curr_sn_time := init_sn_time;
  
  while init_sn_time = curr_sn_time 
  loop
	  select sum(time_waited)
	  into	 curr_sn_time
	  from   v$session_event
	  where	 sid in (
									select 	sid
									from 	v$session
									where 	client_identifier like '&client_id%'
					)
	    and  event = 'SQL*Net message from client';
  end loop;
end;
/

col val1 new_val init_net_time noprint
select 	sum(time_waited) val1
from	v$session_event
where	sid in (
			select 	sid
			from 	v$session
			where 	client_identifier like '&client_id%'
				)
  and	event = 'SQL*Net message from client';

--select 'init_net_time (secs)='||&init_net_time from dual;

accept x

-- LOAD (i.e., update at time T1) TABLES

-- I did the timing setting FIRST to keep as close as
-- possible to the real time.
--
update  o$rtsess_time
set	cpu_end	 = (	select sum(value)
                  	from   v$sess_time_model
                  	where  stat_name = 'DB CPU'
                    	and  sid in (
								select 	sid
								from 	v$session
								where 	client_identifier like '&client_id%'
									)
                 ),
	clock_end  = ( select dbms_utility.get_time 
                  	from   dual
                  )                        
/
-- Now update the wait event numbers.
declare
	cursor sw is
		select 	event, sum(time_waited) time_waited
		from	v$session_event
		where	sid in (
					select 	sid
					from 	v$session
					where 	client_identifier like '&client_id%'
					   )
		group by event;
begin
	for sw_rec in sw loop
	  update  o$rtsess_ev
	  set     tw_t1 = sw_rec.time_waited
	  where   o$rtsess_ev.event = sw_rec.event;
	end loop;
	commit;
end;
/

-- I had to create a table instead of using a view because of some Oracle
-- bug.  The view would create but a variety of bogus output resulted.
-- Don't believe me?...Just change the table stuff to a view stuff.

drop table oo$i_rt_sum
/
create table oo$i_rt_sum as
SELECT  
	(g.clock_end-g.clock_begin)/100 resp_time_tot,
	(g.clock_end-g.clock_begin)/100 wall_time_sec,
	(g.cpu_end-g.cpu_begin)/1000000 service_time_tot, 
        (c.io_wtime_tot+d.other_wtime_sec+i.net_and_client_sec) queue_time_tot,
	c.io_wtime_tot queue_io_tot,
	d.other_wtime_sec queue_other_tot,
        i.net_and_client_sec queue_net_and_client,
        ((g.clock_end-g.clock_begin)/100)-((g.cpu_end-g.cpu_begin)/1000000)-(c.io_wtime_tot-d.other_wtime_sec) queue_idle_tot,
	e.io_wtime_write_sec queue_io_write_sec,
	f.io_wtime_read_sec queue_io_read_sec,
        (g.clock_end-g.clock_begin)-((g.cpu_end-g.cpu_begin)/1000000)-(c.io_wtime_tot-d.other_wtime_sec) idle_sec
FROM    (
        select  sum(tw_t1-tw_t0)/100 io_wtime_tot
        from    o$rtsess_ev
        where   event in ( select a.event
                           from   o$event_type a
                           where  a.type in ('iow','ior')
                         )
	) c,
	(
        select  sum(tw_t1-tw_t0)/100 other_wtime_sec
        from    o$rtsess_ev
        where   event in ( select a.event
                           from   o$event_type a
                           where  a.type in ('other')
                         )
	) d,
	(
        select  sum(tw_t1-tw_t0)/100 io_wtime_write_sec
        from    o$rtsess_ev
        where   event in ( select a.event
                           from   o$event_type a
                           where  a.type in ('iow')
                         )
	) e,
	(
        select  sum(tw_t1-tw_t0)/100 io_wtime_read_sec
        from    o$rtsess_ev
        where   event in ( select a.event
                           from   o$event_type a
                           where  a.type in ('ior')
                         )
	) f,
	o$rtsess_time g,
	(
        select  sum(tw_t1-tw_t0)/100 idle_sec
        from    o$rtsess_ev
        where   event in ( select a.event
                           from   o$event_type a
                           where  a.type in ('idle')
                         )
        ) h,
	(
        select  (tw_t1-&init_net_time)/100 net_and_client_sec
        from    o$rtsess_ev
        where   event = 'SQL*Net message from client'
        ) i
/
        

set termout on
set feedback off
set heading on

---------------------------------------------------------------------------
-- REPORTS : Interactive Session Level Response Time 
---------------------------------------------------------------------------

set linesize 150
set feedback off verify off

prompt Session level response time details for client identifer &client_id

col cpr   format       90.00 heading "% CPU|RT|[st/rt]"
col qpr   format       90.00 heading "% Queue|RT|[qt/rt]"
col uatr  format       90.00 heading "% UAT|RT|[uat/rt]"
col rt    forma     9,990.00 heading "Response|Time(sec)|[rt=st+qt+uat]"
col qt    forma     9,990.00 heading "Queue|Time(sec)|[qt]"
col st    forma     9,990.00 heading "Service|Time(sec)|[st]"
col uat   forma     9,990.00 heading "Unaccount|Time(sec)|[uat]"

prompt
prompt *** Response Time Summary

select	resp_time_tot rt,
	service_time_tot st,
	queue_time_tot qt,
        resp_time_tot-service_time_tot-queue_time_tot uat,
	100*service_time_tot/(resp_time_tot+0.0000001) cpr,
	100*queue_time_tot/(resp_time_tot+0.0000001) qpr,
	100*(resp_time_tot-service_time_tot-queue_time_tot)/(resp_time_tot+0.0000001) uatr
from	oo$i_rt_sum
/

prompt
prompt *** Queue Time Summary

col qt    forma       990.00 heading "Queue Time(sec)|[qio+qnc+qot]"
col qio   format      990.00 heading "QT|I/O(sec)|[qio]"
col qnc   format      990.00 heading "QT|Net+Client(sec)|[qnc]"
col qot   format      990.00 heading "QT|Other(sec)|[qot]"

select	queue_time_tot qt,
	queue_io_tot qio,
	queue_net_and_client qnc,
	queue_other_tot qot
from	oo$i_rt_sum
/

prompt
prompt *** Queue Time IO Timing Detail

col qio   format      990.00 heading "QT|I/O(sec)|[tio=wio+rio]"
col wio	  format      990.00 heading "QT|Write I/O(sec)|[wio]"
col rio	  format      990.00 heading "QT|Read I/O(sec)|[rio]"
col wpct  format      990.00 heading "% Writes Time|[wio/tio]"
col rpct  format      990.00 heading "% Read Time|[rio/tio]"

select	queue_io_tot qio,
	queue_io_write_sec wio,
	queue_io_read_sec  rio,
	100*queue_io_write_sec/(queue_io_tot+0.00001) wpct,
	100*queue_io_read_sec/(queue_io_tot+0.00001) rpct
from	oo$i_rt_sum
/

prompt
prompt *** Queue Time IO Event Timing Detail

col event  format    a40 heading "Wait Event Name"
col et     format 990.00 heading "Wait Time|(sec)"

select  event,
        (tw_t1-tw_t0)/100 et -- io_wtime_events_sec
from    o$rtsess_ev
where
        (tw_t1-tw_t0) › 0
  and   event in ( select a.event
                   from   o$event_type a
                   where  a.type in ('iow','ior')
                 )
/

prompt
prompt *** Queue Time Other Event Timing Detail

col event  format    a40 heading "Wait Event Name"
col et     format 990.00 heading "Wait Time|(sec)"

select  event,
        sum(tw_t1-tw_t0)/100 et -- other_wtime_events_sec
from    o$rtsess_ev
where
        (tw_t1-tw_t0) › 0
  and   event in ( select a.event
                   from   o$event_type a
                   where  a.type in ('other')
                 )
group by event
/

prompt
prompt *** Wait Event Time Not Categorized (for QA)

col event  format    a40 heading "Wait Event Name"
col et     format 990.00 heading "Wait Time|(sec)"

select  event,
        sum(tw_t1-tw_t0)/100 et -- other_wtime_events_sec
from    o$rtsess_ev
where
	(tw_t1-tw_t0) › 0
  and   event in ( select a.event
                   from   o$event_type a
                   where  a.type not in ('other','ior','iow','idle','bogus')
                 )
group by event
/


prompt
prompt
prompt Unaccounted for time could be the result of time spent
prompt between the Oracle client process and the user, OS and
prompt oracle timing error, tool usage error, uninstrumented
prompt Oracle kernel code, plus other issues.
prompt
--prompt The initial network time was &init_net_time cs.
prompt
prompt You may want to review and/or delete the working tables:
prompt drop table o$rtsess_ev ;
prompt drop table o$rtsess_time ;
prompt drop table oo$i_rt_sum ;
prompt To review time details do: 
prompt select event,tw_t0,tw_t1,tw_t1-tw_t0 from o$rtsess_ev order by event
prompt
prompt There are data collection details contained in the code.
prompt