某客户CPU暴增,且居高不下,通过gv$session发现一条insert造成大量的阻塞和等待,产生大量row chache lock、gc buffer busy acquire、read by other session等待。
通过row cache lock 等待的p1参数发现了大量的内存字典争用,问题点一定在这条SQL。
SQL> select parameter,gets,getmisses,MODIFICATIONS from v$rowcache where cache#=8
2 ;
PARAMETER GETS GETMISSES MODIFICATIONS
-------------------------------- ---------- ---------- -------------
dc_objects 4094971122 267859504 178935525
dc_object_grants 14043535 111310 0
查看SQL的执行信息:
SQL> @show_sql_stat.sql
Please enter the SQL_ID
gcwv8p1fhdq5y
Please enter the number of days before now for the BEGIN time
You can also enter n/24 for n hours before. Leave blank for 10 day before.
2
FLAG SNAP_ID INST_ID PHV EXECS READS READS_PER GETS GETS_PER ROWS_PROCESSED ROWS_PER ELAP_MS ELAP_PER_MS
--------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- -----------
16 10:00--11:00 42582 1 0 76177 125003 1.64095462 2516837 33.0393295 75312 .988644867 166019.923 2.17939697
16 11:00--12:00 42583 1 0 76369 116383 1.52395606 2528546 33.1095864 75572 .989563828 144544.053 1.89270585
16 12:00--13:00 42584 1 0 76806 130401 1.69779705 2562643 33.3651407 76087 .990638752 164757.422 2.14511135
16 13:00--14:00 42585 1 0 81768 138151 1.68954848 2712295 33.1706169 80901 .98939683 173485.561 2.12168038
16 14:00--15:00 42586 1 0 85599 140392 1.64011262 2843482 33.2186357 84579 .988083973 181246.597 2.11739152
16 15:00--16:00 42587 1 0 81204 135980 1.67454805 2700746 33.2587804 80342 .989384759 176946.616 2.17903818
16 16:00--17:00 42588 1 0 83322 148783 1.78563885 2777046 33.3290848 82466 .989726603 184043.691 2.20882469
16 17:00--18:00 42589 1 0 85418 147565 1.72756328 2831110 33.1441851 83420 .976609146 170502.746 1.99609855
==故障点==
16 18:00--19:00 42590 2 0 33332 190275 5.70847834 645854058 19376.3968 33298 .998979959 125881486 3776.59564
16 18:00--19:00 42590 1 0 36410 184902 5.07833013 1006132369 27633.4076 35895 .985855534 200037232 5494.019
16 19:00--20:00 42591 1 0 35535 336318 9.46441537 1697043717 47756.964 35253 .992064162 377126688 10612.8236
16 19:00--20:00 42591 2 0 50064 440842 8.80556887 686566330 13713.773 49821 .995146213 231919377 4632.45799
16 20:00--21:00 42592 1 0 27949 1172217 41.9412859 1460965664 52272.5559 27685 .990554224 194523801 6959.95568
16 20:00--21:00 42592 2 0 53479 336143 6.28551394 0 0 53114 .993174891 90139026 1685.50321
16 21:00--22:00 42593 2 0 29409 152829 5.19667449 12646129 430.008807 29265 .99510354 80984250.2 2753.72336
16 21:00--22:00 42593 1 0 49896 186091 3.72957752 0 0 49285 .987754529 157968653 3165.95825
16 22:00--23:00 42594 2 0 12981 202766 15.6202142 533337869 41086.0387 12756 .982666975 122982690 9474.05359
16 22:00--23:00 42594 1 0 36640 1696828 46.3108079 179624240 4902.4083 36432 .994323144 296228442 8084.83739
16 23:00--00:00 42595 2 0 17020 159116 9.34876616 2499583592 146861.551 16931 .994770858 61505400.7 3613.71332
16 23:00--00:00 42595 1 0 44648 1521072 34.0680882 1397284446 31295.5663 44311 .99245207 129625711 2903.28147
17 00:00--01:00 42596 1 0 22612 208794 9.23376968 1263948900 55897.2625 22301 .986246241 198296480 8769.52413
17 00:00--01:00 42596 2 0 40059 215890 5.38930078 0 0 39116 .976459722 117270283 2927.43911
17 01:00--02:00 42597 2 0 25935 440991 17.0037016 2278553369 87856.3088 25495 .983034509 13939109.9 537.463271
17 01:00--02:00 42597 1 0 89672 84012 .936881078 687759735 7669.72673 88935 .991781158 25419993 283.477484
17 02:00--03:00 42598 1 0 80526 68779 .85412165 0 0 79371 .985656806 20952841.6 260.199707
17 02:00--03:00 42598 2 0 26005 39114 1.50409537 0 0 25942 .997577389 6151055.74 236.53358
17 03:00--04:00 42599 1 0 67907 126845 1.86792231 0 0 67310 .991208565 15298949.8 225.292676
17 03:00--04:00 42599 2 0 33695 103120 3.06039472 2393851734 71044.7168 33593 .996972845 13063994.7 387.713155
17 04:00--05:00 42600 2 0 18725 233086 12.4478505 436491535 23310.6294 18283 .976395194 25373479.5 1355.05898
17 04:00--05:00 42600 1 0 65799 181021 2.75112084 0 0 65339 .993009012 40465816.8 614.991365
17 05:00--06:00 42601 2 0 11586 240541 20.7613499 7590 .655100984 11518 .994130848 41397299.9 3573.04505
17 05:00--06:00 42601 1 0 22702 379459 16.7147828 1845086167 81274.1682 22586 .994890318 123387696 5435.10248
17 06:00--07:00 42602 2 0 24660 30402 1.23284672 824610 33.4391727 24578 .996674777 59451.063 2.41082981
17 06:00--07:00 42602 1 0 54276 59060 1.08814209 1802838 33.2161176 53579 .987158228 102683.106 1.89186945
17 07:00--08:00 42603 1 0 56152 78166 1.39204303 1846615 32.8860058 55077 .980855535 107619.737 1.91657888
17 08:00--09:00 42604 1 0 60410 95884 1.58722066 2000044 33.1078298 58735 .972272803 139223.025 2.30463541
17 09:00--10:00 42605 1 0 20664 225686 10.9216996 1596009173 77236.2163 20453 .989789005 49919182 2415.756
17 09:00--10:00 42605 2 0 12895 123104 9.54664599 1280456496 99298.6813 12852 .996665374 47878880.4 3712.98026
17 10:00--11:00 42606 1 0 56935 190870 3.35241943 944151041 16582.9637 56347 .989672433 79803601.1 1401.66156
17 10:00--11:00 42606 2 0 25459 116877 4.59079304 307005 12.0588004 25212 .990298126 68514250 2691.1603
17 11:00--12:00 42607 1 0 75261 111094 1.47611645 2502787 33.2547667 74431 .988971712 180128.502 2.39338438
17 12:00--13:00 42608 1 0 69754 120863 1.7327035 2315879 33.2006623 68897 .987713966 156938.37 2.24988345
17 13:00--14:00 42609 1 0 69707 124773 1.78996371 2311681 33.1628244 68819 .987260964 159559.819 2.28900712
17 14:00--15:00 42610 1 0 73647 125412 1.70287995 2431715 33.0185208 72747 .987779543 157285.696 2.1356701
17 15:00--16:00 42611 1 0 72567 129561 1.78539832 2413645 33.2609175 71789 .989278873 187017.111 2.5771647
17 16:00--17:00 42612 1 0 87512 163638 1.86989213 2909814 33.2504571 86715 .990892678 228838.456 2.61493802
17 17:00--18:00 42613 1 0 84382 156810 1.85833472 2807071 33.2662298 83693 .991834751 191470.648 2.2690935
17 18:00--19:00 42614 1 0 84219 176364 2.09411178 2810751 33.3743098 83623 .992923212 200487.836 2.38055351
17 19:00--20:00 42615 1 0 54877 302464 5.51167156 140953874 2568.5419 54519 .99347632 133354886 2430.0688
17 19:00--20:00 42615 2 0 31188 252938 8.11010645 415985747 13338.0065 31080 .99653713 79596641.4 2552.156
17 20:00--21:00 42616 1 0 11772 209886 17.8292559 1580145597 134229.154 11502 .97706422 466474416 39625.7574
17 20:00--21:00 42616 2 0 17498 347563 19.8630129 3580654333 204632.206 17312 .989370214 254167800 14525.5343
17 21:00--21:59 42617 1 0 14982 521349 34.798358 1371981896 91575.3502 14651 .977906822 554649850 37021.082
17 21:00--22:00 42617 2 0 30800 539276 17.508961 189274471 6145.27503 30513 .990681818 299654078 9729.02849
17 21:59--22:14 42618 1 0 1392 48057 34.5237069 616293579 442739.64 1302 .935344828 166429947 119561.744
17 22:00--22:14 42618 2 0 2205 82004 37.1900227 0 0 2160 .979591837 98064534.1 44473.7116
17 22:14--23:00 42619 1 0 6599 263876 39.9872708 0 0 6310 .956205486 380374046 57641.1647
17 22:14--23:00 42619 2 0 16574 351473 21.206287 422350538 25482.7162 16312 .984192108 191863168 11576.1535
17 23:00--00:00 42620 1 0 36251 388343 10.7126148 0 0 35712 .985131445 305173147 8418.33733
17 23:00--00:00 42620 2 0 14982 393738 26.2807369 2285262790 152533.893 14857 .991656655 134609365 8984.73933
18 00:00--01:00 42621 1 0 19041 408934 21.4764981 1758998008 92379.4973 18876 .991334489 221780708 11647.5347
18 00:00--01:00 42621 2 0 9854 329540 33.442257 1519726968 154224.373 9765 .990968135 72614441.3 7369.032
18 01:00--02:00 42622 1 0 68056 394564 5.79763724 613421951 9013.48817 67997 .999133067 88688145.8 1303.16424
18 01:00--02:00 42622 2 0 744 202795 272.573925 2122661498 2853039.65 728 .978494624 23596154 31715.2607
18 02:00--03:00 42623 2 0 916 14849 16.2106987 550376095 600847.265 910 .993449782 2805087.49 3062.32259
18 02:00--03:00 42623 1 0 119607 122053 1.02045031 312546333 2613.11071 118906 .994139139 23330388.6 195.058722
18 03:00--04:00 42624 2 0 1026 50928 49.6374269 7484 7.29434698 1009 .983430799 8345535.12 8134.04982
18 03:00--04:00 42624 1 0 117650 73245 .622566936 0 0 116983 .994330642 33865909.7 287.853036
18 04:00--05:00 42625 2 0 14185 367793 25.9283045 3005147110 211853.867 14116 .995135707 147676423 10410.7453
18 04:00--05:00 42625 1 0 21548 393375 18.2557546 3766604182 174800.64 21377 .992064229 323745614 15024.3927
18 05:00--06:00 42626 2 0 8124 656939 80.8639833 1388760375 170945.393 7989 .98338257 259037373 31885.4472
18 05:00--06:00 42626 1 0 4658 549477 117.964148 1844574220 396001.335 4387 .941820524 512543711 110035.146
18 06:00--07:00 42627 2 0 1314 64384 48.9984779 151351041 115183.441 1312 .99847793 806270.204 613.599851
18 06:00--07:00 42627 1 0 93960 66428 .706981694 293322596 3121.78157 93579 .995945083 1612609.57 17.1627243
18 07:00--08:00 42628 2 0 278 56861 204.535971 1135925463 4086062.82 262 .942446043 5614457.83 20195.8915
18 07:00--08:00 42628 1 0 28062 187738 6.69011475 1030093418 36707.7692 27979 .997042264 25981007.1 925.843031
18 08:00--09:00 42629 1 0 29772 91957 3.08870751 5398670 181.333804 29766 .999798468 19793324.5 664.830193
18 08:00--09:00 42629 2 0 258 11675 45.251938 985440327 3819536.15 258 1 4807218.54 18632.63
GV$ 0 1 0 186850 399297 2.13699224 1330015328 7118.09113 186354 .997345464 47472687 254.068434
GV$ 0 2 0 29265 229685 7.84845378 441583753 15089.1424 29002 .991013156 116494318 3980.67034
GV$ 0 2 0 1928 133274 69.1255187 2272719648 1178796.5 1910 .9906639 11228276 5823.79459
从17日18:00开始正常执行的SQL逻辑读暴增,接下来查看SQL文本
INSERT INTO TFA_XXXXXXXXX
(ack_flag,
…内容过多省略…
vendor_type)
VALUES
(:V1,
…内容过多省略…
:V225)
SQL> select owner,trigger_name,trigger_type,table_owner,table_name from dba_triggers where table_name=‘TFA_XXXXXXXXX’;
no rows selected
Elapsed: 00:00:00.14
简单的insert,表中没有触发器,逻辑读一度达到20万,场面有点尴尬,继续查看awr

从TOPSQL中发现了排在第二的都是delete recyclebin$,而且逻辑读很高占比大道了95%

对应的SQL文本是
delete from RecycleBin$ where bo=:1
delete from RecycleBin$ where purgeobj=:1
继续看delete的执行情况
SQL> @show_sql_stat.sql
Please enter the SQL_ID
b52m6vduutr8j
Please enter the number of days before now for the BEGIN time
You can also enter n/24 for n hours before. Leave blank for 10 day before.
7
old 15: where sql_id='&&sql_id'
new 15: where sql_id='b52m6vduutr8j'
old 38: and sht.begin_interval_time>= sysdate-&days
new 38: and sht.begin_interval_time>= sysdate-7
old 39: and sta.sql_id='&&sql_id'
new 39: and sta.sql_id='b52m6vduutr8j'
FLAG SNAP_ID INST_ID PHV EXECS READS READS_PER GETS GETS_PER ROWS_PROCESSED ROWS_PER ELAP_MS ELAP_PER_MS
--------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- -----------
16 10:00--11:00 42582 1 716146596 1288 13 .010093168 117222832 91011.5155 543 .421583851 368215.197 285.881364
16 11:00--12:00 42583 1 716146596 399 10 .025062657 36343798 91087.213 356 .892230576 110850.223 277.820108
16 11:00--12:00 42583 2 716146596 925 236 .255135135 84250803 91081.9492 357 .385945946 267302.21 288.975362
16 12:00--13:00 42584 1 716146596 2058 26739 12.9927114 187024696 90876.9174 718 .34888241 561991.244 273.076406
16 12:00--13:00 42584 2 716146596 450 2 .004444444 40985470 91078.8222 67 .148888889 125206.512 278.236693
16 13:00--14:00 42585 1 716146596 1483 222 .149696561 135108259 91104.6925 616 .415374241 412096.854 277.880549
16 13:00--14:00 42585 2 716146596 888 3 .003378378 80817926 91011.1779 258 .290540541 249587.491 281.066994
16 14:00--15:00 42586 2 716146596 1319 3 .00227445 119951380 90941.1524 234 .177407127 386486.315 293.014644
16 14:00--15:00 42586 1 716146596 1496 13 .00868984 136157979 91014.6918 609 .407085561 411022.678 274.747779
16 15:00--16:00 42587 1 716146596 1037 483 .465766635 94635927 91259.3317 593 .571841851 287550.366 277.290613
16 15:00--16:00 42587 2 716146596 1095 3 .002739726 99731981 91079.4347 235 .214611872 333513.058 304.578135
16 16:00--17:00 42588 1 716146596 367 3 .008174387 33428246 91085.139 268 .730245232 109332.528 297.908796
16 16:00--17:00 42588 2 716146596 1764 45603 25.8520408 159621362 90488.3005 515 .291950113 530314.172 300.631617
16 17:00--18:00 42589 1 716146596 1125 12 .010666667 102623636 91221.0098 444 .394666667 307828.649 273.625466
16 17:00--18:00 42589 2 716146596 1702 28 .016451234 154762424 90929.7438 376 .220916569 493462.625 289.931037
==故障点==
16 18:00--19:00 42590 1 716146596 159825 82967 .519111528 1310669994 8200.65693 393 .002458939 137380687 859.569446
16 18:00--19:00 42590 2 716146596 112235 80726 .719258698 1278883211 11394.6916 1593 .014193433 67786614.5 603.97037
16 19:00--20:00 42591 2 716146596 186744 226641 1.21364542 0 0 2189 .011721929 129961005 695.931354
16 19:00--20:00 42591 1 716146596 300218 198697 .661842395 659596002 2197.05681 501 .001668787 262591816 874.67046
16 20:00--21:00 42592 2 716146596 88764 155246 1.74897481 0 0 1679 .018915326 40671109.1 458.19374
16 20:00--21:00 42592 1 716146596 226914 722417 3.18365989 0 0 1483 .006535516 133327999 587.570615
16 21:00--22:00 42593 1 716146596 197939 71796 .362717807 336776381 1701.41499 626 .00316259 108631591 548.813479
16 21:00--22:00 42593 2 716146596 95967 54107 .563808392 57373637 597.847562 1946 .020277804 36321673.3 378.480866
16 22:00--23:00 42594 1 716146596 242637 1277937 5.26686779 0 0 1082 .004459336 193196923 796.238511
16 22:00--23:00 42594 2 716146596 107305 106327 .990885793 948535834 8839.62382 1537 .014323657 56548732.5 526.990657
16 23:00--00:00 42595 2 716146596 55205 84523 1.53107508 630946913 11429.1624 888 .0160855 33240554.4 602.129416
16 23:00--00:00 42595 1 716146596 128425 862611 6.71684641 2908108919 22644.4144 1646 .012816819 77960194.5 607.048429
17 00:00--01:00 42596 1 716146596 165560 122537 .740136506 0 0 2045 .012352017 134263734 810.967224
17 00:00--01:00 42596 2 716146596 90179 134152 1.48761907 0 0 1277 .014160725 60267130.4 668.305597
17 01:00--02:00 42597 1 716146596 31514 12191 .386843942 2899753683 92014.777 1576 .05000952 10026166.2 318.149591
17 01:00--02:00 42597 2 716146596 16670 286613 17.1933413 1497849856 89853.0208 595 .035692861 7292665.14 437.472414
17 02:00--03:00 42598 2 716146596 10659 5955 .558682803 962820549 90329.3507 471 .04418801 3590051.37 336.809398
17 02:00--03:00 42598 1 716146596 27684 17698 .63928623 0 0 2237 .080804797 8462597.98 305.685522
17 03:00--04:00 42599 2 716146596 19741 47883 2.42556102 0 0 367 .01859075 7553627.96 382.636541
17 03:00--04:00 42599 1 716146596 19277 61523 3.19152358 1792912170 93007.842 1237 .064169736 7393380.11 383.533751
17 04:00--05:00 42600 2 716146596 46440 165994 3.57437554 0 0 727 .015654608 20009276.7 430.862978
17 04:00--05:00 42600 1 716146596 52820 61089 1.15655055 583351143 11044.1337 3083 .058368042 17225931.4 326.125168
17 05:00--06:00 42601 2 716146596 65164 121358 1.86234731 1583453249 24299.5097 1546 .023724756 26334019.4 404.119136
17 05:00--06:00 42601 1 716146596 163112 167302 1.02568787 0 0 1857 .011384815 68020215.5 417.015397
17 06:00--07:00 42602 1 716146596 91912 47639 .518310993 0 0 1526 .016602837 38672457 420.755255
17 06:00--07:00 42602 2 716146596 18879 21021 1.1134594 0 0 1482 .078499921 6663590.38 352.963101
17 07:00--08:00 42603 1 716146596 2841 23427 8.24604013 258505658 90991.0799 1015 .357268567 761030.214 267.874063
17 08:00--09:00 42604 2 716146596 292 0 0 26594690 91077.7055 18 .061643836 81271.498 278.327048
17 08:00--09:00 42604 1 716146596 1133 10 .008826125 103056680 90959.1174 380 .335392763 303539.965 267.908177
17 09:00--10:00 42605 1 716146596 45759 131882 2.8820997 0 0 777 .016980266 25488481 557.015691
17 09:00--10:00 42605 2 716146596 49286 70132 1.42295987 111191557 2256.0475 362 .007344885 33670968.4 683.175109
17 10:00--11:00 42606 2 716146596 72029 50597 .702453179 2115731292 29373.3259 537 .00745533 47465507.9 658.977743
17 10:00--11:00 42606 1 716146596 76768 54733 .71296634 2570062177 33478.3006 1965 .025596603 40807120.1 531.564195
17 11:00--12:00 42607 1 716146596 962 17329 18.0135135 87636874 91098.6216 452 .46985447 265400.52 275.884116
17 12:00--13:00 42608 1 716146596 264 4 .015151515 24045928 91083.0606 137 .518939394 74569.85 282.461553
17 13:00--14:00 42609 1 716146596 304 9 .029605263 27689683 91084.4836 194 .638157895 87070.018 286.414533
17 14:00--15:00 42610 1 716146596 361 7 .019390582 32880941 91082.9391 169 .468144044 98089.056 271.714837
17 16:00--17:00 42612 2 716146596 1907 24063 12.6182486 173641632 91054.8673 421 .2207656 570762.693 299.298738
17 16:00--17:00 42612 1 716146596 1442 12 .008321775 131445218 91154.7975 527 .365464632 414307.063 287.314191
17 17:00--18:00 42613 1 716146596 743 9 .012113055 67765485 91205.2288 354 .476446837 208900.793 281.158537
17 17:00--18:00 42613 2 716146596 1664 29 .017427885 151821069 91238.6232 309 .185697115 501979.109 301.670138
17 18:00--19:00 42614 2 716146596 443 5 .011286682 40349549 91082.5034 213 .480812641 122754.071 277.097226
17 19:00--20:00 42615 2 716146596 71196 133855 1.88009158 2062210340 28965.2556 743 .01043598 42745375.7 600.390129
17 19:00--20:00 42615 1 716146596 115267 124662 1.08150642 1546274378 13414.7187 212 .001839208 89174487.1 773.634146
17 20:00--21:00 42616 1 716146596 320847 136716 .426109641 2447288385 7627.58693 1 3.1168E-06 321900744 1003.28426
17 20:00--21:00 42616 2 716146596 240198 210179 .875023939 1210715 5.04048743 1920 .007993405 135898435 565.776712
17 21:00--21:59 42617 1 716146596 308486 361579 1.1721083 0 0 59 .000191257 382531521 1240.02879
17 21:00--22:00 42617 2 716146596 219392 345481 1.57472014 0 0 1814 .008268305 168008972 765.793522
17 21:59--22:14 42618 1 716146596 77813 31451 .404186961 2570474763 33034.0016 21 .000269878 114401465 1470.21018
17 22:00--22:14 42618 2 716146596 53058 59564 1.12262053 493132476 9294.21531 492 .009272871 48738424.9 918.587677
17 22:14--23:00 42619 2 716146596 144273 235759 1.63411726 0 0 1344 .009315672 96418053.8 668.302827
17 22:14--23:00 42619 1 716146596 221411 181288 .818784975 0 0 142 .000641341 264532026 1194.75557
17 23:00--00:00 42620 2 716146596 120079 246643 2.05400611 2204032162 18354.8511 2190 .018237993 67316233.9 560.599554
17 23:00--00:00 42620 1 716146596 247058 234371 .948647686 342824933 1387.62935 440 .001780958 205261646 830.823719
18 00:00--01:00 42621 1 716146596 250600 273046 1.08956903 885160327 3532.16411 1017 .00405826 148156640 591.20766
18 00:00--01:00 42621 2 716146596 78057 223765 2.86668716 0 0 2187 .028017987 36759602.8 470.932816
18 01:00--02:00 42622 2 716146596 31214 88950 2.84968283 0 0 989 .031684501 11767602.6 376.997583
18 01:00--02:00 42622 1 716146596 117582 146094 1.24248609 0 0 2427 .020640914 44953800.7 382.318729
18 02:00--03:00 42623 2 716146596 6091 38195 6.2707273 557931354 91599.3029 739 .121326547 1936443.18 317.918762
18 02:00--03:00 42623 1 716146596 31710 16966 .535036266 2892901491 91229.943 1634 .051529486 11129636.2 350.981903
18 03:00--04:00 42624 2 716146596 11228 34462 3.06929106 1025445923 91329.3483 986 .087816174 3902760.15 347.591749
18 03:00--04:00 42624 1 716146596 44298 21892 .494198384 3980316228 89853.1814 674 .015215134 21607655.3 487.779478
18 04:00--05:00 42625 1 716146596 318089 280954 .883255944 0 0 302 .00094942 228973892 719.84222
18 04:00--05:00 42625 2 716146596 134051 231918 1.73007288 0 0 2149 .016031212 68587750.3 511.654149
18 05:00--06:00 42626 1 716146596 294244 392129 1.33266609 293475419 997.387947 206 .000700099 360397027 1224.82371
18 05:00--06:00 42626 2 716146596 197673 457128 2.31254648 332059089 1679.84039 2249 .011377376 146516697 741.207432
18 06:00--07:00 42627 2 716146596 976 2604 2.66803279 89465742 91665.7193 62 .06352459 339355.755 347.700569
18 06:00--07:00 42627 1 716146596 66407 127358 1.91783999 1613159420 24292.0087 1131 .017031337 53426789.1 804.535502
18 07:00--08:00 42628 2 716146596 13510 35759 2.64685418 1232079281 91197.5782 1201 .088897113 4512922.82 334.04314
18 07:00--08:00 42628 1 716146596 40087 66357 1.65532467 0 0 2639 .065831816 14149097.8 352.959756
18 08:00--09:00 42629 2 716146596 7240 5313 .733839779 659737307 91123.9374 554 .076519337 2375372.36 328.090105
18 08:00--09:00 42629 1 716146596 33641 29573 .879076127 0 0 1967 .058470319 10991121.7 326.718043
18 09:00--10:00 42630 1 716146596 2996 44 .014686248 272788169 91050.7907 470 .156875834 821568.234 274.221707
好像接近问题本质了,在同样时间点delete from recyclebin$ 语句的执行次数和逻辑读暴增,逻辑读达9w,那么回收站怎么就有那么高逻辑读呢,从执行计划发现,RECYCLEBIN$使用全表扫描,且回收站达到700多MB
Plan hash value: 716146596
------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | | | 611 (100)| |
| 1 | DELETE | RECYCLEBIN$ | | | | |
| 2 | TABLE ACCESS STORAGE FULL| RECYCLEBIN$ | 1 | 19 | 611 (1)| 00:00:08 |
------------------------------------------------------------------------------------------
SQL>
SQL> select owner,segment_name,segment_type,sum(bytes)/1024/1024 MB from dba_segments where owner='SYS' and segment_name ='RECYCLEBIN$' group by owner,segment_name,segment_type;
OWNER SEGMENT_NAME SEGMENT_TYPE MB
------------------------------ --------------------------------------------------------------------------------- ------------------ ----------
SYS RECYCLEBIN$ TABLE 716
那么一直delete recyclebin$一定是表空间不够用了,继续查看表所在的表空间,
SQL>select table_owner,table_name,partition_name,tablespace_name ,to_char(last_analyzed,'yyyy-mm-dd hh24:mi:ss') from dba_tab_partitions where table_name ='TFA_XXXXXXXXX' and table_owner='XXUSER'
2 ;
TABLE_OWNER TABLE_NAME PARTITION_NAME TABLESPACE_NAME TO_CHAR(LAST_ANALYZ
------------------------------ ------------------------------ ------------------------------ ------------------------------ -------------------
XXUSER TFA_XXXXXXXXX PART20200815 TBS_FM_XXXXXXXS 2020-11-08 22:33:21
XXUSER TFA_XXXXXXXXX PART20200816 TBS_FM_XXXXXXXS 2020-11-08 22:35:02
XXUSER TFA_XXXXXXXXX PART20200817 TBS_FM_XXXXXXXS 2020-11-08 22:36:19
XXUSER TFA_XXXXXXXXX PART20200818 TBS_FM_XXXXXXXS 2020-11-08 22:37:35
XXUSER TFA_XXXXXXXXX PART20200819 TBS_FM_XXXXXXXS 2020-11-08 22:38:49
XXUSER TFA_XXXXXXXXX PART20200820 TBS_FM_XXXXXXXS 2020-11-08 22:41:10
XXUSER TFA_XXXXXXXXX PART20200821 TBS_FM_XXXXXXXS 2020-11-08 22:43:43
XXUSER TFA_XXXXXXXXX PART20200822 TBS_FM_XXXXXXXS 2020-11-08 22:46:11
XXUSER TFA_XXXXXXXXX PART20200823 TBS_FM_XXXXXXXS 2020-11-08 22:48:38
select distinct table_owner,table_name,tablespace_name from dba_tab_partitions where table_name ='TFA_XXXXXXXXX' and table_owner='XXUSER'
SQL>select distinct table_owner,table_name,tablespace_name from dba_tab_partitions where table_name ='TFA_XXXXXXXXX' and table_owner='XXUSER';
TABLE_OWNER TABLE_NAME TABLESPACE_NAME
------------------------------ ------------------------------ ------------------------------
XXUSER TFA_XXXXXXXXX TBS_FM_XXXXXXXS
SQL> select tablespace_name ,segment_space_management from dba_tablespaces where tablespace_name='TBS_FM_XXXXXXXS';
TABLESPACE_NAME SEGMEN
------------------------------ ------
TBS_FM_XXXXXXXS AUTO
--表空间使用率,可用96GB
TBS_FM_XXXXXXXS 1884160 1787182 96978 95
问题已经逐渐明朗了,数据库drop了大量表没有释放空间,insert的时候分配segment,没有足够的空间导致触发delete recyclebin操作,而delete recyclebin又是全表SQL秒,执行效率很低,导致insert逻辑读很高。仔细推敲仍需证明: 即使delete效率很差,也不至于insert逻辑读达到20万,回收站是影响原因,但一定不是主要原因。
我们从mos中可以看到那么一篇文章Bug 19791273 - Poor UPDATE SQL performance due to space search cache for updates on ASSM segment (Doc ID 19791273.8)
其中修复的bug 13641076关于bug的描述是:
INSERT operations have a high amount of buffer gets when there is a concurrent uncommitted large DELETE for ASSM segments.
Note:
It is expected in ASSM that a first attempt to find space in a segment may need to visit many blocks in the case of an uncommitted concurrent delete, but subsequent executions of the cursor should use a “reject” list implemented in bug 4188324 and so skip reading of blocks already rejected. Prior to this fix the “rejection” list is cursor based, and so if the DML cursor is closed and a new cursor used the reject list has to be rebuilt.
This fix changes the rejection list to be session based rather than cursor based.
在ASSM段管理中当同时发生大量的uncommited的delete操作时,那么insert操作就会有一个很高的buffer获取。
在发生大量的UNcommited的delete操作时,在ASSM段管理中需要尝试寻找空间,这可能会扫描更多的block,在bug 4188324中针对这个操作修复了一个"reject" list通过cursor保存,在后续的insert时会跳过扫描block这个操作,然而dml操作的游标是在执行完之后就关闭了,在新的造作中会重建新的游标,使得insert在频繁重复的查找block导致很高的逻辑读
针对mos这边文章所叙述的环境跟故障环境极其相似,delete from recyclebin就是大量的delete,查看数据库补丁
[oracle@xxxxx ~] opatch lsinventory -bugs_fixed |grep 13641076
[oracle@xxxxx ~]$
数据库没有相关补丁也证实了此故障触发了bug
解决方案:
1.针对此bug安装修复patch
2.清空回收站,从业务侧推荐临时表使用temporary table 或删除表加purge。
3.可在recyclebin$表purgeobj和bo两个列上创建索引。




