专栏首页杨建荣的学习笔记停止数据库没有响应的问题分析(r9笔记第51天)

停止数据库没有响应的问题分析(r9笔记第51天)

昨天写了一篇停库没有响应的问题分析,其实对于我来说,还是有些不太踏实,里面有几点需要改进。

因为是测试环境,所以操作的时候就随意了一些,如果是生产环境,直接kill进程是很不规范的。对于启库停库的时间把握,只是感觉有延迟,但是延迟究竟有多大还是不够严谨;问题的原因最后没有给出很清晰的答案,主要是因为后面自己没有经过大量的测试,所以这个地方还是不够严谨。

我们来继续分析一下。

目前的问题可以简化为两个:停库慢,启库慢。

我们来逐个击破。

首先是停库慢,shutdown immediate之后,就没有任何反应了,等了若干分钟都是如此。这如果是一个线上环境可是要出大问题的。

日志如下:

Shutting down instance (immediate) Shutting down instance: further logons disabled Stopping background process MMNL Stopping background process MMON License high water mark = 2 All dispatchers and shared servers shutdown ALTER DATABASE CLOSE NORMAL ORA-1109 signalled during: ALTER DATABASE CLOSE NORMAL... ALTER DATABASE DISMOUNT Shutting down archive processes Archiving is disabled Tue Jul 05 10:15:25 2016 。。。

伴随有如下的错误。

TNS-12535: TNS:operation timed out ns secondary err code: 12560 nt main err code: 505 TNS-00505: Operation timed out nt secondary err code: 0 nt OS err code: 0 Client address: <unknown> 所以可以看出问题似乎出来网络层面。如果查看日志目录下的文件。就会发现最新的更新文件都是下面的样子。

-rw-r----- 1 oracle oinstall 2226 Jul 5 09:52 dgtest_nsv1_22580.trc -rw-r----- 1 oracle oinstall 159 Jul 5 10:00 dgtest_nsv1_22586.trm -rw-r----- 1 oracle oinstall 2226 Jul 5 10:00 dgtest_nsv1_22586.trc -rw-r----- 1 oracle oinstall 134 Jul 5 10:09 dgtest_nsv1_22602.trm -rw-r----- 1 oracle oinstall 2226 Jul 5 10:09 dgtest_nsv1_22602.trc -rw-r----- 1 oracle oinstall 82 Jul 5 10:14 dgtest_ora_22767.trm -rw-r----- 1 oracle oinstall 1042 Jul 5 10:14 dgtest_ora_22767.trc -rw-r----- 1 oracle oinstall 7765351 Jul 5 10:16 drcdgtest.log -rw-r----- 1 oracle oinstall 288 Jul 5 10:17 dgtest_nsv1_22613.trm -rw-r----- 1 oracle oinstall 4468 Jul 5 10:17 dgtest_nsv1_22613.trc -rw-r----- 1 oracle oinstall 23410904 Jul 5 10:17 alert_dgtest.log

可以看出还是在DG Broker相关的地方存在一些检查。

如果查看dr日志,会发现下面的信息。

07/05/2016 10:13:25 Failed to connect to remote database dgtest2. Error is ORA-12170 Failed to send message to site dgtest2. Error code is ORA-12170. Data Guard Broker Status Summary: Type Name Severity Status Configuration dg_test_gc Warning ORA-16607 Primary Database dgtest Error ORA-16782 Physical Standby Database dgtest2 Error ORA-12170 07/05/2016 10:16:25 Failed to connect to remote database dgtest2. Error is ORA-12170 Failed to send message to site dgtest2. Error code is ORA-12170. 所以问题已经看起来很明显了。

然后在若干分钟后,实例是终止了。然后我们继续查看startup

这个时候发现startup也卡住了。在alter database open阶段,没有任何反应。日志也没有输出。过了好一会儿,看到突然输出了不少的日志。然后open失败。

SQL> alter database open; alter database open * ERROR at line 1: ORA-03113: end-of-file on communication channel Process ID: 23096 Session ID: 96 Serial number: 9 查看alert日志,发现有了新进展,日志如下:

Errors in file /U01/app/oracle/diag/rdbms/dgtest/dgtest/trace/dgtest_arc1_23160.trc: ORA-19815: WARNING: db_recovery_file_dest_size of 4322230272 bytes is 100.00% used, and has 0 remaining bytes available. ARC1: Error 19809 Creating archive log file to '/U01/app/oracle/fast_recovery_area/DGTEST/archivelog/2016_07_05/o1_mf_1_127_%u_.arc' ARCH: Archival stopped, error occurred. Will continue retrying ORACLE Instance dgtest - Archival Error ORA-16038: log 1 sequence# 127 cannot be archived ORA-19809: limit exceeded for recovery files ORA-00312: online log 1 thread 1: '/U01/app/oracle/oradata/dgtest/redo01.log' Archiver process freed from errors. No longer stopped ARC2: LGWR is scheduled to archive destination LOG_ARCHIVE_DEST_2 after log switch ARCH: Archival stopped, error occurred. Will continue retrying ORACLE Instance dgtest - Archival Error ORA-16014: log 1 sequence# 127 not archived, no available destinations ORA-00312: online log 1 thread 1: '/U01/app/oracle/oradata/dgtest/redo01.log' 可以看到问题的原因还是和空间有关,而这里的空间就是闪回区大小了,有一个参数可以灵活控制。

当然这个时候查看闪回区大小肯定是有问题的。而磁盘空间还是有空余的。

SQL> select *from v$flash_recovery_area_usage FILE_TYPE PERCENT_SPACE_USED PERCENT_SPACE_RECLAIMABLE NUMBER_OF_FILES -------------------- ------------------ ------------------------- --------------- CONTROL FILE 0 0 0 REDO LOG 0 0 0 ARCHIVED LOG 99.48 0 121 BACKUP PIECE 0 0 0 IMAGE COPY 0 0 0 FLASHBACK LOG 0 0 0 FOREIGN ARCHIVED LOG 0 0 0 我们修复一下,调大一些。

SQL> alter system set db_recovery_file_dest_size=5G; System altered. 闪回区的问题就解决了。这个时候继续启动到open阶段,发现虽然启动没有问题了,但是速度依旧是慢。 所以这个时候问题回到原点,虽然发现了问题,但是停库慢,启库慢的问题还是没有解决。

我认真查看了日志,还是发现了不少网络超时的日志。所以决定先把DG Broker的进程先停掉。

TNS-12535: TNS:operation timed out ns secondary err code: 12560 nt main err code: 505 TNS-00505: Operation timed out nt secondary err code: 0 nt OS err code: 0 Client address: <unknown> Tue Jul 05 10:39:58 2016 NSV1 started with pid=22, OS id=23540 SQL> alter system set dg_broker_start=false; System altered.

当然后续还看到警告日志,发现归档路径其实也要考虑。

SQL> alter system set log_archive_dest_2=''; System altered.

能够看到一个有意思的地方就是CKPT的一些信息。

马上能够看到CKPT的日志有了更新。 -rw-r----- 1 oracle oinstall 23447074 Jul 5 10:51 alert_dgtest.log -rw-r----- 1 oracle oinstall 93 Jul 5 10:52 dgtest_ckpt_23300.trm -rw-r----- 1 oracle oinstall 1097 Jul 5 10:52 dgtest_ckpt_23300.trc

日志如下:

*** 2016-07-05 10:37:52.426 *** SESSION ID:(126.1) 2016-07-05 10:37:52.426 *** CLIENT ID:() 2016-07-05 10:37:52.426 *** SERVICE NAME:() 2016-07-05 10:37:52.426 *** MODULE NAME:() 2016-07-05 10:37:52.426 *** ACTION NAME:() 2016-07-05 10:37:52.426 Adjusting CKPT timeout to 1s because LGWR dest is enabled *** 2016-07-05 10:40:52.614 Control file enqueue hold time tracking dump at time: 382179 1: 2920ms (rw) file: kct.c line: 2522 count: 140733193388033 total: 2920ms time: 140733193769848 Reverting CKPT timeout to 3s default 当然后面发现还是有警告,这个排除只有一个参数了。

NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ log_archive_config string dg_config=(dgtest,dgtest2)

SQL> alter system set log_archive_config=''; System altered.

修复之后,停库就很快了。大概10多秒就能搞定。

10:59:02 SQL> shutdown immediate Database closed. Database dismounted. ORACLE instance shut down. 10:59:14 SQL>

这个时候还有一个问题是启库慢。

10:59:34 SQL> startup ORACLE instance started. Database mounted. Database opened. 11:00:14 SQL> 我认真查看了下alert日志发现启动的日志中含有的参数如下:

System parameters with non-default values: processes = 150 pre_page_sga = TRUE lock_sga = FALSE shared_pool_size = 848M large_pool_size = 16M java_pool_size = 16M streams_pool_size = 0 sga_target = 0 。。。

看到这里其实问题就很明显了,还有一个参数需要修改,是pre_page_sga默认是false,而现在是true

11:01:55 SQL> alter system set pre_page_sga=false scope=spfile; System altered.

然后再次启动,就会发现启库快了很多。

11:02:28 SQL> startup ORACLE instance started. Database mounted. Database opened. 11:02:37 SQL> 这样的情况就是让人基本满意的。

本文分享自微信公众号 - 杨建荣的学习笔记(jianrong-notes),作者:杨建荣

原文出处及转载信息见文内详细说明,如有侵权,请联系 yunjia_community@tencent.com 删除。

原始发表时间:2016-07-05

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

我来说两句

0 条评论
登录 后参与评论

相关文章

  • DBA和开发同事的一些代沟(四) (r7笔记第36天)

    DBA和开发都是两个可爱的团队,如果合作起来,那战斗力可是杠杠的。如果合作不愉快,那就是一件简单至极的事情都能扯皮几天几夜,而且还解决不了。 今天出公司的时候碰...

    jeanron100
  • 巧用闪回数据库来查看历史数据 (r10笔记第47天)

    国庆期间有一个例行维护的任务,需要在大早上7点起来,先根据业务指定的SQL查出指定数据,然后运行一个存储过程来更新数据。 查出来的这部分数据需要...

    jeanron100
  • 使用shell脚本查看数据库负载情况(第二篇)(r3笔记第92天)

    在之前写了一个shell脚本,能够得到一个基于时间点的数据库负载报告。 使用shell脚本查看数据库负载情况 http://blog.itpub.net/237...

    jeanron100
  • vim部分常用的命令(更新时间:2018/11/07)

    醉生萌死
  • 更智能化的CDN技术,CDN迈向3.0时代

    我们的生活无时不刻不依赖着网络,伴随着终日对网速慢的抱怨和诅咒,同时也享受着网络技术发展带来的红利。怀着对技术细节刨根问底的执着,我们会发现原来身边还存在着像C...

    SDNLAB
  • “爱康国宾私有化”基金产品吊诡 缺钱的张黎刚即将丧失游戏资格?

    资本围绕体检业展开的争夺可谓如火如荼,爱康国宾董事长张黎刚为狙击美年大健康的收购要约可谓煞费苦心,从最初的毒丸计划,到最近撕破脸皮与美年的对簿公堂、实名举报,连...

    曾响铃
  • Python 增加博客园阅读量

      一般来说,阅读量是通过 ip 识别的,如果一个 ip 已经请求过了,下一次就不再增加阅读量。因此,想要增加阅读量,就需要不同的 ip 进行请求。大致清楚了之...

    py3study
  • Android 教程:开启 Chrome 的阅读模式

    ? 如今许多网站版面上都排布着一些大大小小的广告,这些无关内容不仅侵蚀版面,也在一定程度上干扰我们阅读。为了营造一个干净的阅读环境,一些浏览器内置了阅读模式。...

    非著名程序员
  • PostgreSQL Vacuum again!

    xmin 用于表示这一行的事务ID (我们这里插入一行数据,并且查看这行数据)

    AustinDatabases
  • 语音交互有哪些优势与劣势?

    语音交互是指人与人、人与设备之间,通过自然语音进行信息传递的过程。人与人之间通过语音来传递信息、交流感情等等,其实就是一种最基本的人与人之间的语音交互。

    深蓝学院

扫码关注云+社区

领取腾讯云代金券