caso-2.trc

db file sequential read

Reads one block from disk into the buffer cache: index access, table access by ROWID, undo or segment header.

Normal when

Index access to a few blocks, averaging 0.1 to 1 ms on SSD or flash and 5 to 10 ms on disk.

A concern when

Many reads: the plan reads too many blocks (unselective index, NESTED LOOPS with many rows). High average: slow or contended storage.

Where to look

• How many reads and how long each one lasts: Profile, this component's row: Occurrences and Avg (s) columns
• Slow reads, or many fast reads: Latency distribution, this event's table
• Most-read objects: Objects with the most wait time
• Rereads of the same blocks: Reads, first read and reread of the same block
• Statements that read the most: Top statements by component, this event's group
• Plan operations that read too many blocks: statement detail, Execution plan: highlighted operations

CPU: EXEC dbcalls

The session's CPU time executing: DML, cursor opening and the body of PL/SQL blocks. High in PL/SQL: heavy logic or SQL inside a loop.

Normal when

It is part of the database's normal work.

A concern when

It dominates the total time: start with the statements that use the most CPU and with their logical reads.

Where to look

• CPU by call type: Call types
• Statements with the most logical reads: SQL statements, LIO and Rows columns
• Statements that used the most CPU in this call: Top statements by component, this call's group
• Child statements of the PL/SQL blocks: statement detail, Recursive SQL

unaccounted-for time within calls

The part of the call's duration (e=) that is neither CPU (c=) nor a wait recorded inside it.

Normal when

Small. A negative value comes from the granularity of the CPU measurement, not from a problem.

A concern when

It adds up a lot: CPU queueing (more runnable processes than cores), memory paging (swap) or code without wait instrumentation.

Where to look

• Calls where time goes missing (duration well above CPU plus waits): Longest depth-0 calls
• Statements that carry the most of this time: Top statements by component, this event's group
• Server CPU load and free memory over the period, outside the report

unaccounted-for time between calls

Time between the end of one level-0 call and the start of the next with no recorded wait. It is the difference between the total time and the sum of the calls and the waits between them.

Normal when

Small: fractions of a millisecond per call.

A concern when

It adds up a lot: the trace was turned on or off midway, the process was kept off the CPU (saturated server), the application took long without the client wait showing up, or a collection file is missing.

Where to look

• Trace period and large time gaps: Summary, Period
• In a collection, whether all files arrived: Collection, files and sessions
• Calls separated by gaps: Longest depth-0 calls

direct path read

Reads blocks from disk straight into session memory, bypassing the buffer cache: large serial full scan or parallel query.

Normal when

Full read of a large table in a batch process.

A concern when

It shows up in a user screen or inside a loop: a large full scan repeated, a whole table read to return a few rows.

Where to look

• Statements that read the most: Top statements by component, this event's group
• TABLE ACCESS FULL operations and how many times they ran: statement detail, Execution plan: Exec column
• Most-read objects: Objects with the most wait time

SQL*Net message from client

The session finished the previous call and is waiting for the application's next request. It is application, network and user time, not database time.

Normal when

It shows up between every call. Long, isolated waits are the user thinking or the application busy with something else.

A concern when

It dominates the total time with many short waits: the application talks to the database too much (one row per call, SQL inside a loop). With a few long waits, the delay is in the application, and SQL tuning will not fix it.

Where to look

• How many round trips there were and how long each one lasts: Profile, this component's row: Occurrences and Avg (s) columns
• Many short waits or a few long ones: Latency distribution, this event's table
• FETCH calls that bring few rows each: Call types, FETCH row: Count and Rows
• Statements that waited the most for the application: Top statements by component, this event's group

direct path read temp

Reads from the temporary tablespace what a sort, a hash join or a temporary table wrote there.

Normal when

Large sorts and joins, in batch.

A concern when

The operation should fit in the session's memory: PGA too small for it, or more volume than needed (wrong join, sorting too many rows).

Where to look

• Statements that used TEMP: Top statements by component, this event's group
• SORT and HASH JOIN operations that wrote to TEMP: statement detail, Execution plan: PW column
• pga_aggregate_target and pga_aggregate_limit, in the database

CPU: FETCH dbcalls

The session's CPU time fetching rows. High: too many logical reads (LIO), usually a plan that reads far more blocks than the rows returned call for.

Normal when

It is part of the database's normal work.

A concern when

It dominates the total time: start with the statements that use the most CPU and with their logical reads.

Where to look

• CPU by call type: Call types
• Statements with the most logical reads: SQL statements, LIO and Rows columns
• Statements that used the most CPU in this call: Top statements by component, this call's group
• Plan operations with a high self LIO: statement detail, Execution plan: highlighted operations

db file scattered read

Reads several contiguous blocks at once into the buffer cache: full table scan or index fast full scan.

Normal when

Full scan of a small or medium table that fits in the cache.

A concern when

Full scan of a large table to return a few rows: an index is missing, or the index is not used.

Where to look

• Statements that read the most: Top statements by component, this event's group
• TABLE ACCESS FULL and INDEX FAST FULL SCAN operations: statement detail, Execution plan: highlighted operations
• Most-read objects: Objects with the most wait time

direct path write temp

Writes to TEMP the part of a sort or hash join that did not fit in the PGA.

Normal when

Large operations, in batch.

A concern when

Same as reading from TEMP: small PGA or high volume.

Where to look

• Statements that used TEMP: Top statements by component, this event's group
• SORT and HASH JOIN operations that wrote to TEMP: statement detail, Execution plan: PW column

CPU: PARSE dbcalls

The session's CPU time parsing the SQL. High: hard parses from SQL without binds, or repeated parsing of the same cursor (opened and closed on every execution).

Normal when

It is part of the database's normal work.

A concern when

It dominates the total time: start with the statements that use the most CPU and with their logical reads.

Where to look

• Hard parses: Call types, PARSE row: Count and Misses
• Statements that differ only in literals: Shareable texts
• A PARSE for every EXEC: statement detail, Calls: PARSE against EXEC
• Statements that used the most CPU in this call: Top statements by component, this call's group

CPU: CLOSE dbcalls

The session's CPU time closing the cursor. Almost always small.

Normal when

It is part of the database's normal work.

A concern when

It dominates the total time: start with the statements that use the most CPU and with their logical reads.

Where to look

• CPU by call type: Call types
• Statements with the most logical reads: SQL statements, LIO and Rows columns
• Statements that used the most CPU in this call: Top statements by component, this call's group
• Child statements of the PL/SQL blocks: statement detail, Recursive SQL

log file switch completion

The session waits for the redo log file switch to finish.

Normal when

Rare: one short wait per switch.

A concern when

Redo logs too small for the volume generated: frequent switches.

Where to look

• How many switches and how long each one lasts: Profile, this component's row: Occurrences and Avg (s) columns

Configuration

Waits caused by a configuration limit: small redo log, buffer cache, ITL, sequence cache, space.

Normal when

Rare.

A concern when

The event points to the parameter or object to tune.

Where to look

• Which event, and what it asks for: By wait class, this class's row: Top components column

Unclassified

Events the engine cannot classify.

Normal when

It adds up to little time.

A concern when

It adds up a lot: the event's class in v$event_name says where it belongs.

Where to look

• The event's class: v$event_name.wait_class, in the database

enq: RO - fast object reuse

TRUNCATE or DROP waiting for the database to discard the object's blocks held in the buffer cache.

Normal when

It adds up to little time.

A concern when

TRUNCATE inside a loop, or a buffer cache too large to sweep.

Where to look

• How many occurrences: Profile, this component's row: Occurrences column
• Statements that waited the most: Top statements by component, this event's group

Disk file operations I/O

File operations (open, close, size lookup), not data reads.

Normal when

It adds up to little time.

A concern when

It adds up a lot: many files opened and closed, or a slow file system.

Where to look

• How many occurrences and how long each one lasts: Profile, this component's row: Occurrences and Avg (s) columns

reliable message

The session sent a message to background processes or to other instances and waits for the acknowledgement.

Normal when

It adds up to little time.

A concern when

It adds up a lot: TRUNCATE, result cache or a parameter change in RAC.

Where to look

• Statements that waited the most: Top statements by component, this event's group

SQL*Net message to client

Time to hand a response packet to the operating system. It does not measure the network to the client, only the handoff to the OS.

Normal when

Microseconds per occurrence, one per call.

A concern when

The average rises to milliseconds: the server's network buffer is full or the network is saturated.

Where to look

• Average and maximum per wait: Profile, this component's row: Avg (s) and Max (s) columns

User I/O

Data reads and writes done by the session itself.

Normal when

There is always some I/O, with a low average per read.

A concern when

Too many blocks (the plan reads more than it needs) or high average time per read (slow storage).

Where to look

• Which I/O events weigh: By wait class, this class's row: Top components column
• Slow reads, or many fast reads: Latency distribution
• Most-read objects: Objects with the most wait time
• Statements that read the most: Top statements by class, this class's group
• Plan operations that read too many blocks: statement detail, Execution plan: highlighted operations

Unaccounted-for

Time the trace does not explain by CPU or wait: within calls and between them.

Normal when

Small.

A concern when

CPU queue, paging, gaps in the trace or a file missing from the collection.

Where to look

• The two unaccounted-for time components and the card of each one: Response time profile

CPU

CPU time of the database calls (the c= of PARSE, EXEC and FETCH).

Normal when

This is the database's work.

A concern when

It adds up a lot: too many logical reads (plan), too much parsing or heavy PL/SQL.

Where to look

• CPU by call type: Call types
• Statements with the most logical reads: SQL statements, LIO and Rows columns
• Statements that used the most CPU: Top statements by class, this class's group

Idle

The session is waiting for work. In a session trace it is almost always SQL*Net message from client: application, network and user time.

Normal when

It shows up between calls.

A concern when

Dominates the total time and the user complains about slowness: the delay is outside the database (application, network, too many round trips).

Where to look

• How many round trips there were: Summary, Database calls and Waits
• FETCH calls that bring few rows each: Call types, FETCH row: Count and Rows
• Statements that waited the most for the application: Top statements by class, this class's group

Application

Waits caused by how the application uses the database: rows and tables locked by another session, application locks, returned errors.

Normal when

It adds up to little time.

A concern when

Session stalled waiting for another: long transactions, same row updated by several sessions, unindexed foreign key.

Where to look

• Which events weigh: By wait class, this class's row: Top components column
• Contended objects: Objects with the most wait time
• Statements that were blocked: Top statements by class, this class's group
• Who holds the lock: v$session.blocking_session, in the database

Other

Internal events with no more specific class.

Normal when

It adds up to little time.

A concern when

It adds up a lot: the event itself points to the cause.

Where to look

• Which event weighs: By wait class, this class's row: Top components column

Network

Sending and receiving data over SQL*Net, with the application or with another database over dblink.

Normal when

It adds up to little time.

A concern when

Large results, low arraysize or slow dblink.

Where to look

• Which events of the class weigh (more data, dblink): By wait class, this class's row: Top components column
• Rows per FETCH: Call types, FETCH row: Count and Rows
• Statements that used the network the most: Top statements by class, this class's group

Recursive SQL (child statements)

Time of the calls this statement triggered: SQL inside PL/SQL functions and procedures, triggers and dictionary queries.

Normal when

PL/SQL statement that runs other SQL.

A concern when

It adds up a lot in a plain SELECT or DML: a PL/SQL function called per row, or a heavy trigger.

Where to look

• Which child statements and what each one costs: statement detail, Recursive SQL