資料庫響應慢問題處理

哎呀我的天吶發表於2015-03-24
資料庫

1. 客戶環境

作業系統：HP

資料庫版本：Oracle Database 10.2.0.5

2. 問題描述

使用者資料庫系統2015年3月19日1點到2015年3月19日1點22分，資料庫響應非常緩慢。

3. 資料庫檢查

3.1 查詢1點至2點每分鐘的資料庫事物數量


點選(此處)摺疊或開啟

  1. select to_char(SAMPLE_TIME, 'yyyy-mm-dd hh24:mi'), count(*)
  2.   from dba_hist_active_sess_history
  3.  where snap_id >= 34592
  4.    and snap_id <= 34593
  5.  group by to_char(SAMPLE_TIME, 'yyyy-mm-dd hh24:mi')
  6.  order by 1;

  8. 2015-03-18 23:59    7
  9. 2015-03-19 00:00    72
  10. 2015-03-19 00:01    161
  11. 2015-03-19 00:02    79
  12. 2015-03-19 00:03    78
  13. 2015-03-19 00:04    79
  14. 2015-03-19 00:05    105
  15. 2015-03-19 00:06    69
  16. 2015-03-19 00:07    74
  17. 2015-03-19 00:08    71
  18. 2015-03-19 00:09    75
  19. 2015-03-19 00:10    81
  20. 2015-03-19 00:11    158
  21. 2015-03-19 00:12    87
  22. 2015-03-19 00:13    69
  23. 2015-03-19 00:14    61
  24. 2015-03-19 00:15    64
  25. 2015-03-19 00:16    77
  26. 2015-03-19 00:17    67
  27. 2015-03-19 00:18    74
  28. 2015-03-19 00:19    90
  29. 2015-03-19 00:20    84
  30. 2015-03-19 00:21    106
  31. 2015-03-19 00:22    84
  32. 2015-03-19 00:23    79
  33. 2015-03-19 00:24    71
  34. 2015-03-19 00:25    120
  35. 2015-03-19 00:26    68
  36. 2015-03-19 00:27    96
  37. 2015-03-19 00:28    71
  38. 2015-03-19 00:29    67
  39. 2015-03-19 00:30    77
  40. 2015-03-19 00:31    75
  41. 2015-03-19 00:32    53
  42. 2015-03-19 00:33    72
  43. 2015-03-19 00:34    69
  44. 2015-03-19 00:35    88
  45. 2015-03-19 00:36    86
  46. 2015-03-19 00:37    98
  47. 2015-03-19 00:38    76
  48. 2015-03-19 00:39    83
  49. 2015-03-19 00:40    82
  50. 2015-03-19 00:41    108
  51. 2015-03-19 00:42    59
  52. 2015-03-19 00:43    65
  53. 2015-03-19 00:44    63
  54. 2015-03-19 00:45    49
  55. 2015-03-19 00:46    56
  56. 2015-03-19 00:47    114
  57. 2015-03-19 00:48    71
  58. 2015-03-19 00:49    89
  59. 2015-03-19 00:50    97
  60. 2015-03-19 00:51    55
  61. 2015-03-19 00:52    76
  62. 2015-03-19 00:53    80
  63. 2015-03-19 00:54    66
  64. 2015-03-19 00:55    89
  65. 2015-03-19 00:56    106
  66. 2015-03-19 00:57    75
  67. 2015-03-19 00:58    101
  68. 2015-03-19 00:59    99
  69. 2015-03-19 01:00    313
  70. 2015-03-19 01:01    296
  71. 2015-03-19 01:02    381
  72. 2015-03-19 01:03    496
  73. 2015-03-19 01:04    713
  74. 2015-03-19 01:05    929
  75. 2015-03-19 01:06    1074
  76. 2015-03-19 01:07    1146
  77. 2015-03-19 01:08    1317
  78. 2015-03-19 01:09    1399
  79. 2015-03-19 01:10    1649
  80. 2015-03-19 01:11    1827
  81. 2015-03-19 01:12    2031
  82. 2015-03-19 01:13    2133
  83. 2015-03-19 01:14    2281
  84. 2015-03-19 01:15    2421
  85. 2015-03-19 01:16    2117
  86. 2015-03-19 01:17    2637
  87. 2015-03-19 01:18    2880
  88. 2015-03-19 01:19    3072
  89. 2015-03-19 01:20    3203
  90. 2015-03-19 01:21    3319
  91. 2015-03-19 01:22    1746
  92. 2015-03-19 01:23    140
  93. 2015-03-19 01:24    170
  94. 2015-03-19 01:25    122
  95. 2015-03-19 01:26    97
  96. 2015-03-19 01:27    104
  97. 2015-03-19 01:28    133
  98. 2015-03-19 01:29    100
  99. 2015-03-19 01:30    119
  100. 2015-03-19 01:31    109
  101. 2015-03-19 01:32    93
  102. 2015-03-19 01:33    122
  103. 2015-03-19 01:34    95
  104. 2015-03-19 01:35    111
  105. 2015-03-19 01:36    96
  106. 2015-03-19 01:37    131
  107. 2015-03-19 01:38    261
  108. 2015-03-19 01:39    302
  109. 2015-03-19 01:40    293
  110. 2015-03-19 01:41    182
  111. 2015-03-19 01:42    101
  112. 2015-03-19 01:43    100
  113. 2015-03-19 01:44    105
  114. 2015-03-19 01:45    327
  115. 2015-03-19 01:46    108
  116. 2015-03-19 01:47    111
  117. 2015-03-19 01:48    104
  118. 2015-03-19 01:49    118
  119. 2015-03-19 01:50    118
  120. 2015-03-19 01:51    86
  121. 2015-03-19 01:52    119
  122. 2015-03-19 01:53    102
  123. 2015-03-19 01:54    119
  124. 2015-03-19 01:55    88
  125. 2015-03-19 01:56    109
  126. 2015-03-19 01:57    87
  127. 2015-03-19 01:58    80
  128. 2015-03-19 01:59    73

分析： 2015-03-19 01:00  至 2015-03-19 01:22 發生等待次數較多SQL_ID


3.2 進一步分析1點至1點22分等待事件


點選(此處)摺疊或開啟

  1. select * from (select sql_id,event, count(*) cnt
  2.   from dba_hist_active_sess_history
  3.  where snap_id >= 34592
  4.    and snap_id <= 34593
  5.    and to_char(SAMPLE_TIME, 'yyyy-mm-dd hh24:mi')>'2015-03-19 01:00'
  6.    and to_char(SAMPLE_TIME, 'yyyy-mm-dd hh24:mi')<'2015-03-19 01:22'
  7.  group by sql_id,event
  8.  order by 3 desc) where rownum<30;
  9.  
  10. SQL_ID EVENT CNT
  11. ------------- ---------------------------------------------------------------- ----------
  12. 0ggty2d2d96qn enq: TX - row lock contention 14319
  13. fkjwrr2ax004g latch: cache buffers chains 8851
  14. fkjwrr2ax004g gc buffer busy 7076
  15. fkjwrr2ax004g wait list latch free 735
  16. fkjwrr2ax004g latch: row cache objects 587
  17. fkjwrr2ax004g 224
  18.               log file sync 210
  19.               Backup: sbtwrite2 167
  20.                                                                                       123
  21. 7g3xvq43j0rns 86
  22.               log file parallel write 72
  23. 79t4hx5nx9bu6 db file sequential read 68
  24. grwfx6xbcnh39 55
  25.               SQL*Net message from dblink 42
  26. 520mkxqpf15q8 38
  27. 1u209u2t2d7fd db file scattered read 36
  28. 7xbdhjbn3x96q 35
  29. d7g1p6925bps5 db file scattered read 30
  30. 2m7w0gv9v0hpb 28
  31. fkjwrr2ax004g buffer busy waits 27
  32. 55hk4qa068nku 24
  33. 1t5mrg4njz5jj 23
  34.               cursor: pin S 20
  35. 520mkxqpf15q8 cursor: pin S 14
  36. bqju3yc59quzb 14
  37. fkjwrr2ax004g gc current block 2-way 14
  38. 1nwwqwc0qay94 enq: TX - row lock contention 14
  39. 3j66afaz3n3s9 gc current block 2-way 14
  40. dgkwa1zp9fxwk SQL*Net message from dblink 13

分析： 等待事件較高sql為0ggty2d2d96qn(select for update)/ fkjwrr2ax004g(insert into porthistory)

3.3  進一步分析awr報告



點選(此處)摺疊或開啟

  1. Sql_id 79t4hx5nx9bu6
  2. DELETE FROM PORTHISTORY WHERE TIMEKEY < TO_CHAR(TRUNC(SYSDATE) - 120, 'YYYYMMDDHH24MISS')

分析： 單次執行時間1307.13秒，接近22分鐘

3.4 抓取執行計劃分析


點選(此處)摺疊或開啟

  1. SQL> select * from table(dbms_xplan.display_awr('79t4hx5nx9bu6'));
  2.                                                                                                                                      
  3. PLAN_TABLE_OUTPUT
  4. --------------------------------------------------------------------------------------------
  5. SQL_ID 79t4hx5nx9bu6
  6. --------------------
  7. DELETE FROM PORTHISTORY WHERE TIMEKEY < TO_CHAR(TRUNC(SYSDATE) - 120,
  8. 'YYYYMMDDHH24MISS')
  9.                                                                                                                                  
  10. Plan hash value: 1650323717                                                                                                          
  11. ---------------------------------------------------------------------------------
  12. | Id |        Operation |           Name | Rows | Bytes | Cost (%CPU)|     Time |
  13. ---------------------------------------------------------------------------------
  14. |  0 | DELETE STATEMENT |                |      |       | 85528 (100)|          |
  15. |  1 |  DELETE          |    PORTHISTORY |      |       |            |          |
  16. |  2 |   INDEX SKIP SCAN| PORTHISTORY_PK | 426K |   13M |   85528 (1)| 00:17:07 |
  17. ---------------------------------------------------------------------------------
  18.                                                                                                                                    
  19. SQL_ID 79t4hx5nx9bu6
  20. --------------------
  21. DELETE FROM PORTHISTORY WHERE TIMEKEY < TO_CHAR(TRUNC(SYSDATE) - 120,
  22. 'YYYYMMDDHH24MISS')
  23.                                                                                                                                     
  24. Plan hash value: 3989602834
  25.                                                                                                                                      
  26. ----------------------------------------------------------------------------------
  27. | Id |         Operation |           Name | Rows | Bytes | Cost (%CPU)|     Time |
  28. ----------------------------------------------------------------------------------
  29. |  0 | DELETE STATEMENT  |                |      |       | 49551 (100)|          |
  30. |  1 |  DELETE           |    PORTHISTORY |      |       |            |          |
  31. |  2 |   INDEX FULL SCAN | PORTHISTORY_PK | 568K |   17M |   49551 (1)| 00:09:55 |
  32. ----------------------------------------------------------------------------------
  33.                                                                                                                                
  34. 30 rows selected.

分析： 有多個版本執行計劃

3.5 檢視sql執行計劃版本變化時間


點選(此處)摺疊或開啟

  1. select sql_id,plan_hash_value,to_char(timestamp,\'yyyy-mm-dd hh24:mi:ss\') from dba_hist_sql_plan where sql_id=\'79t4hx5nx9bu6\'
  2.  
  3.      79t4hx5nx9bu6    1650323717    2015-02-14 17:38:45
  4.      79t4hx5nx9bu6    1650323717    2015-02-14 17:38:45
  5.      79t4hx5nx9bu6    1650323717    2015-02-14 17:38:45
  6.      79t4hx5nx9bu6    3989602834    2015-02-15 16:39:31
  7.      79t4hx5nx9bu6    3989602834    2015-02-15 16:39:31
  8.      79t4hx5nx9bu6    3989602834    2015-02-15 16:39:31

分析： sql執行計劃最新版本為3989602834

4. 操作過程

4.1分析所用到索引


點選(此處)摺疊或開啟

  1. SQL> analyze index fabadm.porthistory_pk validate structure;

  3. Index analyzed.

  5. SQL> select t.name,
  6.   2 t.lf_rows, --number of leaf rows (values in the index)
  7.   3 t.lf_blks,
  8.   4 t.del_lf_rows, --number of deleted leaf rows in the index
  9.   5 (t.del_lf_rows / t.lf_rows)*100 ratio
  10.   6 from index_stats t
  11.   7 where t.name=\'PORTHISTORY_PK\';

  13. NAME LF_ROWS LF_BLKS DEL_LF_ROWS RATIO
  14. ------------------------------ ---------- ---------- ----------- ----------
  15. PORTHISTORY_PK 18031455 251171 51533 .285795018

分析： 索引不存在碎片化

4.1 重新收集統計資訊，保證執行計劃準確性

點選(此處)摺疊或開啟

  1. BEGIN
  2.   DBMS_STATS.GATHER_TABLE_STATS(ownname => 'FABADM',
  3.                                 tabname => 'PORTHISTORY',
  4.                                 estimate_percent => 60,
  5.                                 method_opt => 'for all columns size repeat',
  6.                                 no_invalidate => FALSE,
  7.                                 degree => 4,
  8.                                 granularity => 'ALL',
  9.                                 cascade => TRUE);
  10. END;
  11. /

5. 總結

1.  分析
1點至2點每分鐘的等待事件，主要在01:00  至  01:22  產生大量等待

2     2、進一步分析，查詢1點至1點22產生等待sql_id為0ggty2d2d96qn/ fkjwrr2ax004g

3、瞭解業務進一步分析，首先select for update鎖定資料,inert 到porthistory併成功提交後釋放鎖

4.    綜合awr分析可能由於delete刪除造成此次響應較慢問題, SQL_ID: 79t4hx5nx9bu6 DELETE FROM PORTHISTORY WHERE TIMEKEY < TO_CHAR(TRUNC(SYSDATE) - 120,'YYYYMMDDHH24MISS')，執行時間為1307秒,正好接近22分鐘,也就是業務緩慢時間段

已經對錶收集統計資訊，並把索引rebuild








來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/29990276/viewspace-1471380/，如需轉載，請註明出處，否則將追究法律責任。

相關文章