2017-10-29 DBA日记,dbms_stats打开并行度后引发递归登录次数过高

数据库 waitig 496℃ 百度已收录 0评论

案例描述

在2017-10-27 17:00时,通过监控软件发现RAC数据库的节点二每隔5分钟出现一次每秒登录的用户数达到4,采样时间为1分钟,那就是说一分钟内有240次登录。
节点二除了为业务程序提供服务上,也是数据库后台作业运行专用节点。

问题定义

是什么原因导致数据库在一分钟内有240次登录呢?

收集和分析数据

数据库监听器日志信息收集

ssh 到rac2 上
#获取监听日志存放位置
lsnrctl status   
vi ./log.xml
并使用之前的python程序分析监听日志,没有发现可疑点。

收集数据库实例日志

打开alert_rac2.log也没有发现可疑点。

分析数据库收集登录信息

执行以下程序后,发现在14:33:00 时,1秒以内有200多个用户登录。

declare 
r1 int;
r2 int;
diff int;
begin
for i in 1 .. 150 loop
select value into r1 from gv$sysstat where inst_id=2 and name in ('logons cumulative');
DBMS_LOCK.SLEEP(1);
select value into r2 from gv$sysstat where inst_id=2 and name in ('logons cumulative');
diff:=r2-r1;
DBMS_OUTPUT.PUT_LINE(to_char(sysdate,'YYYY-MM-DD HH24:MI:SS'));
DBMS_OUTPUT.PUT_LINE(to_char(diff));
DBMS_OUTPUT.PUT_LINE('----------------------------------------------------------------------');
end loop;
end;
/

收集在14:33:00 时,rac2正在运行会话

  • 查询会话表gv$session 及 gv$active_session_history
  • 查询后台作业表dba_scheduler_jobs,dba_scheduler_jon_run_details
  • 结果发现在后台一个scheduler job的运行时间与数据库自行记录登录的时间非常吻合。

详细分析14:33:00 时运行的作业job_x 特点

  • 发现该作业是调用一个package里面的一个存储过程
  • 存储过程都是打开了自治事务的标记
  • 存储过程有一步调用另外一个package pkg_tool去收集表的统计值
    • 打开收表统计值的代码查看,结果代码在收集统计信息的并行度是16,这是个一个交易系统,一个作业使用16个并行度,那么如果多个类似这样的作业同时运行,那岂不是把数据库的CPU资源都消耗完,所以这时我不管是不是由于它造成的,果度更改并行度为1,结果发现每秒登录数恢复到正常水平.
    • 代码更改前
    PROCEDURE GatherTableStats(p_table_name varchar2) IS
    PRAGMA AUTONOMOUS_TRANSACTION;
    v_date_CHR      VARCHAR2(8);  --回单月份;

BEGIN DBMS_STATS.GATHER_TABLE_STATS(ownname => ‘CBS’,tabname => p_table_name,cascade => true,degree=>16); END GatherTableStats; -
代码更改后
 PROCEDURE GatherTableStats(p_table_name varchar2) IS PRAGMA AUTONOMOUS_TRANSACTION; v_date_CHR VARCHAR2(8); –回单月份; BEGIN DBMS_STATS.GATHER_TABLE_STATS(ownname => ‘CBS’,tabname => p_table_name,cascade => true,degree=>1); END GatherTableStats;
“`

验证

完成代码更改后,通过监控软件观察,每秒登录数恢复到正常水平,每秒0.4登录。

结论

  1. dbms_stats打开并行度后,oracle后台的进程会在后台并发登录,这些后台并发登录在监听器日志里是不会记录的,在v$session中也难以发现。
  2. dbms_stats打开并行度数量越多,后台进程登录的次数越高。
  3. 在11.2.0.4中oracle除了自动收集logons cumulative,还会收集user logons cumulative,其中logons cumulative包含了后台+前端用户登录,user logons cumulative只有前端用户登录。
  4. 在线交易系统是不能使用显示并行的。

备注

该问题困扰了我三天的时间,从怀疑前端再到数据库的bug,数据库后台作作来,数据库系统进程等多方面,通过一一排查核对,再加上阅读用户代码后,再最终发现原因所在。
但是,这里的原因并不是根本的原因,我在这里面还有很多疑问并没有得到充分解答,如,该作业在10-27 17:00前已经运行了一个多月,并且代码在些期间并没有修改过,为什么这时才发生呢?也有同事告诉我可能是因为数据的问题。 又如:在进行并发收集统计信息时,oracle到底激活了那些后台进程呢?这些进程又是在做什么呢?
这个事件的真相就像世界的不解之迷那样,只要把问题解决了,也防止再发生了,就没有人再去纠结了,毕竟有趣的事比这个多得去了,我们不必要把时间和精力花在不会产生效益的地方。


本文由【waitig】发表在等英博客
本文固定链接:2017-10-29 DBA日记,dbms_stats打开并行度后引发递归登录次数过高
欢迎关注本站官方公众号,每日都有干货分享!
等英博客官方公众号
点赞 (0)分享 (0)