Tuesday, January 11, 2011

A QUICK LOOK AT WHY

The other day I got the following email:

***********
Sam,
Can you please take a look at this query? It’s been running twice as long as expected:

SID
738 aname bname SQL*Plus @@corvette 15,051 776.06 08-JAN-11 02:40:23 32 02:55:15 136
insert /*+ append */ into tmp_somename_tb select scheme. Id…

Thanks!
***********

Here is the quick pass I performed to see what was going on.

First the summary I gave:
As expected the insert is doing heavy direct path reads to temp and then once those slave buckets are full it does heavy direct path writes to temp. During the reads the box load is light (9 and 10), the cpu is light (51% used – 47% user and 4% system), the run queue not bad (4, 5); however, The cpu’s are waiting on i/o (25, 28). During the writes the box load is very high (126 and 152), the cpu is heavy (99% used – 94% user and 5% system), the run queue is very high (116, 122); The cpu’s are not waiting on i/o (0).

Now, the where I got it from:
Direct path reads/writes to temp:
Within grid control, under top activity, selected the sqlid in question, in the details section the summary block using the color codes to determine the direct path reads/writes to temp.

Box Load:
At the top of ‘top’: load average: 9.03, 10.93, 14.60

CPU: Also from ‘top’

Run Queue:
sfulke@corvette[gmdwhp]:/home/sfulke> vmstat 5 5
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
11 18 900 14836684 276388 4334588 0 0 37171 4913 0 0 32 7 49 11
9 22 900 14893188 276412 4334564 0 0 671667 54523 10845 18386 59 11 3 27
28 11 900 14684604 276424 4334552 0 0 624320 68223 7881 12968 48 8 14 30
33 13 900 14683636 276444 4334532 0 0 680810 320344 12198 14958 66 13 9 12
20 14 900 14682612 276492 4334484 0 0 739581 278236 10658 15601 57 12 14 17
sfulke@corvette[gmdwhp]:/home/sfulke>

The run queue is the first column from the vmastat output (remember to disregard the first line of output as it can be accumulative) ‘r’.

The last column from the vmstat output is the cpu’s waiting on i/o ‘wa’.


Here is a little more detail for each of the columns from the vmstat output:
Processes:
r: Processes waiting in line for some time on the CPU
b: Uninterruptble sleeping processes

Memory:
swpd: Virtual memory usage
free: Idle memory usage
buff: Buffer Memory
cache: Cache Memory

Swap:
si: Memory swapped in from disk
so: Memory swapped out to disk

IO:
bi: Blocks received hdd
bo: Blocks sent to hdd

System:
in: Number of interrupts per second
cs: Number of context switches per second

CPU:
us: Time used executing non-kernel code. (For example: User Time items like ‘nice’ – actual work)
sy: Time used executing kernel code. (For example: System Time items like ‘IO interrupts’- work management)
id: Time in idle state.
wa: Time used waiting for IO. Prior

Have a great day!

No comments: