Re: Enqueue wait time discrepancies in statspack

  • From: "Domingo Diaz Saenz" <domingo.diazs@xxxxxxxxx>
  • To: nigel@xxxxxxxxxxxxxx
  • Date: Tue, 13 Jun 2006 13:09:46 +0200

Interesting,

Top 10 Timed Events section of Statspack report is based in view
v$system_event with event='enqueue' , by other hand Enqueue activity section
is based in v$enqueue_stats.

Really if the system is suffering very often waits perhaps you can see it in
real time:

select chr(bitand(p1,-16777216)/16777215)||
     chr(bitand(p1,16711680)/65535) "Lock"
from v$session_wait
where event = 'enqueue';


Best regards

On 6/13/06, Nigel Thomas <nigel@xxxxxxxxxxxxxx> wrote: 

  Can the list think of a good reason why statspack would show top event
as enqueue (26,380 secs in a 15.4 minute period) while at the same time
showing the top 10 enqueue activities adding up to 20 secs only?

Possibly of relevance
1) I'm wondering if the missing time could be related to AQ's 'skip
locked' behaviour somehow. We have a couple of heavily used queues, one for
requests and one for replies; the reply queue is polled by the client...

2) The only possibly relevant DB change I can think of prior to this
happening is the addition of a couple of (as yet unused) tables with
unindexed FK. These tables aren't used by the test (but the tables they
reference are inserted and updated heavily - not deleted). Sadly I'm not
allowed to add indexes to exclude this at the moment.

Thanks and regards Nigel

(Three node 9.2.0.5 RAC on Linux)

Top 10 Timed Events
~~~~~~~~~~~~~~~~~~                                                     %
Total
Event                                               Waits    Time (s) Ela
Time
-------------------------------------------- ------------ -----------
--------
enqueue                                            95,747      26,380
75.60
buffer busy global cache                           88,063       2,852
8.17
global cache null to x                             74,094       1,075
3.08
CPU time                                                          976
2.80
latch free                                        154,687         952
2.73
db file sequential read                           164,339         914
2.62
buffer busy waits                                  74,369         860
2.46
global cache cr request                           381,071         378
1.08
buffer busy global CR                             131,858         201
.58
global cache open x                                38,603          89
.25

Enqueue activity:
Eq     Requests    Succ Gets Failed Gets       Waits   Time (ms)     Time
(s)
-- ------------ ------------ ----------- ----------- -------------
------------
TX      128,230       27,220     100,985      21,083
.93           20
US            7            7           0           7         13.29
0
FB           54           54           0          38          1.08
0
HW          122          122           0          18          1.17
0
CF        1,388        1,388           0          16          1.00
0
SQ          129          129           0           4          2.50
0
TM      247,657      247,655           0           9
.89            0
DR            1            1           0           1          3.00
0
TA            3            3           0           3
.33            0





--
Domingo Diaz Saenz

Other related posts:

  1. Home
  2. oracle-l
  3. Archive
  4. 06-2006