Strange - Inserts first slow, then fast after index drop and recreate
Hello,
I have a table with over 1,250,000,000 rows on Oracle 11.1.0.7, Linux. It had 4 global, not partitioned indexes. Inserts into this table were very slow - lots of db file sequential reads, each one taking on average 0.009 second (from tkprof) - not bad, but the overall performance was bad - so I dropped & recreated primary key index (3 columns in this index) and dropped permanently the other 3 indexes. As a consequence, total number of db file sequential reads decreased about 4 times (I expected that - now there is only 1, not 4 indexes) but not only that - the avarage db file sequential read time dropped to just 0.0014 second !!!
Upon further investigation, I found in traces, that BEFORE the drop & recreate, each db file sequential read was reading totally different ("random") blocks, and AFTER the drop & recreate, blocks accessed by db file sequential reads are almost sequentially ordered (which allows for storage array caching and I think that's why I get 0.0014 instead of 0.009)! My question is - HOW DID IT HAPPEN? Why index rebuild helped so much? Was the index fragmented? And maybe PCTFREE of 10%, which I recreated index with, helped and there are no index block splits now (but will appear in the future)?
Important notes - the result set which I insert is and always was ordered by table PK index columns. Parameter FILESYSTEMIO_OPTIONS is set to SETALL, so it's not OS cache (I presume) which makes my reads faster (because I have Direct IO).
Below is an extract from trace file (waits for one single Insert operation):
-->> BEFORE:
WAIT #12: nam='db file sequential read' ela= 35089 file#=15 block#=20534014 blocks=1 obj#=64560 tim=1294827907110090
WAIT #12: nam='db file sequential read' ela= 6434 file#=15 block#=61512424 blocks=1 obj#=64560 tim=1294827907116799
WAIT #12: nam='db file sequential read' ela= 7961 file#=15 block#=33775666 blocks=1 obj#=64560 tim=1294827907124874
WAIT #12: nam='db file sequential read' ela= 16681 file#=15 block#=60785827 blocks=1 obj#=64560 tim=1294827907143821
WAIT #12: nam='db file sequential read' ela= 2380 file#=15 block#=60785891 blocks=1 obj#=64560 tim=1294827907147000
WAIT #12: nam='db file sequential read' ela= 4219 file#=15 block#=33775730 blocks=1 obj#=64560 tim=1294827907151553
WAIT #12: nam='db file sequential read' ela= 7218 file#=15 block#=58351090 blocks=1 obj#=64560 tim=1294827907158922
WAIT #12: nam='db file sequential read' ela= 6140 file#=15 block#=20919908 blocks=1 obj#=64560 tim=1294827907165194
WAIT #12: nam='db file sequential read' ela= 542 file#=15 block#=60637720 blocks=1 obj#=64560 tim=1294827907165975
WAIT #12: nam='db file sequential read' ela= 13736 file#=15 block#=33350753 blocks=1 obj#=64560 tim=1294827907179807
WAIT #12: nam='db file sequential read' ela= 57465 file#=15 block#=59840995 blocks=1 obj#=64560 tim=1294827907237569
WAIT #12: nam='db file sequential read' ela= 20077 file#=15 block#=11266833 blocks=1 obj#=64560 tim=1294827907257879
WAIT #12: nam='db file sequential read' ela= 10642 file#=15 block#=34506477 blocks=1 obj#=64560 tim=1294827907268867
WAIT #12: nam='db file sequential read' ela= 5393 file#=15 block#=20919972 blocks=1 obj#=64560 tim=1294827907275227
WAIT #12: nam='db file sequential read' ela= 15308 file#=15 block#=61602921 blocks=1 obj#=64560 tim=1294827907291203
WAIT #12: nam='db file sequential read' ela= 11228 file#=15 block#=34032720 blocks=1 obj#=64560 tim=1294827907303261
WAIT #12: nam='db file sequential read' ela= 7885 file#=15 block#=60785955 blocks=1 obj#=64560 tim=1294827907311867
WAIT #12: nam='db file sequential read' ela= 6652 file#=15 block#=19778448 blocks=1 obj#=64560 tim=1294827907319158
WAIT #12: nam='db file sequential read' ela= 8735 file#=15 block#=34634855 blocks=1 obj#=64560 tim=1294827907328770
WAIT #12: nam='db file sequential read' ela= 14235 file#=15 block#=61411940 blocks=1 obj#=64560 tim=1294827907343804
WAIT #12: nam='db file sequential read' ela= 7173 file#=15 block#=33350808 blocks=1 obj#=64560 tim=1294827907351214
WAIT #12: nam='db file sequential read' ela= 8033 file#=15 block#=60493866 blocks=1 obj#=64560 tim=1294827907359424
WAIT #12: nam='db file sequential read' ela= 14654 file#=15 block#=19004731 blocks=1 obj#=64560 tim=1294827907374257
WAIT #12: nam='db file sequential read' ela= 6116 file#=15 block#=34565376 blocks=1 obj#=64560 tim=1294827907380647
WAIT #12: nam='db file sequential read' ela= 6203 file#=15 block#=20920100 blocks=1 obj#=64560 tim=1294827907387054
WAIT #12: nam='db file sequential read' ela= 50627 file#=15 block#=61602985 blocks=1 obj#=64560 tim=1294827907437838
WAIT #12: nam='db file sequential read' ela= 13752 file#=15 block#=33351193 blocks=1 obj#=64560 tim=1294827907451875
WAIT #12: nam='db file sequential read' ela= 6883 file#=15 block#=58686059 blocks=1 obj#=64560 tim=1294827907459551
WAIT #12: nam='db file sequential read' ela= 13284 file#=15 block#=19778511 blocks=1 obj#=64560 tim=1294827907473558
WAIT #12: nam='db file sequential read' ela= 16678 file#=15 block#=34226211 blocks=1 obj#=64560 tim=1294827907493010
WAIT #12: nam='db file sequential read' ela= 9565 file#=15 block#=61123267 blocks=1 obj#=64560 tim=1294827907507419
WAIT #12: nam='db file sequential read' ela= 6893 file#=15 block#=20920164 blocks=1 obj#=64560 tim=1294827907515073
WAIT #12: nam='db file sequential read' ela= 9817 file#=15 block#=61603049 blocks=1 obj#=64560 tim=1294827907525598
WAIT #12: nam='db file sequential read' ela= 4691 file#=15 block#=33351248 blocks=1 obj#=64560 tim=1294827907530960
WAIT #12: nam='db file sequential read' ela= 25983 file#=15 block#=58351154 blocks=1 obj#=64560 tim=1294827907557661
WAIT #12: nam='db file sequential read' ela= 7402 file#=15 block#=5096358 blocks=1 obj#=64560 tim=1294827907565927
WAIT #12: nam='db file sequential read' ela= 7964 file#=15 block#=61603113 blocks=1 obj#=64560 tim=1294827907574570
WAIT #12: nam='db file sequential read' ela= 32776 file#=15 block#=33549538 blocks=1 obj#=64560 tim=1294827907608063
WAIT #12: nam='db file sequential read' ela= 5674 file#=15 block#=60493930 blocks=1 obj#=64560 tim=1294827907614596
WAIT #12: nam='db file sequential read' ela= 9525 file#=15 block#=61512488 blocks=1 obj#=64560 tim=1294827907625007
WAIT #12: nam='db file sequential read' ela= 15729 file#=15 block#=33549602 blocks=1 obj#=64560 tim=1294827907641538
WAIT #12: nam='db file sequential read' ela= 11510 file#=15 block#=60902458 blocks=1 obj#=64560 tim=1294827907653819
WAIT #12: nam='db file sequential read' ela= 26431 file#=15 block#=59841058 blocks=1 obj#=64560 tim=1294827907680940
WAIT #12: nam='db file sequential read' ela= 9196 file#=15 block#=33350809 blocks=1 obj#=64560 tim=1294827907690434
WAIT #12: nam='db file sequential read' ela= 7745 file#=15 block#=60296291 blocks=1 obj#=64560 tim=1294827907698353
WAIT #12: nam='db file sequential read' ela= 429 file#=15 block#=61603177 blocks=1 obj#=64560 tim=1294827907698953
WAIT #12: nam='db file sequential read' ela= 8459 file#=15 block#=33351194 blocks=1 obj#=64560 tim=1294827907707695
WAIT #12: nam='db file sequential read' ela= 25998 file#=15 block#=49598412 blocks=1 obj#=64560 tim=1294827907733890
*** 2011-01-12 11:25:07.742
WAIT #12: nam='db file sequential read' ela= 7988 file#=15 block#=11357900 blocks=1 obj#=64560 tim=1294827907742683
WAIT #12: nam='db file sequential read' ela= 10066 file#=15 block#=61512552 blocks=1 obj#=64560 tim=1294827907753540
WAIT #12: nam='db file sequential read' ela= 8400 file#=15 block#=33775858 blocks=1 obj#=64560 tim=1294827907762668
WAIT #12: nam='db file sequential read' ela= 11750 file#=15 block#=60636761 blocks=1 obj#=64560 tim=1294827907774667
WAIT #12: nam='db file sequential read' ela= 16933 file#=15 block#=20533183 blocks=1 obj#=64560 tim=1294827907791839
WAIT #12: nam='db file sequential read' ela= 8895 file#=15 block#=61603241 blocks=1 obj#=64560 tim=1294827907801047
WAIT #12: nam='db file sequential read' ela= 12685 file#=15 block#=33775922 blocks=1 obj#=64560 tim=1294827907813913
WAIT #12: nam='db file sequential read' ela= 12664 file#=15 block#=60493994 blocks=1 obj#=64560 tim=1294827907827379
WAIT #12: nam='db file sequential read' ela= 8271 file#=15 block#=19372356 blocks=1 obj#=64560 tim=1294827907835881
WAIT #12: nam='db file sequential read' ela= 10825 file#=15 block#=59338524 blocks=1 obj#=64560 tim=1294827907847439
WAIT #12: nam='db file sequential read' ela= 13086 file#=15 block#=49440992 blocks=1 obj#=64793 tim=1294827907862022
WAIT #12: nam='db file sequential read' ela= 16491 file#=15 block#=32853984 blocks=1 obj#=64793 tim=1294827907879282
WAIT #12: nam='db file sequential read' ela= 9349 file#=15 block#=60133021 blocks=1 obj#=64793 tim=1294827907888849
WAIT #12: nam='db file sequential read' ela= 5680 file#=15 block#=20370585 blocks=1 obj#=64793 tim=1294827907895281
WAIT #12: nam='db file sequential read' ela= 34021 file#=15 block#=58183834 blocks=1 obj#=64793 tim=1294827907930014
WAIT #12: nam='db file sequential read' ela= 8574 file#=15 block#=32179028 blocks=1 obj#=64793 tim=1294827907938813
WAIT #12: nam='db file sequential read' ela= 10862 file#=15 block#=49402735 blocks=1 obj#=64793 tim=1294827907949821
WAIT #12: nam='db file sequential read' ela= 4501 file#=15 block#=11270933 blocks=1 obj#=64793 tim=1294827907954533
WAIT #12: nam='db file sequential read' ela= 9936 file#=15 block#=61007523 blocks=1 obj#=64793 tim=1294827907964616
WAIT #12: nam='db file sequential read' ela= 7631 file#=15 block#=34399970 blocks=1 obj#=64793 tim=1294827907972457
WAIT #12: nam='db file sequential read' ela= 6162 file#=15 block#=60305187 blocks=1 obj#=64793 tim=1294827907978797
WAIT #12: nam='db file sequential read' ela= 8555 file#=15 block#=20912586 blocks=1 obj#=64793 tim=1294827907987532
WAIT #12: nam='db file sequential read' ela= 9499 file#=15 block#=61007587 blocks=1 obj#=64793 tim=1294827907997296
WAIT #12: nam='db file sequential read' ela= 23690 file#=15 block#=19769014 blocks=1 obj#=64793 tim=1294827908024105
WAIT #12: nam='db file sequential read' ela= 7081 file#=15 block#=61314072 blocks=1 obj#=64793 tim=1294827908031968
WAIT #12: nam='db file sequential read' ela= 31727 file#=15 block#=34026602 blocks=1 obj#=64793 tim=1294827908063914
WAIT #12: nam='db file sequential read' ela= 4932 file#=15 block#=60905313 blocks=1 obj#=64793 tim=1294827908069052
WAIT #12: nam='db file sequential read' ela= 6616 file#=15 block#=20912650 blocks=1 obj#=64793 tim=1294827908075835
WAIT #12: nam='db file sequential read' ela= 8443 file#=15 block#=33781968 blocks=1 obj#=64793 tim=1294827908084594
WAIT #12: nam='db file sequential read' ela= 22291 file#=15 block#=60641967 blocks=1 obj#=64793 tim=1294827908107052
WAIT #12: nam='db file sequential read' ela= 6610 file#=15 block#=18991774 blocks=1 obj#=64793 tim=1294827908113879
WAIT #12: nam='db file sequential read' ela= 6493 file#=15 block#=34622382 blocks=1 obj#=64793 tim=1294827908120535
WAIT #12: nam='db file sequential read' ela= 5028 file#=15 block#=20912714 blocks=1 obj#=64793 tim=1294827908125861
WAIT #12: nam='db file sequential read' ela= 11834 file#=15 block#=61679845 blocks=1 obj#=64793 tim=1294827908137858
WAIT #12: nam='db file sequential read' ela= 4261 file#=15 block#=34498166 blocks=1 obj#=64793 tim=1294827908142305
WAIT #12: nam='db file sequential read' ela= 19267 file#=15 block#=60905377 blocks=1 obj#=64793 tim=1294827908161695
WAIT #12: nam='db file sequential read' ela= 14108 file#=15 block#=19769078 blocks=1 obj#=64793 tim=1294827908176046
WAIT #12: nam='db file sequential read' ela= 4128 file#=15 block#=33781465 blocks=1 obj#=64793 tim=1294827908180396
WAIT #12: nam='db file sequential read' ela= 9986 file#=15 block#=61007651 blocks=1 obj#=64793 tim=1294827908190535
WAIT #12: nam='db file sequential read' ela= 8907 file#=15 block#=20912778 blocks=1 obj#=64793 tim=1294827908199614
WAIT #12: nam='db file sequential read' ela= 12023 file#=15 block#=34230838 blocks=1 obj#=64793 tim=1294827908211852
WAIT #12: nam='db file sequential read' ela= 29837 file#=15 block#=60905441 blocks=1 obj#=64793 tim=1294827908241853
WAIT #12: nam='db file sequential read' ela= 5989 file#=15 block#=60133085 blocks=1 obj#=64793 tim=1294827908248065
WAIT #12: nam='db file sequential read' ela= 74172 file#=15 block#=33357369 blocks=1 obj#=64793 tim=1294827908322391
WAIT #12: nam='db file sequential read' ela= 5443 file#=15 block#=60498917 blocks=1 obj#=64793 tim=1294827908328064
WAIT #12: nam='db file sequential read' ela= 4645 file#=15 block#=20912842 blocks=1 obj#=64793 tim=1294827908332912
WAIT #12: nam='db file sequential read' ela= 13595 file#=15 block#=61679909 blocks=1 obj#=64793 tim=1294827908346618
WAIT #12: nam='db file sequential read' ela= 9120 file#=15 block#=58356376 blocks=1 obj#=64793 tim=1294827908355975
WAIT #12: nam='db file sequential read' ela= 3186 file#=15 block#=19385867 blocks=1 obj#=64793 tim=1294827908359374
WAIT #12: nam='db file sequential read' ela= 5114 file#=15 block#=61589533 blocks=1 obj#=64793 tim=1294827908364630
WAIT #12: nam='db file sequential read' ela= 42263 file#=15 block#=33356474 blocks=1 obj#=64793 tim=1294827908407045
WAIT #12: nam='db file sequential read' ela= 10683 file#=15 block#=58183898 blocks=1 obj#=64793 tim=1294827908417994
WAIT #12: nam='db file sequential read' ela= 10284 file#=15 block#=20529486 blocks=1 obj#=64793 tim=1294827908429134
WAIT #12: nam='db file sequential read' ela= 12544 file#=15 block#=60498981 blocks=1 obj#=64793 tim=1294827908441945
WAIT #12: nam='db file sequential read' ela= 8311 file#=15 block#=33191548 blocks=1 obj#=64793 tim=1294827908451011
WAIT #12: nam='db file sequential read' ela= 4261 file#=15 block#=59083610 blocks=1 obj#=64793 tim=1294827908455902
WAIT #12: nam='db file sequential read' ela= 4653 file#=15 block#=18991837 blocks=1 obj#=64793 tim=1294827908461264
WAIT #12: nam='db file sequential read' ela= 4905 file#=15 block#=34685472 blocks=1 obj#=64793 tim=1294827908466897
WAIT #12: nam='db file sequential read' ela= 12360 file#=15 block#=61775403 blocks=1 obj#=64793 tim=1294827908480080
WAIT #12: nam='db file sequential read' ela= 6956 file#=15 block#=58921225 blocks=1 obj#=64793 tim=1294827908487704
WAIT #12: nam='db file sequential read' ela= 6068 file#=15 block#=19769142 blocks=1 obj#=64793 tim=1294827908494608
WAIT #12: nam='db file sequential read' ela= 5249 file#=15 block#=33781528 blocks=1 obj#=64793 tim=1294827908500666
WAIT #12: nam='db file sequential read' ela= 6013 file#=15 block#=60905505 blocks=1 obj#=64793 tim=1294827908507366
WAIT #12: nam='db file sequential read' ela= 3014 file#=15 block#=20912970 blocks=1 obj#=64793 tim=1294827908511019
WAIT #12: nam='db file sequential read' ela= 3636 file#=15 block#=33781591 blocks=1 obj#=64793 tim=1294827908515425
WAIT #12: nam='db file sequential read' ela= 12226 file#=15 block#=58183962 blocks=1 obj#=64793 tim=1294827908528268
WAIT #12: nam='db file sequential read' ela= 7635 file#=15 block#=60499173 blocks=1 obj#=64793 tim=1294827908536613
WAIT #12: nam='db file sequential read' ela= 7364 file#=15 block#=11270996 blocks=1 obj#=64793 tim=1294827908544203
WAIT #12: nam='db file sequential read' ela= 5452 file#=15 block#=34622446 blocks=1 obj#=64793 tim=1294827908550475
WAIT #12: nam='db file sequential read' ela= 9734 file#=15 block#=20913034 blocks=1 obj#=64793 tim=1294827908561029
WAIT #12: nam='db file sequential read' ela= 14077 file#=15 block#=61679973 blocks=1 obj#=64793 tim=1294827908575440
WAIT #12: nam='db file sequential read' ela= 9694 file#=15 block#=34550681 blocks=1 obj#=64793 tim=1294827908585311
WAIT #12: nam='db file sequential read' ela= 6753 file#=15 block#=61007715 blocks=1 obj#=64793 tim=1294827908592228
WAIT #12: nam='db file sequential read' ela= 12577 file#=15 block#=19769206 blocks=1 obj#=64793 tim=1294827908604943
WAIT #12: nam='db file sequential read' ela= 609 file#=15 block#=61589534 blocks=1 obj#=64793 tim=1294827908605735
WAIT #12: nam='db file sequential read' ela= 6267 file#=15 block#=33356538 blocks=1 obj#=64793 tim=1294827908612148
WAIT #12: nam='db file sequential read' ela= 7876 file#=15 block#=58184026 blocks=1 obj#=64793 tim=1294827908620164
WAIT #12: nam='db file sequential read' ela= 14058 file#=15 block#=32767835 blocks=1 obj#=80883 tim=1294827908634546
WAIT #12: nam='db file sequential read' ela= 9798 file#=15 block#=58504373 blocks=1 obj#=80883 tim=1294827908644575
WAIT #12: nam='db file sequential read' ela= 11081 file#=15 block#=11118811 blocks=1 obj#=80883 tim=1294827908655908
WAIT #12: nam='db file sequential read' ela= 6249 file#=15 block#=58087798 blocks=1 obj#=80883 tim=1294827908662451
WAIT #12: nam='db file sequential read' ela= 9513 file#=15 block#=33331129 blocks=1 obj#=80883 tim=1294827908672904
WAIT #12: nam='db file sequential read' ela= 4648 file#=15 block#=60301818 blocks=1 obj#=80883 tim=1294827908677736
WAIT #12: nam='db file sequential read' ela= 6147 file#=15 block#=20523119 blocks=1 obj#=80883 tim=1294827908684075
WAIT #12: nam='db file sequential read' ela= 59531 file#=15 block#=61016570 blocks=1 obj#=80883 tim=1294827908743795
*** 2011-01-12 11:25:08.752
WAIT #12: nam='db file sequential read' ela= 8787 file#=15 block#=33770842 blocks=1 obj#=80883 tim=1294827908752846
WAIT #12: nam='db file sequential read' ela= 9858 file#=15 block#=60895354 blocks=1 obj#=80883 tim=1294827908762960
WAIT #12: nam='db file sequential read' ela= 11237 file#=15 block#=19369506 blocks=1 obj#=80883 tim=1294827908775138
WAIT #12: nam='db file sequential read' ela= 5838 file#=15 block#=34229712 blocks=1 obj#=80883 tim=1294827908782100
WAIT #12: nam='db file sequential read' ela= 6518 file#=15 block#=61221772 blocks=1 obj#=80883 tim=1294827908789403
WAIT #12: nam='db file sequential read' ela= 9946 file#=15 block#=20523183 blocks=1 obj#=80883 tim=1294827908800089
WAIT #12: nam='db file sequential read' ela= 16699 file#=15 block#=61016634 blocks=1 obj#=80883 tim=1294827908817077
WAIT #12: nam='db file sequential read' ela= 15215 file#=15 block#=33770900 blocks=1 obj#=80883 tim=1294827908832934
WAIT #12: nam='db file sequential read' ela= 8403 file#=15 block#=60895418 blocks=1 obj#=80883 tim=1294827908842317
WAIT #12: nam='db file sequential read' ela= 8927 file#=15 block#=18950791 blocks=1 obj#=80883 tim=1294827908852190
WAIT #12: nam='db file sequential read' ela= 4382 file#=15 block#=34493493 blocks=1 obj#=80883 tim=1294827908856821
WAIT #12: nam='db file sequential read' ela= 9356 file#=15 block#=61324964 blocks=1 obj#=80883 tim=1294827908866337
WAIT #12: nam='db file sequential read' ela= 10575 file#=15 block#=20883018 blocks=1 obj#=80883 tim=1294827908877102
WAIT #12: nam='db file sequential read' ela= 16601 file#=15 block#=60502307 blocks=1 obj#=80883 tim=1294827908893926
WAIT #12: nam='db file sequential read' ela= 5236 file#=15 block#=33331193 blocks=1 obj#=80883 tim=1294827908899387
WAIT #12: nam='db file sequential read' ela= 9981 file#=15 block#=59830076 blocks=1 obj#=80883 tim=1294827908910427
WAIT #12: nam='db file sequential read' ela= 8100 file#=15 block#=19767805 blocks=1 obj#=80883 tim=1294827908918751
WAIT #12: nam='db file sequential read' ela= 12492 file#=15 block#=67133332 blocks=1 obj#=80883 tim=1294827908931732
WAIT #12: nam='db file sequential read' ela= 5876 file#=15 block#=34229775 blocks=1 obj#=80883 tim=1294827908937859
WAIT #12: nam='db file sequential read' ela= 8741 file#=15 block#=61408244 blocks=1 obj#=80883 tim=1294827908948439
WAIT #12: nam='db file sequential read' ela= 8477 file#=15 block#=20523247 blocks=1 obj#=80883 tim=1294827908957099
WAIT #12: nam='db file sequential read' ela= 7947 file#=15 block#=61016698 blocks=1 obj#=80883 tim=1294827908965210
WAIT #12: nam='db file sequential read' ela= 2384 file#=15 block#=33331257 blocks=1 obj#=80883 tim=1294827908967773
WAIT #12: nam='db file sequential read' ela= 3585 file#=15 block#=59571985 blocks=1 obj#=80883 tim=1294827908971564
WAIT #12: nam='db file sequential read' ela= 7753 file#=15 block#=5099571 blocks=1 obj#=80883 tim=1294827908979647
WAIT #12: nam='db file sequential read' ela= 8205 file#=15 block#=61408308 blocks=1 obj#=80883 tim=1294827908988200
WAIT #12: nam='db file sequential read' ela= 7745 file#=15 block#=34229335 blocks=1 obj#=80883 tim=1294827908996129
WAIT #12: nam='db file sequential read' ela= 10942 file#=15 block#=61325028 blocks=1 obj#=80883 tim=1294827909007244
WAIT #12: nam='db file sequential read' ela= 6247 file#=15 block#=20523311 blocks=1 obj#=80883 tim=1294827909013706
WAIT #12: nam='db file sequential read' ela= 16188 file#=15 block#=60777362 blocks=1 obj#=80883 tim=1294827909030088
WAIT #12: nam='db file sequential read' ela= 16642 file#=15 block#=33528224 blocks=1 obj#=80883 tim=1294827909046971
WAIT #12: nam='db file sequential read' ela= 10118 file#=15 block#=60128498 blocks=1 obj#=80883 tim=1294827909057402
WAIT #12: nam='db file sequential read' ela= 10747 file#=15 block#=802317 blocks=1 obj#=64495 tim=1294827909069165
WAIT #12: nam='db file sequential read' ela= 4795 file#=15 block#=33079541 blocks=1 obj#=64560 tim=1294827909074367
WAIT #12: nam='db file sequential read' ela= 6822 file#=15 block#=20913098 blocks=1 obj#=64793 tim=1294827909081436
WAIT #12: nam='db file sequential read' ela= 10932 file#=15 block#=19369570 blocks=1 obj#=80883 tim=1294827909092607
-->>AFTER:
WAIT #23: nam='db file sequential read' ela= 16367 file#=15 block#=70434065 blocks=1 obj#=115059 tim=1295342220878947
WAIT #23: nam='db file sequential read' ela= 1141 file#=15 block#=70434066 blocks=1 obj#=115059 tim=1295342220880549
WAIT #23: nam='db file sequential read' ela= 456 file#=15 block#=70434067 blocks=1 obj#=115059 tim=1295342220881615
WAIT #23: nam='db file sequential read' ela= 689 file#=15 block#=70434068 blocks=1 obj#=115059 tim=1295342220882617
WAIT #23: nam='db file sequential read' ela= 495 file#=15 block#=70434069 blocks=1 obj#=115059 tim=1295342220883482
WAIT #23: nam='db file sequential read' ela= 419 file#=15 block#=70434070 blocks=1 obj#=115059 tim=1295342220884195
WAIT #23: nam='db file sequential read' ela= 149 file#=15 block#=70434071 blocks=1 obj#=115059 tim=1295342220884629
WAIT #23: nam='db file sequential read' ela= 161 file#=15 block#=70434072 blocks=1 obj#=115059 tim=1295342220885085
WAIT #23: nam='db file sequential read' ela= 146 file#=15 block#=70434073 blocks=1 obj#=115059 tim=1295342220885533
WAIT #23: nam='db file sequential read' ela= 188 file#=15 block#=70434074 blocks=1 obj#=115059 tim=1295342220886026
WAIT #23: nam='db file sequential read' ela= 181 file#=15 block#=70434075 blocks=1 obj#=115059 tim=1295342220886498
WAIT #23: nam='db file sequential read' ela= 303 file#=15 block#=70434076 blocks=1 obj#=115059 tim=1295342220887082
WAIT #23: nam='db file sequential read' ela= 550 file#=15 block#=70434077 blocks=1 obj#=115059 tim=1295342220887916
WAIT #23: nam='db file sequential read' ela= 163 file#=15 block#=70434078 blocks=1 obj#=115059 tim=1295342220888402
WAIT #23: nam='db file sequential read' ela= 200 file#=15 block#=70434079 blocks=1 obj#=115059 tim=1295342220888980
WAIT #23: nam='db file sequential read' ela= 134 file#=15 block#=70434080 blocks=1 obj#=115059 tim=1295342220889409
WAIT #23: nam='db file sequential read' ela= 157 file#=15 block#=70434081 blocks=1 obj#=115059 tim=1295342220889850
WAIT #23: nam='db file sequential read' ela= 5112 file#=15 block#=70434540 blocks=1 obj#=115059 tim=1295342220895272
WAIT #23: nam='db file sequential read' ela= 276 file#=15 block#=70434082 blocks=1 obj#=115059 tim=1295342220895640
*** 2011-01-18 10:17:00.898
WAIT #23: nam='db file sequential read' ela= 2936 file#=15 block#=70434084 blocks=1 obj#=115059 tim=1295342220898921
WAIT #23: nam='db file sequential read' ela= 1843 file#=15 block#=70434085 blocks=1 obj#=115059 tim=1295342220901233
WAIT #23: nam='db file sequential read' ela= 452 file#=15 block#=70434086 blocks=1 obj#=115059 tim=1295342220902050
WAIT #23: nam='db file sequential read' ela= 686 file#=15 block#=70434087 blocks=1 obj#=115059 tim=1295342220903031
WAIT #23: nam='db file sequential read' ela= 1582 file#=15 block#=70434088 blocks=1 obj#=115059 tim=1295342220904933
WAIT #23: nam='db file sequential read' ela= 179 file#=15 block#=70434089 blocks=1 obj#=115059 tim=1295342220905544
WAIT #23: nam='db file sequential read' ela= 426 file#=15 block#=70434090 blocks=1 obj#=115059 tim=1295342220906303
WAIT #23: nam='db file sequential read' ela= 138 file#=15 block#=70434091 blocks=1 obj#=115059 tim=1295342220906723
WAIT #23: nam='db file sequential read' ela= 3004 file#=15 block#=70434092 blocks=1 obj#=115059 tim=1295342220910053
WAIT #23: nam='db file sequential read' ela= 331 file#=15 block#=70434093 blocks=1 obj#=115059 tim=1295342220910765
WAIT #23: nam='db file sequential read' ela= 148 file#=15 block#=70434094 blocks=1 obj#=115059 tim=1295342220911236
WAIT #23: nam='db file sequential read' ela= 296 file#=15 block#=70434095 blocks=1 obj#=115059 tim=1295342220911836
WAIT #23: nam='db file sequential read' ela= 441 file#=15 block#=70434096 blocks=1 obj#=115059 tim=1295342220912581
WAIT #23: nam='db file sequential read' ela= 157 file#=15 block#=70434097 blocks=1 obj#=115059 tim=1295342220913038
WAIT #23: nam='db file sequential read' ela= 281 file#=15 block#=70434098 blocks=1 obj#=115059 tim=1295342220913603
WAIT #23: nam='db file sequential read' ela= 150 file#=15 block#=70434099 blocks=1 obj#=115059 tim=1295342220914048
WAIT #23: nam='db file sequential read' ela= 143 file#=15 block#=70434100 blocks=1 obj#=115059 tim=1295342220914498
WAIT #23: nam='db file sequential read' ela= 384 file#=15 block#=70434101 blocks=1 obj#=115059 tim=1295342220916907
WAIT #23: nam='db file sequential read' ela= 164 file#=15 block#=70434102 blocks=1 obj#=115059 tim=1295342220917458
WAIT #23: nam='db file sequential read' ela= 218 file#=15 block#=70434103 blocks=1 obj#=115059 tim=1295342220917962
WAIT #23: nam='db file sequential read' ela= 450 file#=15 block#=70434104 blocks=1 obj#=115059 tim=1295342220918698
WAIT #23: nam='db file sequential read' ela= 164 file#=15 block#=70434105 blocks=1 obj#=115059 tim=1295342220919159
WAIT #23: nam='db file sequential read' ela= 136 file#=15 block#=70434106 blocks=1 obj#=115059 tim=1295342220919598
WAIT #23: nam='db file sequential read' ela= 143 file#=15 block#=70434107 blocks=1 obj#=115059 tim=1295342220920041
WAIT #23: nam='db file sequential read' ela= 3091 file#=15 block#=70434108 blocks=1 obj#=115059 tim=1295342220925409