exemplo-10046.trc

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

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

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

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

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

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: 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

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

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

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

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

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