db file sequential read waits on INSERT into non-indexed partitioned table
- From: "Wayne Adams" <work@xxxxxxxxxxxxxx>
- To: <oracle-l@xxxxxxxxxxxxx>
- Date: Mon, 26 Sep 2011 12:57:00 -0700
Trying to understand what is affecting the performance of some INSERTs that
we have going on.
Database is a 3 node 10.2.0.3 RAC database.
Table is a range-hash partitioned table (date range, 128 partition numeric
hash), with no indexes or LOBs. Tablespace is a locally SYSTEM managed ASSM
bigfile tablespace.
This particular INSERT is a single threaded FORALL INSERT with an arraysize
of 50000.
Tkprof output
-----------------
INSERT INTO STAGE_TRANS_WAYNE
VALUES
(:B1 ,:B2 ,:B3 ,:B4 ,:B5 ,:B6 ,:B7 ,:B8 ,:B9 ,:B10 ,:B11 ,:B12 ,:B13 ,:B14
,
:B15 ,:B16 ,:B17 ,:B18 ,:B19 ,:B20 ,:B21 ,:B22 ,:B23 ,:B24 ,:B25 ,:B26 ,
:B27 ,:B28 ,:B29 ,:B30 ,:B31 ,:B32 ,:B33 ,:B34 ,:B35 ,:B36 ,:B37 ,:B38 ,
:B39 ,:B40 ,:B41 ,:B42 ,:B43 ,:B44 ,:B45 ,:B46 ,:B47 ,:B48 ,:B49 ,:B50 ,
:B51 ,:B52 ,:B53 ,:B54 ,:B55 ,:B56 ,:B57 ,:B58 ,:B59 ,:B60 ,:B61 ,:B62 ,
:B63 ,:B64 ,:B65 ,:B66 ,:B67 ,:B68 ,:B69 ,:B70 ,:B71 ,:B72 ,:B73 ,:B74 ,
:B75 ,:B76 ,:B77 ,:B78 ,:B79 ,:B80 ,:B81 ,:B82 ,:B83 ,:B84 ,:B85 ,:B86 ,
:B87 ,:B88 ,:B89 ,:B90 ,:B91 ,:B92 ,:B93 ,:B94 ,:B95 ,:B96 ,:B97 ,:B98 ,
:B99 ,:B100 ,:B101 ,:B102 ,:B103 ,:B104 ,:B105 ,:B106 ,:B107 ,:B108 ,:B109
,
:B110 ,:B111 ,:B112 ,:B113 ,:B114 ,:B115 ,:B116 ,:B117 ,:B118 ,:B119
,:B120
,:B121 ,:B122 ,:B123 ,:B124 ,:B125 ,:B126 ,:B127 ,:B128 ,:B129 ,:B130 ,
:B131 ,:B132 ,:B133 ,:B134 ,:B135 ,:B136 ,:B137 ,:B138 ,:B139 ,:B140
,:B141
,:B142 ,:B143 ,:B144 ,:B145 ,:B146 ,:B147 ,:B148 ,:B149 ,:B150 ,:B151 ,
:B152 ,:B153 ,:B154 ,:B155 ,:B156 ,:B157 ,:B158 ,:B159 ,:B160 ,:B161
,:B162
,:B163 ,:B164 ,:B165 ,:B166 ,:B167 ,:B168 ,:B169 ,:B170 ,:B171 ,:B172 ,
:B173 ,:B174 ,:B175 ,:B176 ,:B177 ,:B178 ,:B179 ,:B180 ,:B181 ,:B182
,:B183
,:B184 ,:B185 ,:B186 ,:B187 ,:B188 ,:B189 ,:B190 ,:B191 ,:B192 ,:B193 ,
:B194 ,:B195 ,:B196 ,:B197 ,:B198 ,:B199 ,:B200 ,:B201 ,:B202 ,:B203
,:B204
,:B205 ,:B206 ,:B207 ,:B208 ,:B209 ,:B210 ,:B211 ,:B212 ,:B213 ,:B214 ,
:B215 ,:B216 ,:B217 ,:B218 ,:B219 ,:B220 ,:B221 ,:B222 ,:B223 ,:B224
,:B225
,:B226 ,:B227 ,:B228 ,:B229 ,:B230 ,:B231 ,:B232 ,:B233 ,:B234 ,:B235 )
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 1 0.00 0.00 0 0 0
0
Execute 2 14.51 20.48 6647 61385 207160
50877
Fetch 0 0.00 0.00 0 0 0
0
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 3 14.51 20.48 6647 61385 207160
50877
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 145 (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
---------------------------------------- Waited ----------
------------
enq: FB - contention 395 0.01
0.35
gc current grant 2-way 4187 0.00
1.02
db file sequential read 6639 0.02
3.53
enq: HW - contention 1331 0.01
0.94
enq: TT - contention 1 0.00
0.00
row cache lock 780 0.00
0.18
latch: ges resource hash list 7 0.00
0.00
KJC: Wait for msg sends to complete 4 0.00
0.00
latch free 1 0.00
0.00
****************************************************************************
****
Sample of Trace Output
----------------
WAIT #12: nam='db file sequential read' ela= 200 file#=9 block#=12234401
blocks=1 obj#=192843 tim=1286157671284413
WAIT #12: nam='gc current grant 2-way' ela= 2199 p1=9 p2=12234402
p3=33554433 obj#=192843 tim=1286157671288826
WAIT #12: nam='db file sequential read' ela= 244 file#=9 block#=12234402
blocks=1 obj#=192843 tim=1286157671289192
WAIT #12: nam='gc current grant 2-way' ela= 261 p1=9 p2=12234403 p3=33554433
obj#=192843 tim=1286157671289918
WAIT #12: nam='db file sequential read' ela= 305 file#=9 block#=12234403
blocks=1 obj#=192843 tim=1286157671290276
WAIT #12: nam='gc current grant 2-way' ela= 224 p1=9 p2=12234404 p3=33554433
obj#=192843 tim=1286157671291017
WAIT #12: nam='db file sequential read' ela= 417 file#=9 block#=12234404
blocks=1 obj#=192843 tim=1286157671291503
WAIT #12: nam='gc current grant 2-way' ela= 191 p1=9 p2=12234405 p3=33554433
obj#=192843 tim=1286157671291880
WAIT #12: nam='db file sequential read' ela= 234 file#=9 block#=12234405
blocks=1 obj#=192843 tim=1286157671292203
WAIT #12: nam='gc current grant 2-way' ela= 194 p1=9 p2=12234406 p3=33554433
obj#=192843 tim=1286157671292646
WAIT #12: nam='db file sequential read' ela= 1080 file#=9 block#=12234406
blocks=1 obj#=192843 tim=1286157671293777
WAIT #12: nam='gc current grant 2-way' ela= 168 p1=9 p2=12234407 p3=33554433
obj#=192843 tim=1286157671294260
WAIT #12: nam='db file sequential read' ela= 264 file#=9 block#=12234407
blocks=1 obj#=192843 tim=1286157671294583
WAIT #12: nam='gc current grant 2-way' ela= 198 p1=9 p2=12234408 p3=33554433
obj#=192843 tim=1286157671294989
WAIT #12: nam='db file sequential read' ela= 1082 file#=9 block#=12234408
blocks=1 obj#=192843 tim=1286157671296201
WAIT #12: nam='enq: FB - contention' ela= 760 name|mode=1178730502
tablespace #=9 dba=12235244 obj#=192843 tim=1286157671300116
WAIT #12: nam='gc current grant 2-way' ela= 420 p1=9 p2=12235289 p3=33554433
obj#=192783 tim=1286157671300857
WAIT #12: nam='db file sequential read' ela= 8455 file#=9 block#=12235289
blocks=1 obj#=192783 tim=1286157671309374
WAIT #12: nam='gc current grant 2-way' ela= 321 p1=9 p2=12235290 p3=33554433
obj#=192783 tim=1286157671310115
WAIT #12: nam='db file sequential read' ela= 3103 file#=9 block#=12235290
blocks=1 obj#=192783 tim=1286157671313341
Since this process is the only process doing any inserts into this table and
there are no indexes on the table, I'm puzzled as to why there are "db file
sequential read" and "enq:HW - contention". Not really even sure why it
needs the "gc current grant 2-way".
I looked at some of the objects being read, and I believe they are all the
subpartitions of the table.
Thanks in advance!
Wayne Adams
Senior Oracle Consultant
--
//www.freelists.org/webpage/oracle-l
Other related posts:
