[20191203]大量resmgrcpu quantum等待事件.txt

lfree發表於2019-12-03

[20191203]大量resmgrcpu quantum等待事件.txt

--//生產系統遇到大量resmgr:cpu quantum等待,出現嚴重問題是12.1號(正好星期天).機器已經重啟.事後分析.

1.環境:
SYS@192.168.xx.zzz:1521/orcl> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
IBMPC/WIN_NT64-9.1.0           11.2.0.1.0     Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
--//windows的版本,11.2.0.1 這個版本問題多多...

2.分析:
SYS@192.168.xx.zzz:1521/orcl> select trunc(sysdate-2)+8/24 , trunc(sysdate-2)+9/24 from dual ;
TRUNC(SYSDATE-2)+8/ TRUNC(SYSDATE-2)+9/
------------------- -------------------
2019-12-01 08:00:00 2019-12-01 09:00:00

SYS@192.168.xx.zzz:1521/orcl> @ tpt/ash/dash_wait_chains event2 1=1 trunc(sysdate-2)+8/24  trunc(sysdate-2)+9/24

-- Display ASH Wait Chain Signatures script v0.2 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This     SECONDS        AAS WAIT_CHAIN
------ ---------- ---------- -------------------------------
  64%       25240          7 -> ON CPU
  36%       14360          4 -> resmgr:cpu quantum
   0%          30          0 -> control file parallel write
   0%          10          0 -> db file scattered read

SYS@192.168.xx.zzz:1521/orcl> show parameter cpu_count
NAME       TYPE     VALUE
---------- -------- -----
cpu_count  integer  6

--//25240/3600 = 7.01.而僅僅6個CPU,沒開啟多執行緒嗎?無法登入伺服器不瞭解相關設定.明顯cpu資源已經耗盡,無法相應前臺的登入請求,大量
--//ora-12xxx錯誤.

SYS@192.168.xx.zzz:1521/orcl> @ tpt/ash/dash_wait_chains event2 session_type='FOREGROUND' trunc(sysdate-2)+8/24  trunc(sysdate-2)+9/24
-- Display ASH Wait Chain Signatures script v0.2 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This     SECONDS        AAS WAIT_CHAIN
------ ---------- ---------- --------------------------------
  98%       14230          4 -> resmgr:cpu quantum
   2%         340         .1 -> ON CPU
--//前臺主要等待事件是resmgr:cpu quantum

SYS@192.168.xx.zzz:1521/orcl> @ tpt/ash/dash_wait_chains program2||event2 1=1 trunc(sysdate-2)+8/24  trunc(sysdate-2)+9/24
-- Display ASH Wait Chain Signatures script v0.2 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This     SECONDS        AAS WAIT_CHAIN
------ ---------- ---------- ----------------------------------------
  63%       24850        6.9 -> rman.exe ON CPU
  33%       12920        3.6 -> (wnwp.exe) resmgr:cpu quantum
   1%         420         .1 -> (TJWorklist.exe) resmgr:cpu quantum
   1%         340         .1 -> (wnwp.exe) ON CPU
   1%         300         .1 -> (rman.exe) resmgr:cpu quantum
   1%         290         .1 -> (zxtopacs.exe) resmgr:cpu quantum
   0%         130          0 -> (Mnnn) resmgr:cpu quantum
   0%         120          0 -> (oracle) resmgr:cpu quantum
   0%          90          0 -> (Jnnn) resmgr:cpu quantum
   0%          90          0 -> (plsqldev.exe) resmgr:cpu quantum
   0%          30          0 -> (CKPT) control file parallel write
   0%          20          0 -> (CTWR) ON CPU
   0%          20          0 -> (PMON) ON CPU
   0%          10          0 -> (Mnnn) db file scattered read
   0%          10          0 -> (DBRM) ON CPU
15 rows selected.
--//還在備份什麼回事....備份沒完成嗎?

SYS@192.168.xx.zzz:1521/orcl> @ ev_name "resmgr:cpu quantum"
    EVENT#   EVENT_ID NAME               PARAMETER1           PARAMETER2           PARAMETER3           WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS
---------- ---------- ------------------ -------------------- -------------------- -------------------- ------------- ----------- ----------
       286 1452455426 resmgr:cpu quantum location                                                          2396326234          10 Scheduler

--//查詢v$rman_backup_job_details檢視發現備份時間與後臺排程的分析時間重合.都是22點上下.結果不貼出了.

SELECT *
  FROM DBA_AUTOTASK_JOB_HISTORY
 WHERE client_name       =  'auto optimizer stats collection'
   AND window_start_time >= '2019/11/29 22:00:00.378000 +08:00'
 order by 3;

SYS@192.168.xx.zzz:1521/orcl> select * from DBA_AUTOTASK_JOB_HISTORY where client_name='auto optimizer stats collection' and window_start_time>= '2019/11/29 22:00:00.378000 +08:00' order by 3;
CLIENT_NAME                     WINDOW_NAME          WINDOW_START_TIME                        WINDOW_DURATION                JOB_NAME                JOB_STATUS JOB_START_TIME                     JOB_DURATION    JOB_ERROR JOB_INFO
------------------------------- -------------------- ---------------------------------------- ------------------------------ ----------------------- ---------- ---------------------------------- -------------- ---------- --------------------
auto optimizer stats collection FRIDAY_WINDOW        2019-11-29 22:00:00.378000 +08:00        +000000000 03:59:59.668000     ORA$AT_OS_OPT_SY_16545  SUCCEEDED  2019-11-29 22:00:00.955000 +08:00  +000 00:01:11           0
auto optimizer stats collection SATURDAY_WINDOW      2019-11-30 06:00:00.135000 +08:00        +000000000 19:59:59.914000     ORA$AT_OS_OPT_SY_16550  SUCCEEDED  2019-11-30 22:02:52.153000 +08:00  +000 00:00:11           0
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
auto optimizer stats collection SATURDAY_WINDOW      2019-11-30 06:00:00.135000 +08:00        +000000000 19:59:59.914000     ORA$AT_OS_OPT_SY_16546  SUCCEEDED  2019-11-30 06:00:01.554000 +08:00  +000 00:00:14           0
auto optimizer stats collection SATURDAY_WINDOW      2019-11-30 06:00:00.135000 +08:00        +000000000 19:59:59.914000     ORA$AT_OS_OPT_SY_16547  SUCCEEDED  2019-11-30 10:00:15.683000 +08:00  +000 00:00:42           0
auto optimizer stats collection SATURDAY_WINDOW      2019-11-30 06:00:00.135000 +08:00        +000000000 19:59:59.914000     ORA$AT_OS_OPT_SY_16548  SUCCEEDED  2019-11-30 14:01:08.141000 +08:00  +000 00:00:10           0
auto optimizer stats collection SATURDAY_WINDOW      2019-11-30 06:00:00.135000 +08:00        +000000000 19:59:59.914000     ORA$AT_OS_OPT_SY_16549  SUCCEEDED  2019-11-30 18:01:59.976000 +08:00  +000 00:00:06           0
auto optimizer stats collection SUNDAY_WINDOW        2019-12-01 06:00:00.200000 +08:00        +000000000 19:59:59.855000     ORA$AT_OS_OPT_SY_16564  SUCCEEDED  2019-12-01 10:05:29.013000 +08:00  +000 00:00:56           0
auto optimizer stats collection SUNDAY_WINDOW        2019-12-01 06:00:00.200000 +08:00        +000000000 19:59:59.855000     ORA$AT_OS_OPT_SY_16551  SUCCEEDED  2019-12-01 06:00:02.259000 +08:00  +000 00:04:17           0
8 rows selected.

--//注意看下劃線.WINDOW_START_TIME='2019-11-30 06:00:00.135000 +08:00',而實際上JOB_START_TIME在2019-11-30 22:02:52.153000 +08:00
--//才開始執行.執行時間僅僅11秒.說明11.30號已經出現問題.
--//注:12.2下午我已經停止auto optimizer stats collection的分析.
--//exec DBMS_AUTO_TASK_ADMIN.DISABLE(client_name => 'auto optimizer stats collection',operation => NULL,window_name => NULL);
--//我不知道是備份還是auto optimizer stats collection分析導致出現效能問題.兩者重合了,啟用了resmgr:cpu quantum這個bug.
--//如果上網查詢: resmgr:cpu quantum,可以發現大量連結提示如下修改:

alter system set resource_manager_plan='';
execute dbms_scheduler.set_attribute('WEEKNIGHT_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('WEEKEND_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('<window name>','RESOURCE_PLAN','');

execute dbms_scheduler.set_attribute('SATURDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('SUNDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('MONDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('TUESDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('WEDNESDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('THURSDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('FRIDAY_WINDOW','RESOURCE_PLAN','');

--//問題在於我們根本沒有啟動資源管理.
SYS@192.168.xx.zzz:1521/orcl> show parameter resource_manager_plan
NAME                  TYPE    VALUE
--------------------- ------- --------
resource_manager_plan string

SYS@192.168.xx.zzz:1521/orcl> @ hide _resource_manager_always_o
NAME                           DESCRIPTION                         DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD
------------------------------ ----------------------------------- ------------- ------------- ------------ ----- ---------
_io_resource_manager_always_on io resource manager always on       TRUE          FALSE         FALSE        FALSE FALSE
_resource_manager_always_off   disable the resource manager always TRUE          FALSE         FALSE        FALSE FALSE
_resource_manager_always_on    enable the resource manager always  TRUE          TRUE          TRUE         FALSE FALSE

--//SQL> alter system set "_resource_manager_always_off"=true scope=spfile;
--//SQL> alter system set "_resource_manager_always_on"=false scope=spfile;

SYS@192.168.xx.zzz:1521/orcl> SELECT window_name ,resource_plan ,repeat_interval ,duration FROM DBA_SCHEDULER_WINDOWS;
WINDOW_NAME      RESOURCE_PLAN            REPEAT_INTERVAL                                                           DURATION
---------------- ------------------------ ------------------------------------------------------------------------- -------------
MONDAY_WINDOW    DEFAULT_MAINTENANCE_PLAN freq=daily;byday=MON;byhour=22;byminute=0; bysecond=0                     +000 04:00:00
TUESDAY_WINDOW   DEFAULT_MAINTENANCE_PLAN freq=daily;byday=TUE;byhour=22;byminute=0; bysecond=0                     +000 04:00:00
WEDNESDAY_WINDOW DEFAULT_MAINTENANCE_PLAN freq=daily;byday=WED;byhour=22;byminute=0; bysecond=0                     +000 04:00:00
THURSDAY_WINDOW  DEFAULT_MAINTENANCE_PLAN freq=daily;byday=THU;byhour=22;byminute=0; bysecond=0                     +000 04:00:00
FRIDAY_WINDOW    DEFAULT_MAINTENANCE_PLAN freq=daily;byday=FRI;byhour=22;byminute=0; bysecond=0                     +000 04:00:00
SATURDAY_WINDOW  DEFAULT_MAINTENANCE_PLAN freq=daily;byday=SAT;byhour=6;byminute=0; bysecond=0                      +000 20:00:00
SUNDAY_WINDOW    DEFAULT_MAINTENANCE_PLAN freq=daily;byday=SUN;byhour=6;byminute=0; bysecond=0                      +000 20:00:00
WEEKNIGHT_WINDOW                          freq=daily;byday=MON,TUE,WED,THU,FRI;byhour=22;byminute=0; bysecond=0     +000 08:00:00
WEEKEND_WINDOW                            freq=daily;byday=SAT;byhour=0;byminute=0;bysecond=0                       +002 00:00:00
9 rows selected.
--//注意看DURATION時間.
--//難道WINDOW_NAME受DEFAULT_MAINTENANCE_PLAN的控制.

--//解決如下:
execute dbms_scheduler.set_attribute('SATURDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('SUNDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('MONDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('TUESDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('WEDNESDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('THURSDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('FRIDAY_WINDOW','RESOURCE_PLAN','');

SYS@192.168.xx.zzz:1521/orcl> SELECT window_name ,resource_plan ,repeat_interval ,duration FROM DBA_SCHEDULER_WINDOWS;
WINDOW_NAME      RESOURCE_PLAN             REPEAT_INTERVAL                                                       DURATION
---------------- ------------------------- --------------------------------------------------------------------- -------------
MONDAY_WINDOW                              freq=daily;byday=MON;byhour=22;byminute=0; bysecond=0                 +000 04:00:00
TUESDAY_WINDOW                             freq=daily;byday=TUE;byhour=22;byminute=0; bysecond=0                 +000 04:00:00
WEDNESDAY_WINDOW                           freq=daily;byday=WED;byhour=22;byminute=0; bysecond=0                 +000 04:00:00
THURSDAY_WINDOW                            freq=daily;byday=THU;byhour=22;byminute=0; bysecond=0                 +000 04:00:00
FRIDAY_WINDOW                              freq=daily;byday=FRI;byhour=22;byminute=0; bysecond=0                 +000 04:00:00
SATURDAY_WINDOW                            freq=daily;byday=SAT;byhour=6;byminute=0; bysecond=0                  +000 20:00:00
SUNDAY_WINDOW                              freq=daily;byday=SUN;byhour=6;byminute=0; bysecond=0                  +000 20:00:00
WEEKNIGHT_WINDOW                           freq=daily;byday=MON,TUE,WED,THU,FRI;byhour=22;byminute=0; bysecond=0 +000 08:00:00
WEEKEND_WINDOW                             freq=daily;byday=SAT;byhour=0;byminute=0;bysecond=0                   +002 00:00:00
9 rows selected.

alter system set "_resource_manager_always_off"=true scope=spfile;
alter system set "_resource_manager_always_on"=false scope=spfile;

--//注:修改這2個引數要重啟.我目前無法重啟.先暫時停止auto optimizer stats collection的分析.
SYS@192.168.xx.zzz:1521/orcl> exec DBMS_AUTO_TASK_ADMIN.DISABLE(client_name => 'auto optimizer stats collection',operation => NULL,window_name => NULL);
PL/SQL procedure successfully completed.

--//分析主要參考連結:https://www.iteye.com/blog/dbzone-2359348

總結:
--//解決如下:
execute dbms_scheduler.set_attribute('SATURDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('SUNDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('MONDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('TUESDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('WEDNESDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('THURSDAY_WINDOW','RESOURCE_PLAN','');
execute dbms_scheduler.set_attribute('FRIDAY_WINDOW','RESOURCE_PLAN','');

alter system set "_resource_manager_always_off"=true scope=spfile;
alter system set "_resource_manager_always_on"=false scope=spfile;

--//臨時解決,關閉相關schedule任務.
--//exec DBMS_AUTO_TASK_ADMIN.DISABLE(client_name => 'auto optimizer stats collection',operation => NULL,window_name => NULL);

SYS@192.168.xx.zzz:1521/orcl> column ATTRIBUTES format a55
SYS@192.168.xx.zzz:1521/orcl> select client_name, status,attributes,window_group from dba_autotask_client;
CLIENT_NAME                     STATUS           ATTRIBUTES                                              WINDOW_GROUP
------------------------------- ---------------- ------------------------------------------------------- ---------------
auto optimizer stats collection DISABLED         ON BY DEFAULT, VOLATILE, SAFE TO KILL                   ORA$AT_WGRP_OS
auto space advisor              DISABLED         ON BY DEFAULT, VOLATILE, SAFE TO KILL                   ORA$AT_WGRP_SA
sql tuning advisor              DISABLED         ONCE PER WINDOW, ON BY DEFAULT, VOLATILE, SAFE TO KILL  ORA$AT_WGRP_SQ

SYS@192.168.xx.zzz:1521/orcl> @ bg dbrm
old   1: select  addr,pid,spid,program from v$process where background=1 and PROGRAM like upper('%&1%')
new   1: select  addr,pid,spid,program from v$process where background=1 and PROGRAM like upper('%dbrm%')
ADDR                 PID SPID   PROGRAM
---------------- ------- ------ --------------------------
0000000390614218       6 6672   ORACLE.EXE (DBRM)

--//正常設定"_resource_manager_always_off"=true,"_resource_manager_always_on"=false,應該看不到DBRM程式,我給在測試環境測試看看.

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

相關文章