Unaccounted-for time within calls

Time inside calls that is neither CPU nor a recorded wait means that the session was busy while Oracle did not measure what it was doing. Before drawing conclusions about the rest of the profile, this time needs an explanation.

Symptoms

In the Diagnosis, the finding A lot of time inside calls with no CPU or recorded wait (NAO_CONTABILIZADO_DENTRO) appears. The text names the common causes, asks you to check the CPU load on the server during the period and ends with View in profile.

The finding appears when the unaccounted-for time within calls component takes up a large part of the total time. The severity is always high. Even when this component is the largest in the profile, it does not also raise the dominant component finding: this finding already covers that time.

Cause

Each call records its duration (e=) and its CPU (c=). This component is the part of the duration that is neither CPU, nor a wait recorded inside the call, nor a child call. It grows when:

• The trace has no waits. At 10046 levels 1 and 4 there are no WAIT lines: the time of disk reads, of locks and of every other wait inside the calls becomes unaccounted-for.
• There is CPU queueing. More processes are ready to run than there are cores: the session waits its turn on the CPU, and that time is neither CPU nor an Oracle wait.
• The server is paging memory. With no free memory, the system swaps pages with the disk and the process stalls.
• There is code without wait instrumentation. These are stretches of code that Oracle does not measure as a wait; the finding text mentions long PL/SQL loops.

Resolution

1. Check whether the trace has waits: Waits equal to 0 in the Summary indicates a trace without waits. Generate it again at level 8 or 12 (10046 levels).
2. Check the CPU load on the server during the Period of the trace. CPU queueing shows up as runnable processes above the number of cores, for example in the r column of vmstat or in sar -q. For a period that has already passed, use the sar history or the server monitoring.

   vmstat 5
   sar -q 5 12

3. Check the memory in the same period: pages swapped with the disk (the si and so columns of vmstat) indicate paging.
4. Find where the time goes. In Longest depth-0 calls, look for calls with Duration (s) well above CPU (s); in Top statements by component, open the unaccounted-for time within calls group.
5. With CPU queueing or paging, the fix is on the server: fewer concurrent processes, more CPU or memory, or an SGA and PGA sized to fit in physical memory.
6. If the time is concentrated in a PL/SQL block and the server was not overloaded, investigate the code of that block.

How to confirm

Generate a new trace of the same operation, with waits and during a period in which the cause was fixed. The unaccounted-for time within calls component should become small, the time it was hiding shows up as waits or CPU in the other components, and the finding disappears.

If you only turned on the waits, the Total time may not change: the time just got a name. Go back to the profile and attack the largest component.

In the report

In the sample report, this component adds up to 2.3% of the total time, without a finding. The links open the sections of the example:

• Diagnosis: the finding and the View in profile link.
• Profile, unaccounted-for time within calls row. Click the name to open the card with Where to look.
• By wait class, Unaccounted-for row: the two unaccounted-for time components added up.
• Longest depth-0 calls: Duration (s) and CPU (s) of each call.
• Top statements by component, the component's group: the statements that carry the most of this time.
• Summary: Waits and Period.