ORACLE统计信息作业Stop job called because associated window was closed

一个Oracle 19c实例的告警日志出现告警， 具体的告警信息，如下所示：

xxxxx(3):Closing scheduler window
xxxxx(3):Closing Resource Manager plan via scheduler window
xxxxx(3):Clearing Resource Manager plan via parameter
2022-11-07T17:00:01.500300+08:00
opidrv aborting process J001 ospid (772) as a result of ORA-1013
2022-11-07T17:00:01.500542+08:00
Errors in file /xxxxx/diag/rdbms/edr/edr/trace/edr_j001_772.trc:
ORA-01013: user requested cancel of current operation
2022-11-07T17:00:03.209581+08:00
opidrv aborting process J000 ospid (770) as a result of ORA-1013
2022-11-07T17:00:03.211890+08:00
Errors in file /xxxxx/diag/rdbms/edr/edr/trace/edr_j000_770.trc:
ORA-01013: user requested cancel of current operation

出现这个错误，是因为有些Job运行异常了，Scheduler作业运行时间超出了维护窗口时间，我们检查Scheduler作业的执行历史记录信息

SQL> SET LINESIZE 1080;
SQL> COL LOG_ID FOR 9999999;
SQL> COL JOB_NAME FOR A16;
SQL> COL JOB_CLASS FOR A10;
SQL> COL ACTUAL_START_DATE FOR A16;
SQL> COL LOG_DATE FOR A16;
SQL> COL STATUS FOR A10;
SQL> COL RUN_DURATION FOR A16;
SQL> COL ADDITIONAL_INFO FOR A26;
SQL> SELECT JRD.LOG_ID,
  2         JRD.JOB_NAME,
  3         N.JOB_CLASS,
  4         TO_CHAR(JRD.ACTUAL_START_DATE,'YYYY-MM-DD HH24:MI:SS') ACTUAL_START_DATE,
  5         TO_CHAR(JRD.LOG_DATE, 'YYYY-MM-DD HH24:MI:SS') LOG_DATE,
  6         JRD.STATUS,
  7         JRD.ERROR#,
  8         JRD.RUN_DURATION ,
  9         JRD.ADDITIONAL_INFO
 10    FROM DBA_SCHEDULER_JOB_LOG N, DBA_SCHEDULER_JOB_RUN_DETAILS JRD
 11   WHERE N.LOG_ID = JRD.LOG_ID
 12       AND JRD.LOG_DATE >=TO_DATE('2022-11-07 16:30:00','yyyy-mm-dd hh24:mi:ss')
 13       AND JRD.LOG_DATE <=TO_DATE('2022-11-07 17:30:00','yyyy-mm-dd hh24:mi:ss')
 14       ORDER BY JRD.LOG_DATE DESC;

  LOG_ID JOB_NAME         JOB_CLASS  ACTUAL_START_DAT LOG_DATE         STATUS         ERROR# RUN_DURATION     ADDITIONAL_INFO
-------- ---------------- ---------- ---------------- ---------------- ---------- ---------- ---------------- --------------------------
  265608 ORA$AT_SA_SPC_SY ORA$AT_JCN 2022-11-07 00:06 2022-11-07 17:00 STOPPED             0 +000 00:53:21    REASON="Stop job called be
         _8582            RM_SA      :40              :00                                                     cause associated window wa
                                                                                                              s closed"

  265606 ORA$AT_OS_OPT_SY ORA$AT_JCN 2022-11-07 00:06 2022-11-07 17:00 STOPPED             0 +000 00:53:21    REASON="Stop job called be
         _8581            RM_OS      :39              :00                                                     cause associated window wa
                                                                                                              s closed"


SQL> 

注意：要切换到对应的PDB执行上面脚本：

如上所示，作业的STATUS为STOPPED，提示信息为：REASON="Stop job called because associated window was closed" ，我们还不清楚作业被停止的原因，我们接着继续分析，执行下面脚本

SET LINES 200 PAGES 0
SET LONG 10000000
COLUMN REPORT FORMAT A200
 
VARIABLE my_report CLOB;
BEGIN
:my_report := DBMS_STATS.REPORT_STATS_OPERATIONS (
since => SYSDATE-3
, until => SYSDATE-1
, detail_level => 'ALL'
, format => 'HTML'
, auto_only => TRUE
);
END;
/

spool stats_output.html
print my_report;
spool off;

通过上面的查询结果，gather_database_stats对应的操作32253超时了（TIMEOUT），将对应的OPID=32253输入下面的脚本，然后执行：

SET LINES 200 PAGES 0
SET LONG 10000000
COLUMN REPORT FORMAT A200
VARIABLE my_rep CLOB;
 
BEGIN
  :my_rep :=DBMS_STATS.REPORT_SINGLE_STATS_OPERATION (OPID => 32253,detail_level => 'ALL',FORMAT => 'HTML');
END;
/
 
 
spool stats_task_output.html
print my_rep;
spool off;

分析发现是在分析很大的分区表时出现了超时，如下截图所示：

我们还可以通过下面脚本收集一下信息进行分析、诊断

-- This is monitoring script to get useful information regarding maintenance windows and it's scheduled job.
-- It is from (Doc ID 1561498.1) with little changes..
ALTER SESSION SET NLS_TIMESTAMP_TZ_FORMAT ='DD/MM/YYYY HH24:MI:SS TZR TZD';
ALTER SESSION SET NLS_DATE_FORMAT ='DD-MM-YYYY HH24:MI:SS';
set pagesize 9999

spool /tmp/dba_autotask_client.html


set markup html on


show parameter job_queue_processes
show parameter statistics_level


select * from DBA_AUTOTASK_CLIENT;
select * from DBA_AUTOTASK_CLIENT_HISTORY where CLIENT_NAME like '%optimizer stats%' order by WINDOW_START_TIME;
select * from DBA_AUTOTASK_CLIENT_JOB;
select * from DBA_AUTOTASK_JOB_HISTORY where CLIENT_NAME like '%optimizer stats%' and JOB_START_TIME > systimestamp - 14 order by JOB_START_TIME; 
select * from DBA_AUTOTASK_OPERATION;
select * from DBA_AUTOTASK_SCHEDULE order by START_TIME;
select * from DBA_AUTOTASK_TASK;
select * from DBA_AUTOTASK_WINDOW_CLIENTS;
select * from DBA_AUTOTASK_WINDOW_HISTORY order by WINDOW_START_TIME;

SELECT TARGET, JOB_NAME, START_TIME, (END_TIME - START_TIME) AS ELAPSED_TIME, NOTES FROM DBA_OPTSTAT_OPERATION_TASKS WHERE STATUS = 'FAILED' order by 3;

select * from dba_scheduler_windows;
select * from dba_scheduler_window_groups;
select * from dba_scheduler_job_run_details where LOG_DATE >= TRUNC(SYSDATE) - 14 order by log_id;  
select * from DBA_SCHEDULER_JOB_LOG where LOG_DATE >= TRUNC(SYSDATE) -  14 order by log_id;         
SELECT program_name, program_action, enabled FROM dba_scheduler_programs;
spool off

那么根据官方文档Auto Optimizer Stats Often Fail with "Stop job called because associated window was closed" (Doc ID 2381223.1)^[1]，我们可以从下面几个角度去解决这个问题：

1：增加维护作业的时间窗口

这个比较简单，这里就不多说了，我也将时间创建从4小时调整到6小时。后续观察验证。

BEGIN
dbms_scheduler.disable(name => 'MONDAY_WINDOW');
dbms_scheduler.set_attribute(name => 'MONDAY_WINDOW',
attribute => 'DURATION',
value=> numtodsinterval(6, 'hour'));
dbms_scheduler.enable(name => 'MONDAY_WINDOW');
END;
/

2：调优DBMS_STATS的选项

Auto_Degree   : Likely to reduce gather times significantly if the schema has some large tables.
Concurrent    : Likely to reduce gather times significantly if the schema consistes of a large number of smaller tables

* using both needs high & plenty of system resource, otherwise it may exhaust system resource.


Set Auto_degree globally:

exec dbms_stats.set_global_prefs('DEGREE', DBMS_STATS.AUTO_DEGREE)


Set Concurrent Stats gathering globally:

exec dbms_stats.set_global_prefs('CONCURRENT','AUTOMATIC')

因为这个案例中遇到都是一些采集大表统计信息超时，那么可以加大收集统计信息的并行度

SQL> exec dbms_stats.set_global_prefs('DEGREE', DBMS_STATS.AUTO_DEGREE)

PL/SQL procedure successfully completed.

3：追踪分析dbms_stats为什么运行那么长时间

这个比较复杂和繁琐，这里就不展开阐述了。

参考资料