Last Friday, one of our production database experienced slowness in about 1 hours time period. During that period of time, there were 60+ blocking sessions. One of the blocking session was issuing the following statment:


update seq$ set
         increment$=:2,minvalue=:3,maxvalue=:4,cycle#=
         :5,order$=:6,cache=:7,highwater=:8,audit$=:9,
         flags=:10 where obj#=:1

This looks like having somthing to do with the sequences. Our team leader suggested that we should increase the cache size for two relevant sequences to proactively avoid the problem. I acutally opened a SR with Oracle, asking what this statment is doing. But they did not give direct answer to this specific question so far. On the other hand, the guy suggested we should increase the log file size to reduce "log file sync" wait event, which appears at the top of the wait event in our statspack report. His suggestions is obviously nonsense. He must have no idea about what "log file sync" wait event is. I am disappointed with the support.

To understand this update statment, I did a test today. I created a table T and a sequence T_SEQ:



labadmin@DB10G> desc t;
 Name                      Null?    Type
 ------------------------- -------- ------------------------------------
 ID                                 NUMBER
 VALUE                              VARCHAR2(20)

labadmin@DB10G> select * from user_sequences;

SEQUENCE_NAME          MIN_VALUE  MAX_VALUE INCREMENT_BY C O CACHE_SIZE LAST_NUMBER
--------------------- ---------- ---------- ------------ - - ---------- -----------
T_SEQ                          1 1.0000E+27            1 N N         20      904821

Then I have 20 sessions repeatedly executing the following insert statment simutaneouly:

isnert into t values(t_seq.nextval, 'xxxx');

I can observe there is one blocking sessions from time to time, for example:


                 Lock                Time Held
   SID Lock Type Requested Lock Held (minutes) Block
------ --------- --------- --------- --------- -----
   126 SQ        None      Exclusive         0 Yes
    99 SQ        Exclusive None              0 No
   124 SQ        Exclusive None              0 No
   123 SQ        Exclusive None              0 No
   128 SQ        Exclusive None              0 No
   158 SQ        Exclusive None              0 No
   109 SQ        Exclusive None              0 No
   159 SQ        Exclusive None              0 No
   130 SQ        Exclusive None              0 No
   114 SQ        Exclusive None              0 No
   131 SQ        Exclusive None              0 No
    ....k

I traced one of the 20 sessions, found that:



update seq$ set increment$=:2,minvalue=:3,maxvalue=:4,cycle#=:5,order$=:6,
  cache=:7,highwater=:8,audit$=:9,flags=:10
where
 obj#=:1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse      561      0.03       0.05          0          0          0           0
Execute    561      2.04       8.81          0        561       1132         561
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     1122      2.07       8.87          0        561       1132         561

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 2)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  UPDATE  SEQ$ (cr=1 pr=0 pw=0 time=339 us)
      1   INDEX UNIQUE SCAN I_SEQ1 (cr=1 pr=0 pw=0 time=40 us)(object id 102)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  latch: undo global data                         2        0.00          0.00
  latch: library cache                            1        0.01          0.01
  log buffer space                                8        1.00          6.39
  latch: library cache pin                        2        0.10          0.10
********************************************************************************

INSERT INTO T
VALUES
 (T_SEQ.NEXTVAL, :B1 )


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute   9026      8.51     351.24          0        211      21192        9026
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     9026      8.51     351.24          0        211      21192        9026

Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 102     (recursive depth: 1)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  enq: SQ - contention                          775        3.07        258.38
  latch: enqueue hash chains                      6        0.03          0.06
  log buffer space                               38        1.36         21.72
  latch: library cache pin                        3        0.01          0.01
  latch free                                     12        0.40          1.52
  free buffer waits                            1717        0.08         25.67
  latch: library cache                           10        0.15          0.62
  latch: In memory undo latch                     8        1.27          2.56
  latch: redo copy                                6        0.33          0.41
  buffer busy waits                              19        0.98          4.37
  latch: undo global data                         4        0.07          0.09
  enq: FB - contention                            2        0.82          0.98
  enq: TX - contention                            2        0.22          0.22
  enq: HW - contention                            2        0.45          0.45
  latch: session allocation                       1        0.00          0.00
********************************************************************************

So it can be seen that the "update seq$ ..." statement is a recursive sql issued by Oracle sys user to update dictionary table about sequence.

I did a further test:

I set the cache of t_seq to be 20, and I trace the session when executing following statement:

insert into t
select t_seq.nextval, 'qqq' from all_objects where rownum <=100;

I found the 'update seq$' statment executed 5 times.

Then I set the cache of t_seq to be 50, I found the 'update seq$' executed 2 time.

Thus, it looks like that every time that the cached sequence number is used up, Oracle should do the caching again and issue this statment to update dictionary table.

ITPub博客

Recursive SQL statement: update seq$

最新文章