How to Find Performance Problems with Active Session History (ASH)

Analyze a finished workload with V$ACTIVE_SESSION_HISTORY: time on CPU and waits, the top SQL, and who blocked whom, after the fact.

V$SESSION shows what sessions are doing now; when users report that the system was slow ten minutes ago, the moment has passed. Active Session History fills that gap. Every second, Oracle records a sample of each active session: whether it was on the CPU or waiting, for which event, running which SQL, and who was blocking it. Counting these samples shows where database time went in any recent period. This guide runs a small workload with a busy report and a blocked session, and then analyzes it afterward with V$ACTIVE_SESSION_HISTORY.

Licensing

Active Session History is part of the Oracle Diagnostics Pack. On Enterprise Edition, query it only when the database is licensed for the Diagnostics Pack and CONTROL_MANAGEMENT_PACK_ACCESS includes DIAGNOSTIC. The examples run on Oracle AI Database 26ai Free, as a user with the SELECT_CATALOG_ROLE role.

Sample Tables and Workload

Example:

create table demo_orders as
select level as order_id, mod(level * 7, 5000) + 1 as customer_id,
       mod(level * 13, 500) + 10 as amount
from   dual connect by level <= 1000000;

create table demo_seats (seat varchar2(4) primary key, passenger varchar2(30));
insert into demo_seats values ('14C', null);
commit;

Output:

Table DEMO_ORDERS created.

Table DEMO_SEATS created.

1 row inserted.

Commit complete.

Three sessions run at the same time, each with its own module name. A report runs an aggregate over a million rows for 25 seconds:

Example:

-- a report that runs the same aggregate again and again for 25 seconds
exec dbms_application_info.set_module('ASH_REPORT', null)
declare
  l_end   number := dbms_utility.get_time + 2500;
  l_total number;
begin
  while dbms_utility.get_time < l_end loop
    select sum(amount) into l_total from demo_orders where customer_id > 100;
  end loop;
end;
/

A session locks seat 14C and sleeps with the transaction open:

Example:

-- a session that locks a seat and then sleeps
exec dbms_application_info.set_module('ASH_HOLDER', null)
update demo_seats set passenger = 'Mia' where seat = '14C';
exec dbms_session.sleep(25)
rollback;

A booking needs the same seat and has to wait:

Example:

-- a booking that needs the same seat
exec dbms_application_info.set_module('ASH_BOOKING', null)
update demo_seats set passenger = 'Raj' where seat = '14C';
rollback;

Output:

PL/SQL procedure successfully completed.

1 row updated.

Rollback complete.

All three have finished before the analysis below starts.

Where the Time Went

Each sample stands for about one second of database time of one session, so counting samples gives seconds:

Example:

-- where the sessions' time went in the last 5 minutes: one sample per active second
select module, session_state, nvl(event, 'ON CPU') as event, count(*) as samples
from   v$active_session_history
where  module like 'ASH_%'
and    sample_time > systimestamp - interval '5' minute
group  by module, session_state, event
order  by samples desc;

Output:

MODULE         SESSION_STATE    EVENT                               SAMPLES
______________ ________________ ________________________________ __________
ASH_REPORT     ON CPU           ON CPU                                   25
ASH_BOOKING    WAITING          enq: TX - row lock contention            20
  • The report spent 25 seconds on the CPU, its whole run time.
  • The booking spent 20 seconds waiting on enq: TX - row lock contention.
  • The holder does not appear at all: sleeping, like waiting for a client's next request, is an idle wait, and ASH samples only active sessions. A blocker that does nothing is invisible here; it shows up as the blocker of others.

The Top SQL

Example:

-- the statements behind the samples
select h.sql_id, count(*) as samples, substr(min(q.sql_text), 1, 60) as sql_text
from   v$active_session_history h
left   join v$sql q on q.sql_id = h.sql_id
where  h.module like 'ASH_%'
and    h.sample_time > systimestamp - interval '5' minute
group  by h.sql_id
order  by samples desc;

Output:

SQL_ID              SAMPLES SQL_TEXT
________________ __________ ______________________________________________________________
6hk5bh961cjws            25 SELECT SUM(AMOUNT) FROM DEMO_ORDERS WHERE CUSTOMER_ID > 100
6y1t39jrv312z            20 update demo_seats set passenger = 'Raj' where seat = '14C'

The report's aggregate and the waiting UPDATE account for all the samples. The aggregate appears in uppercase because it ran as static SQL inside PL/SQL.

Who Was Blocking

Samples of waiting sessions also record the blocking session:

Example:

-- who blocked the waiting session, according to the samples
select h.event, h.blocking_session as blocker, count(*) as samples,
       min(to_char(h.sample_time, 'HH24:MI:SS')) as first_seen,
       max(to_char(h.sample_time, 'HH24:MI:SS')) as last_seen
from   v$active_session_history h
where  h.module = 'ASH_BOOKING'
and    h.sample_time > systimestamp - interval '5' minute
group  by h.event, h.blocking_session;

Output:

EVENT                               BLOCKER    SAMPLES FIRST_SEEN    LAST_SEEN
________________________________ __________ __________ _____________ ____________
enq: TX - row lock contention           209         20 04:37:26      04:37:45

Session 209, the holder, blocked the booking for 20 seconds, from 04:37:26 to 04:37:45. Even after both sessions have ended, the samples tell who waited, for how long, and for whom.

Useful Columns

  • SAMPLE_TIME, SESSION_ID, SESSION_SERIAL#, USER_ID, MODULE, and ACTION identify when and who.
  • SESSION_STATE (ON CPU or WAITING), EVENT, and WAIT_CLASS tell what the session was doing.
  • SQL_ID, SQL_PLAN_HASH_VALUE, and SQL_PLAN_LINE_ID point to the statement and even the plan line being executed.
  • BLOCKING_SESSION, CURRENT_OBJ#, and the TEMP_SPACE_ALLOCATED and PGA_ALLOCATED columns add the context for locks and memory.

Things to Know

  • V$ACTIVE_SESSION_HISTORY lives in memory and typically covers the last hour or so on a busy system, depending on the buffer size.
  • One in ten samples is kept in the Automatic Workload Repository and can be queried longer through DBA_HIST_ACTIVE_SESS_HISTORY, where each sample then stands for about 10 seconds.
  • Counts are statistical: a statement that ran for a fraction of a second may not be sampled at all, while long-running work is measured accurately.
  • Set MODULE and ACTION with DBMS_APPLICATION_INFO in applications, so ASH can tell which part of the application used the time.

Related Guides

Conclusion

Active Session History samples every active session once a second, so counting its rows gives database time by session state, event, SQL, and module for any recent period. Group V$ACTIVE_SESSION_HISTORY by those columns to find what was slow after the fact, and by BLOCKING_SESSION to find who held others up.

Vinish Kapoor
Vinish Kapoor

An Oracle ACE, author of four books on Oracle APEX, SQL and PL/SQL, and Oracle Forms, and a software developer building Oracle database applications since 2001.

guest

0 Comments
Oldest
Newest Most Voted