A slowdown has a root cause only when every second of the wait is explained. That is why the method starts from the time someone waits, not from indicators for the whole database: it measures that time in a concrete operation, divides it into parts and attacks the largest one first.
What it is
Response time (R) is how long the operation took for whoever waits for it. WaitScope reads the 10046 trace of the session and divides R into components: the CPU of each call type, each wait event and the time the trace does not explain, within calls and between them. The components add up to exactly R, so all the time is accounted for.
The method was described by Cary Millsap and Jeff Holt in the book Optimizing Oracle Performance (O'Reilly, 2003), and the name Method R is theirs. The report profile follows the same principle: the total time divided into parts that add up to R.
The steps
- Choose the operation that matters to the business. A task with someone waiting for it: closing an order, issuing an invoice, a batch job that ran past its window. The average of the whole database mixes that operation with all the others and hides the cause.
- Measure R with a trace of that operation. Turn on 10046 tracing with waits only in the session that runs the operation, right before it starts, and turn it off right after it ends (turn on tracing with DBMS_MONITOR, 10046 levels). In the report, R is the Total time in the Summary, and the Period shows whether the trace covers the operation.
- Attack the largest component. The response time profile is sorted by duration. No fix saves more than the component it reduces: eliminating a component that is 5% of R removes at most 5% of the time.
- Before touching SQL, look at the wait for the application and at the unaccounted-for time.
SQL*Net message from clientis time outside the database, which SQL tuning does not reduce (session waiting for the application). High unaccounted-for time points to CPU queueing, a trace without waits or an incomplete trace (within calls, between calls). Fix the measurement before drawing conclusions. - Drill down to statement, plan and object. In Top statements by component, see which statements spent the time of the largest component. In the statement detail, the execution plan shows the operation that concentrates the work, and Objects with the most wait time shows the table or the index.
- Change one thing at a time. With two changes together, there is no way to know which of them changed the time, or whether one made worse what the other improved.
- Measure again with a new trace. Repeat the same operation, under the same conditions and with tracing turned on the same way, and compare the Total time and the component you attacked. Upload the new file: the same file as before opens the report that already exists (repeated upload). In the console History, the Total time column shows the R of each analysis.
The role of the diagnosis
The Diagnosis section of the report points out patterns that often explain the profile, in order of severity and, in general, with a link to the data that supports each one. They are leads, not conclusions: confirm them in the profile and in the statement before acting (how to read the Diagnosis).
Each finding has a page in this documentation, with the cause, the resolution and how to confirm it; the list is in where to go from here. The API returns the code of each finding in the code field, for example TEMPO_NA_APLICACAO.
In the sample report
The sample report, made from the synthetic trace, has a Total time of 0.007 s. In the profile, the largest component is SQL*Net message from client, with 71.3%, and the Diagnosis opens with The session spent most of its time waiting for the application.
Following step 4, the conclusion comes before looking at SQL: even if every other component went to zero, R would drop by at most 28.7%. The next component, db file sequential read, accounts for 18.5%. Only then is it worth drilling down to statement #1, whose plan concentrates the time in the TABLE ACCESS BY INDEX ROWID operation (operation that dominates the plan).
What the method does not do
- It does not explain the whole system. The trace shows one session: whoever holds the lock it waits for, or whatever else was running on the server, stays outside it.
- It does not see inside the time spent outside the database. The application time shows up as a wait, with no detail of what the application was doing.
- It does not work with mixed tasks. The trace of a session that does several tasks gives a profile that describes none of them: trace only the chosen operation.
- It does not replace testing. A fix that speeds up one operation can slow down another: also measure the other operations that matter.
The limits of the product are in what WaitScope does not do.
Where to go from here
Each page covers a finding of the Diagnosis. Grouped by the step of the method where they usually show up:
- Time outside the database: session waiting for the application and many FETCH calls with few rows.
- Time the trace does not explain: within calls, gaps between calls and CPU above elapsed time.
- One component dominates: dominant component, dominant CPU, slow reads and many reads.
- Waiting for other sessions or for the database: locking, concurrency, commit, configuration, RAC and Resource Manager.
- Parse and bind: many hard parses, one PARSE per execution and literals instead of binds.
- Plan and PL/SQL: operation that dominates the plan, wrong row estimate and row by row in PL/SQL.
- Other records: slow calls, Oracle errors, no data found, rollback, deadlock and empty trace.
To read the report section by section, start with the profile and the Diagnosis.