執行時間在1秒以下的SQL同樣也會引發效能問題

某客戶的操作人員反應很慢不能操作，管理人員登入小機系統後發現CPU使用到了95%以上。而且這種情況持續了幾個月。小機是IBM的P520,配置是2顆4核的CPU,記憶體是48G,Oracle是10.2.0.5。topas與生成的AWR報告如下:

從上面的load profile部分可以看到每秒執行的sql與事務數並不高，因為是週末並沒有太多人使用系統。

從上面的top 等待事件來看主要是CPU time。檢視這個時間段生成的ADDM報告:

          DETAILED ADDM REPORT FOR TASK 'TASK_72988' WITH ID 72988
          --------------------------------------------------------

              Analysis Period: 20-DEC-2015 from 09:00:33 to 10:00:34
         Database ID/Instance: 1329630138/1
      Database/Instance Names: ORCL/orcl
                    Host Name: dbserv
             Database Version: 10.2.0.5.0
               Snapshot Range: from 26245 to 26246
                Database Time: 16644 seconds
        Average Database Load: 4.6 active sessions

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

FINDING 1: 93% impact (15444 seconds)
-------------------------------------
SQL statements consuming significant database time were found.

   RECOMMENDATION 1: SQL Tuning, 100% benefit (38004 seconds)
      ACTION: Run SQL Tuning Advisor on the SQL statement with SQL_ID
         "fb44z8kbnu8wg".
         RELEVANT OBJECT: SQL statement with SQL_ID fb44z8kbnu8wg and
         PLAN_HASH 1055903002
         SELECT COUNT(EmailDetail.F_EMAIL_DETAIL_ID) AS UnReadCount FROM
         T_LK_EMAIL_EMAILGROUP EmailGroup LEFT OUTER JOIN T_LK_EMAIL_DETAIL
         EmailDetail ON EmailGroup.F_EMAIL_GROUP_ID=EmailDetail.F_EMAIL_GROUP_
         ID AND (EmailDetail.F_RECEIVER_ID=:param0 OR
         (EmailDetail.F_SENDER_ID=:param0 AND EmailDetail.F_RECEIVER_ID IS
         NULL)) AND EmailDetail.F_EMAIL_STATE='0' AND
         EmailDetail.F_RECORD_STATE='0' WHERE EmailGroup.F_PARENT_ID=0 AND
         (EmailGroup.F_EMAIL_GROUP_ID!=4 OR (EmailGroup.F_GROUP_TYPE='USER'
         AND EmailGroup.F_USER_ID=:param0))
      ACTION: Investigate the SQL statement with SQL_ID "fb44z8kbnu8wg" for
         possible performance improvements.
         RELEVANT OBJECT: SQL statement with SQL_ID fb44z8kbnu8wg and
         PLAN_HASH 1055903002
         SELECT COUNT(EmailDetail.F_EMAIL_DETAIL_ID) AS UnReadCount FROM
         T_LK_EMAIL_EMAILGROUP EmailGroup LEFT OUTER JOIN T_LK_EMAIL_DETAIL
         EmailDetail ON EmailGroup.F_EMAIL_GROUP_ID=EmailDetail.F_EMAIL_GROUP_
         ID AND (EmailDetail.F_RECEIVER_ID=:param0 OR
         (EmailDetail.F_SENDER_ID=:param0 AND EmailDetail.F_RECEIVER_ID IS
         NULL)) AND EmailDetail.F_EMAIL_STATE='0' AND
         EmailDetail.F_RECORD_STATE='0' WHERE EmailGroup.F_PARENT_ID=0 AND
         (EmailGroup.F_EMAIL_GROUP_ID!=4 OR (EmailGroup.F_GROUP_TYPE='USER'
         AND EmailGroup.F_USER_ID=:param0))
      RATIONALE: SQL statement with SQL_ID "fb44z8kbnu8wg" was executed 16029
         times and had an average elapsed time of 0.93 seconds.

  

FINDING 2: 76% impact (12602 seconds)
-------------------------------------
Time spent on the CPU by the instance was responsible for a substantial part
of database time.

   RECOMMENDATION 1: SQL Tuning, 100% benefit (38004 seconds)
      ACTION: Run SQL Tuning Advisor on the SQL statement with SQL_ID
         "fb44z8kbnu8wg".
         RELEVANT OBJECT: SQL statement with SQL_ID fb44z8kbnu8wg and
         PLAN_HASH 1055903002
         SELECT COUNT(EmailDetail.F_EMAIL_DETAIL_ID) AS UnReadCount FROM
         T_LK_EMAIL_EMAILGROUP EmailGroup LEFT OUTER JOIN T_LK_EMAIL_DETAIL
         EmailDetail ON EmailGroup.F_EMAIL_GROUP_ID=EmailDetail.F_EMAIL_GROUP_
         ID AND (EmailDetail.F_RECEIVER_ID=:param0 OR
         (EmailDetail.F_SENDER_ID=:param0 AND EmailDetail.F_RECEIVER_ID IS
         NULL)) AND EmailDetail.F_EMAIL_STATE='0' AND
         EmailDetail.F_RECORD_STATE='0' WHERE EmailGroup.F_PARENT_ID=0 AND
         (EmailGroup.F_EMAIL_GROUP_ID!=4 OR (EmailGroup.F_GROUP_TYPE='USER'
         AND EmailGroup.F_USER_ID=:param0))
      ACTION: Investigate the SQL statement with SQL_ID "fb44z8kbnu8wg" for
         possible performance improvements.
         RELEVANT OBJECT: SQL statement with SQL_ID fb44z8kbnu8wg and
         PLAN_HASH 1055903002
         SELECT COUNT(EmailDetail.F_EMAIL_DETAIL_ID) AS UnReadCount FROM
         T_LK_EMAIL_EMAILGROUP EmailGroup LEFT OUTER JOIN T_LK_EMAIL_DETAIL
         EmailDetail ON EmailGroup.F_EMAIL_GROUP_ID=EmailDetail.F_EMAIL_GROUP_
         ID AND (EmailDetail.F_RECEIVER_ID=:param0 OR
         (EmailDetail.F_SENDER_ID=:param0 AND EmailDetail.F_RECEIVER_ID IS
         NULL)) AND EmailDetail.F_EMAIL_STATE='0' AND
         EmailDetail.F_RECORD_STATE='0' WHERE EmailGroup.F_PARENT_ID=0 AND
         (EmailGroup.F_EMAIL_GROUP_ID!=4 OR (EmailGroup.F_GROUP_TYPE='USER'
         AND EmailGroup.F_USER_ID=:param0))
      RATIONALE: SQL statement with SQL_ID "fb44z8kbnu8wg" was executed 16029
         times and had an average elapsed time of 0.93 seconds.
      RATIONALE: Average CPU used per execution was 0.76 seconds.

  
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

          ADDITIONAL INFORMATION
          ----------------------

Wait class "Application" was not consuming significant database time.
Wait class "Commit" was not consuming significant database time.
Wait class "Concurrency" was not consuming significant database time.
Wait class "Configuration" was not consuming significant database time.
Wait class "Network" was not consuming significant database time.
Wait class "User I/O" was not consuming significant database time.
Session connect and disconnect calls were not consuming significant database
time.
Hard parsing of SQL statements was not consuming significant database time.

The database's maintenance windows were active during 99% of the analysis
period.

The analysis of I/O performance is based on the default assumption that the
average read time for one database block is 10000 micro-seconds.

An explanation of the terminology used in this report is available when you
run the report with the 'ALL' level of detail.

task_name
---------
TASK_72988

從上面的資訊ADDM報告與top sql部分可以看到在快照26245到26246之間Database Time為16644秒。而找到的一條SQL消耗了76%的CPU時間。如果對這兩條SQL執行優化應該可以將CPU消耗顯著降低。而該SQL雖然每執行一次的時間是0.93秒，消耗的CPU時間只有0.76秒，但在週末的時間內一個小時都執行了16,029次，消耗的CPU時間是12249秒而且小機的CPU數量只有2顆(6核)，那麼每秒該SQL的執行次數就是=16029/3600=4.5次，所以大部分的CPU被該SQL所消耗了。這還是週末，如果上班時間該SQL執行的次數會以倍數增加，那麼CPU的消耗就會更高。

SQL語句如下:

SELECT COUNT(EmailDetail.F_EMAIL_DETAIL_ID) AS UnReadCount
  FROM T_LK_EMAIL_EMAILGROUP EmailGroup
  LEFT OUTER JOIN T_LK_EMAIL_DETAIL EmailDetail ON EmailGroup.F_EMAIL_GROUP_ID =
                                                   EmailDetail.F_EMAIL_GROUP_ID
                                               AND (EmailDetail.F_RECEIVER_ID =3440
                                                    OR
                                                   (EmailDetail.F_SENDER_ID =3418
                                                    AND
                                                   EmailDetail.F_RECEIVER_ID IS NULL))
                                               AND EmailDetail.F_EMAIL_STATE = '0'
                                               AND EmailDetail.F_RECORD_STATE = '0'
 WHERE EmailGroup.F_PARENT_ID = 0
   AND (EmailGroup.F_EMAIL_GROUP_ID != 4 OR
       (EmailGroup.F_GROUP_TYPE = 'USER' AND
       EmailGroup.F_USER_ID = 23402));

其執行計劃如下:

從執行計劃來看該SQL的cost也不高(執行時間是0.93秒，cpu時間是0.76秒)，從SQL的執行計劃來看見兩個表是使用的巢狀迴圈，而驅動表T_LK_EMAIL_EMAILGROUP的資料量是1w多行，T_LK_EMAIL_DETAIL表的數量是20w行左右。而表T_LK_EMAIL_EMAILGROUP執行全表掃描後滿足查詢條件的記錄有4條，所以就得對錶T_LK_EMAIL_DETAIL中的記錄遍歷4次來找到與驅動表相匹配的記錄,雖然每次執行時間不長，但是在併發執行次數高，而物理CPU數量不足的情況下還是會引發效能問題。而這兩個表有等值連線條件F_EMAIL_GROUP_ID，而且在驅動表中F_EMAIL_GROUP_ID列建立了索引，所以這裡選擇在表T_LK_EMAIL_DETAIL表的F_EMAIL_GROUP_ID列上建立索引之後執行計劃如下所示:

SQL執行計劃的COST顯示增加了，但SQL執行時間只有0.1s提高了10倍。在對該SQL優化之後，業務系統恢復正常，CPU使用率也維持在20%左右。

所以在優化時，不能簡單的根據SQL執行時間來判斷該SQL是否會引發效能問題，要具體問題具體分析。

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