direct path write temp引起的数据库重启以及ogg进程停止

简介:

集中客户系统在2016年11月8日17点业务反馈系统链接不上,是不是有问题。当即查看系统

[oracle@SIDDB01 hwbackup3]$crs_stat -t -v                               

Name           Type           R/RA   F/FT   Target    State     Host    

----------------------------------------------------------------------  

ora....D1.inst application    1/5    0/0    ONLINE    ONLINE    siddb01 

ora....D2.inst application    0/5    0/0    ONLINE    ONLINE    esbdb01 

ora....ID2.srv application    0/0    0/0    ONLINE    ONLINE    esbdb01 

ora....Bsrv.cs application    0/0    0/1    ONLINE    ONLINE    esbdb01 

ora....ID1.srv application    0/0    0/0    ONLINE    ONLINE    siddb01 

ora....Dsrv.cs application    0/0    0/1    ONLINE    ONLINE    siddb01 

ora.ESBSID.db  application    0/0    0/1    ONLINE    ONLINE    siddb01 

ora....01.lsnr application    0/5    0/0    ONLINE    ONLINE    esbdb01 

ora....b01.gsd application    2/5    0/0    ONLINE    OFFLINE           

ora....b01.ons application    0/3    0/0    ONLINE    ONLINE    esbdb01 

ora....b01.vip application    0/0    0/0    ONLINE    ONLINE    esbdb01 

ora....01.lsnr application    0/5    0/0    ONLINE    ONLINE    siddb01 

ora....b01.gsd application    5/5    0/0    ONLINE    OFFLINE           

ora....b01.ons application    1/3    0/0    ONLINE    ONLINE    siddb01 

ora....b01.vip application    0/0    0/0    ONLINE    ONLINE    siddb01 


因为监控5分钟自动采集还没来得及嗅探,数据库自启动完成,所以运维人员都不知道数据库发生了什么事情。查看一下CRS日志情况,看看是否有切换动作;

                                                                                                                                                            

2016-11-02 16:26:21.226: [  CRSAPP][2990760] CheckResource error for ora.siddb01.vip error code = -1                                                        

2016-11-08 17:08:15.846: [  CRSEVT][3027957] CAAMonitorHandler :: 0:Could not join /oracle/crs/bin/racgwrap(check)                                          

category: 1234, operation: scls_process_join, loc: childcrash, OS error: 0, other: Abnormal termination of the child                                        

                                                                                                                                                            

2016-11-08 17:08:25.193: [  CRSEVT][3027957] CAAMonitorHandler :: 0:Action Script /oracle/crs/bin/racgwrap(check) timed out for ora.siddb01.vip! (timeout=60

)                                                                                                                                                           

2016-11-08 17:08:25.194: [  CRSAPP][3027957] CheckResource error for ora.siddb01.vip error code = -2                                                        

2016-11-08 17:09:53.467: [  CRSEVT][3027958] CAAMonitorHandler :: 0:Could not join /oracle/product/10.2.0/bin/racgwrap(check)                               

category: 1234, operation: scls_process_join, loc: childcrash, OS error: 0, other: Abnormal termination of the child                                        

                                                                                                                                                            

2016-11-08 17:10:07.582: [  CRSAPP][3027958] CheckResource error for ora.siddb01.LISTENER_SIDDB01.lsnr error code = -1                                      

2016-11-08 17:10:14.102: [  CRSEVT][3027962] CAAMonitorHandler :: 0:Could not join /oracle/crs/bin/racgwrap(check)                                          

category: 1234, operation: scls_process_join, loc: childcrash, OS error: 0, other: Abnormal termination of the child                                        

                                                                                                                                                            

2016-11-08 17:10:19.909: [  CRSAPP][3027962] CheckResource error for ora.ESBSID.db error code = -1                                                          

2016-11-08 17:10:39.084: [  CRSRES][3027965] In stateChanged, ora.ESBSID.ESBSID1.inst target is ONLINE                                                      

2016-11-08 17:10:41.191: [  CRSRES][3027965] ora.ESBSID.ESBSID1.inst on siddb01 went OFFLINE unexpectedly                                                   

2016-11-08 17:10:43.326: [  CRSRES][3027965] StopResource: setting CLI values                                                                               

2016-11-08 17:10:43.723: [  CRSRES][3027965] Attempting to stop `ora.ESBSID.ESBSID1.inst` on member `siddb01`                                               

2016-11-08 17:11:09.197: [  CRSRES][3027977] In stateChanged, ora.ESBSID.SIDsrv.ESBSID1.srv target is ONLINE                                                

2016-11-08 17:11:09.198: [  CRSRES][3027977] ora.ESBSID.SIDsrv.ESBSID1.srv on siddb01 went OFFLINE unexpectedly                                             

2016-11-08 17:11:09.198: [  CRSRES][3027977] StopResource: setting CLI values                                                                               

2016-11-08 17:11:09.885: [  CRSRES][3027977] Attempting to stop `ora.ESBSID.SIDsrv.ESBSID1.srv` on member `siddb01`                                         

2016-11-08 17:11:10.543: [  CRSRES][3027977] Stop of `ora.ESBSID.SIDsrv.ESBSID1.srv` on member `siddb01` succeeded.                                         

2016-11-08 17:11:10.614: [  CRSRES][3027977] ora.ESBSID.SIDsrv.ESBSID1.srv RESTART_COUNT=0 RESTART_ATTEMPTS=0                                               

2016-11-08 17:11:10.730: [  CRSRES][3027977] ora.ESBSID.SIDsrv.ESBSID1.srv failed on siddb01 relocating.                                                    

2016-11-08 17:11:13.721: [  CRSRES][3027977] Attempting to start `ora.ESBSID.SIDsrv.ESBSID1.srv` on member `esbdb01`                                        

2016-11-08 17:11:26.264: [  CRSAPP][3027988] CheckResource error for ora.ESBSID.SIDsrv.cs error code = 1                                                    

2016-11-08 17:11:26.267: [  CRSRES][3027988] In stateChanged, ora.ESBSID.SIDsrv.cs target is ONLINE                                                         

2016-11-08 17:11:26.267: [  CRSRES][3027988] ora.ESBSID.SIDsrv.cs on siddb01 went OFFLINE unexpectedly                                                      

2016-11-08 17:11:26.268: [  CRSRES][3027988] StopResource: setting CLI values                                                                               

2016-11-08 17:11:26.300: [  CRSRES][3027988] Attempting to stop `ora.ESBSID.SIDsrv.cs` on member `siddb01`                                                  

2016-11-08 17:11:26.564: [  CRSRES][3027988] Stop of `ora.ESBSID.SIDsrv.cs` on member `siddb01` succeeded.                                                  

2016-11-08 17:11:26.564: [  CRSRES][3027988] ora.ESBSID.SIDsrv.cs RESTART_COUNT=0 RESTART_ATTEMPTS=0                                                        

2016-11-08 17:11:27.639: [  CRSRES][3027988] ora.ESBSID.SIDsrv.cs exceeded it's failure threshold.  Stopping it and its dependents!                         

2016-11-08 17:11:27.656: [  CRSRES][3027988] ora.ESBSID.SIDsrv.cs target set to OFFLINE before stop action                                                  

2016-11-08 17:11:27.656: [  CRSRES][3027988] StopResource: setting CLI values                                                                               

2016-11-08 17:11:27.665: [  CRSRES][3027988] Target set to OFFLINE for `ora.ESBSID.SIDsrv.cs`                                                               

2016-11-08 17:11:28.419: [  CRSRES][3027965] Stop of `ora.ESBSID.ESBSID1.inst` on member `siddb01` succeeded.                                               

2016-11-08 17:11:28.420: [  CRSRES][3027965] ora.ESBSID.ESBSID1.inst RESTART_COUNT=1 RESTART_ATTEMPTS=5                                                     

2016-11-08 17:11:28.420: [  CRSRES][3027965] ora.ESBSID.ESBSID1.inst Uptime exceeds uptime_threshold, resetting RC                                          

2016-11-08 17:11:28.420: [  CRSRES][3027965] Restarting ora.ESBSID.ESBSID1.inst on siddb01                                                                  

2016-11-08 17:11:28.426: [  CRSRES][3027965] startRunnable: setting CLI values                                                                              

2016-11-08 17:11:28.426: [  CRSRES][3027965] Attempting to start `ora.ESBSID.ESBSID1.inst` on member `siddb01`                                              

2016-11-08 17:11:34.766: [  CRSRES][3027977] Start of `ora.ESBSID.SIDsrv.ESBSID1.srv` on member `esbdb01` succeeded.                                        

2016-11-08 17:11:46.009: [  CRSRES][3027999] startRunnable: setting CLI values                                                                              

2016-11-08 17:12:22.967: [  CRSRES][3027965] Start of `ora.ESBSID.ESBSID1.inst` on member `siddb01` succeeded.                                              

2016-11-08 17:12:22.968: [  CRSRES][3027965] Successfully restarted ora.ESBSID.ESBSID1.inst on siddb01, RESTART_COUNT=1                                     

2016-11-08 17:12:22.997: [  CRSRES][3027965] ora.ESBSID.ESBSID1.inst Updated LAST_RESTART time in ocr               


打算从会话连接数入手,找到连接数超高时间点,然后以此来查询当时数据库等待事件,然后找到对应的SQL进行分析;


INSTANCE_NUMBER TO_CHAR(TRUNC(SAMPLE_TIME,'MI'),'YYYY-MM-DDHH24:MI')                          COUNT(*)
--------------- --------------------------------------------------------------------------- ----------
              1 2016-11-08 16:55                                                                   270
              1 2016-11-08 16:56                                                                   951
              1 2016-11-08 16:57                                                                  1917
              1 2016-11-08 16:58                                                                  2000
              1 2016-11-08 16:59                                                                  1152
              1 2016-11-08 17:12                                                                   379
              1 2016-11-08 17:13                                                                   560
              1 2016-11-08 17:14                                                                   531
              1 2016-11-08 17:15                                                                   458
              1 2016-11-08 17:16                                                                   125
              1 2016-11-08 17:17                                                                   106

查看一下当时时间点的等待事件

SQL> SELECT event_id, event, COUNT (*) cnt                                               
  2      FROM dba_hist_active_sess_history                                               
  3     WHERE snap_id  between 64368 and 64369 AND wait_class_id = 1740759767            
  4  GROUP BY event_id, event   ORDER BY 3 desc;                                         
                                                                                         
  EVENT_ID EVENT                                                                   CNT   
---------- ---------------------------------------------------------------- ----------   
  38438084 direct path write temp                                                 2867   
3926164927 direct path read                                                       2326   
2652584166 db file sequential read                                                1710   
 861319509 direct path read temp                                                   616   
3056446529 read by other session                                                   604   
 506183215 db file scattered read                                                  572   
 834992820 db file parallel read                                                    29   
 885859547 direct path write                                                        18   
SQL> SELECT sql_id, COUNT (*) cnt                                                        
  2    FROM dba_hist_active_sess_history                                                 
  3   WHERE snap_id  between 64368 and 64369                                             
  4         AND event_id IN(38438084)GROUP BY sql_id                                     
  5  HAVING COUNT (*) > 1                                                                
  6  ORDER BY 2 desc;                                                                    
                                                                                         
SQL_ID               CNT                                                                 
------------- ----------                                                                 
a9k9pzsnh5s9n        575                                                                 
gjv7gx73q07c6        258                                                                 
7zbvg66aw143a        227                                                                 
01spkazwnt63u        206                                                                 
dt4xb2ausdy1z        187                                                                 
768krsak8tg2d        185                                                                 
4mzyj9vbyypc8        148                                                                 
d1j0r7w8hwrp9        138                                                                 
du52p4c2735y2        123                                                                 
1wczkxv3znt0h        107                                                                 
b8sj2zpc6n4kh        103                                                                 
4q08ghwrssm09         99                                                                 
ggurqxjuqpca0         84                                                                 
67ram5177zdgf         75                                                               

SQL> SELECT sql_id, COUNT (*) cnt                                                        
  2    FROM dba_hist_active_sess_history                                                 
  3   WHERE snap_id  between 64368 and 64369                                             
  4         AND event_id IN(3926164927)GROUP BY sql_id                                   
  5  HAVING COUNT (*) > 1                                                                
  6  ORDER BY 2 desc;                                                                    
                                                                                         
SQL_ID               CNT                                                                 
------------- ----------                                                                 
b8sj2zpc6n4kh        638                                                                 
768krsak8tg2d        607                                                                 
67ram5177zdgf        315                                                                 
6varm0b41sfxd        164                                                                 
4q08ghwrssm09        109                                                                 
01spkazwnt63u         64                                                                 
g9x112cs2dr4h         64            

   1,大量的磁盘排序操作,order by, group by, union, distinct,无法在PGA中完成排序,需要利用temp表空间进行排序,当从临时表空间中读取排序结果时,会产生direct path read.
2. 大量的Hash Join操作,利用temp表空间保存hash区。
3. SQL语句的并行处理
4. 大表的全表扫描

wKiom1giyB7B9Fs3AASWAa3OzcU403.jpg-wh_50

上面列举的SQL全都是通过SQL*PLUS连接进来执行的语句也都是distinct\parallel 20

wKioL1giyFvzudfpAACkHe3VRGQ680.png-wh_50

系统内当时也有很多的direct path read、db file sequential read等待事件;

在排序操作(order by/group by/union/distinct/rollup/合并连接)时,由于PGA中的SORT_AREA_SIZE空间不足,造成需要使用临时表空间来保存中间结果,当从临时表空间读入排序结果时,产生direct path read等待事件。

使用HASH连接的SQL语句,将不适合位于内存中的散列分区刷新到临时表空间中。为了查明匹配SQL谓词的行,临时表空间中的散列分区被读回到内存中(目的是为了查明匹配SQL谓词的行),ORALCE会话在direct path read等待事件上等待。

使用并行扫描的SQL语句也会影响系统范围的direct path read等待事件。在并行执行过程中,direct path read等待事件与从属查询有关,而与父查询无关,运行父查询的会话基本上会在PX Deq:Execute Reply上等待,从属查询会产生direct path read等待事件我们来验证一下这些语句的执行计划;

wKiom1giyv6h6bPPAAFxCMdV8Xk234.png-wh_50

那么有朋友想问了,ogg重启和他有什么关系?这是我们这个系统专门写的脚本,进行判断,为了就是怕将归档日志给删除,倒是ogg进程异常停止,没想到那段时间的归档日志已经被脚本转移到其他目录之下,这样ogg的抽取进程就报了如下错误;

2016-11-08 19:10:15  ERROR   OGG-00446  Could not find archived log for sequence 144299 thread 1 under default destinations SQL <SELECT  name    FROM v$arch

ived_log   WHERE sequence# = :ora_seq_no AND         thread# = :ora_thread AND         resetlogs_id = :ora_resetlog_id AND         archived = 'YES' AND

    deleted = 'NO' AND         name not like '+%'         AND standby_dest = 'NO' >, error retrieving redo file name for sequence 144299, archived = 1, use_

alternate = 0Not able to establish initial position for sequence 144299, rba 243031568.

OGG-00446也指明了Could not find archived log for sequence 144299 thread 1,我们将故障点以后的ogg进行移回归档目录操作。

wKioL1gizCazFRIGAAARD2QZyAw929.png-wh_50

因为脚本是用root跑的,权限也都有所改变。再将权限重新赋给oracle用户和它的属组

 root@SIDDB01 # cd /oracle/oradata/archlog/sidarchlog/
root@SIDDB01 # ls -ltar
total 8177360
drwxr-xr-x   6 oracle   dba         8192 Jan  6  2015 ..
-r--r-----   1 oracle   dba      759247872 Jul  7  2015 2_152214_784815576.dbf
-r--r-----   1 oracle   dba         1024 Jul  7  2015 2_152215_784815576.dbf
-r--r-----   1 oracle   dba         1024 Jul  7  2015 2_152216_784815576.dbf
-r--r-----   1 oracle   dba         1024 Jul  7  2015 2_152217_784815576.dbf
-r--r-----   1 oracle   dba      311396864 Nov  8 17:20 1_144306_784815576.dbf
-r--r-----   1 oracle   dba      716086272 Nov  8 17:34 1_144307_784815576.dbf
-r--r-----   1 oracle   dba      187094016 Nov  8 17:49 1_144308_784815576.dbf
-r--r-----   1 oracle   dba      160567296 Nov  8 18:01 1_144309_784815576.dbf
-r--r-----   1 oracle   dba      283110912 Nov  8 18:21 1_144310_784815576.dbf
-r--r-----   1 oracle   dba      316848640 Nov  8 18:47 1_144311_784815576.dbf
-r--r-----   1 oracle   dba      194941952 Nov  8 19:03 1_144312_784815576.dbf
-r--r-----   1 root     root     279188480 Nov  8 19:31 1_144299_784815576.dbf
-r--r-----   1 root     root     242944512 Nov  8 19:31 1_144300_784815576.dbf
drwxr-xr-x   2 oracle   dba        16384 Nov  8 19:39 .
-rw-r--r--   1 oracle   dba          391 Nov  8 19:40 ggserr.log
-r--r-----   1 root     root     167494144 Nov  8 19:45 1_144301_784815576.dbf
-r--r-----   1 root     root     199065088 Nov  8 19:46 1_144302_784815576.dbf
-r--r-----   1 root     root     271761408 Nov  8 19:47 1_144303_784815576.dbf
-r--r-----   1 root     root     96945664 Nov  8 19:47 1_144304_784815576.dbf
-r--r-----   1 root     root        1024 Nov  8 19:47 1_144305_784815576.dbf
root@SIDDB01 # chown oracle:dba 1_144*
root@SIDDB01 # ls -ltar
total 8177360
drwxr-xr-x   6 oracle   dba         8192 Jan  6  2015 ..
-r--r-----   1 oracle   dba      759247872 Jul  7  2015 2_152214_784815576.dbf
-r--r-----   1 oracle   dba         1024 Jul  7  2015 2_152215_784815576.dbf
-r--r-----   1 oracle   dba         1024 Jul  7  2015 2_152216_784815576.dbf
-r--r-----   1 oracle   dba         1024 Jul  7  2015 2_152217_784815576.dbf
-r--r-----   1 oracle   dba      311396864 Nov  8 17:20 1_144306_784815576.dbf
-r--r-----   1 oracle   dba      716086272 Nov  8 17:34 1_144307_784815576.dbf
-r--r-----   1 oracle   dba      187094016 Nov  8 17:49 1_144308_784815576.dbf
-r--r-----   1 oracle   dba      160567296 Nov  8 18:01 1_144309_784815576.dbf
-r--r-----   1 oracle   dba      283110912 Nov  8 18:21 1_144310_784815576.dbf
-r--r-----   1 oracle   dba      316848640 Nov  8 18:47 1_144311_784815576.dbf
-r--r-----   1 oracle   dba      194941952 Nov  8 19:03 1_144312_784815576.dbf
-r--r-----   1 oracle   dba      279188480 Nov  8 19:31 1_144299_784815576.dbf
-r--r-----   1 oracle   dba      242944512 Nov  8 19:31 1_144300_784815576.dbf
drwxr-xr-x   2 oracle   dba        16384 Nov  8 19:39 .
-rw-r--r--   1 oracle   dba          391 Nov  8 19:40 ggserr.log
-r--r-----   1 oracle   dba      167494144 Nov  8 19:45 1_144301_784815576.dbf
-r--r-----   1 oracle   dba      199065088 Nov  8 19:46 1_144302_784815576.dbf
-r--r-----   1 oracle   dba      271761408 Nov  8 19:47 1_144303_784815576.dbf
-r--r-----   1 oracle   dba      96945664 Nov  8 19:47 1_144304_784815576.dbf
-r--r-----   1 oracle   dba         1024 Nov  8 19:47 1_144305_784815576.dbf

然后我们在重新启动extract进程

 GGSCI (SIDDB01) 17> info all

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING                                           
JAGENT      STOPPED                                           
EXTRACT     RUNNING     DP01        00:00:00      00:00:03    
EXTRACT     RUNNING     DP02        01:10:28      00:00:05    
EXTRACT     RUNNING     DP03        00:00:00      00:00:10    
EXTRACT     RUNNING     DP04        01:11:41      00:00:06    
EXTRACT     RUNNING     EXT1        00:00:01      00:00:08    
EXTRACT     RUNNING     EXT2        01:10:37      00:00:07    
EXTRACT     RUNNING     EXT3        00:00:01      00:00:09    
EXTRACT     RUNNING     EXT4        01:11:31      00:00:02    

进程启动正常,view report ext4也没有报错。剩下的交给时间慢慢抽取,感谢大家。



本文转自yangjunfeng 51CTO博客,原文链接:http://blog.51cto.com/yangjunfeng/1871100

相关文章
|
6月前
|
监控 Shell
在Shell中自动重启进程
在Shell中自动重启进程
491 1
|
3月前
|
数据采集 监控 API
如何监控一个程序的运行情况,然后视情况将进程杀死并重启
这篇文章介绍了如何使用Python的psutil和subprocess库监控程序运行情况,并在程序异常时自动重启,包括多进程通信和使用日志文件进行断点重续的方法。
|
3月前
|
Linux Perl
在Linux中,系统目前有许多正在运行的任务,在不重启机器的条件下,有什么方法可以把所有正在运行的进程移除呢?
在Linux中,系统目前有许多正在运行的任务,在不重启机器的条件下,有什么方法可以把所有正在运行的进程移除呢?
|
4月前
|
SQL 自然语言处理 网络协议
【Linux开发实战指南】基于TCP、进程数据结构与SQL数据库:构建在线云词典系统(含注册、登录、查询、历史记录管理功能及源码分享)
TCP(Transmission Control Protocol)连接是互联网上最常用的一种面向连接、可靠的、基于字节流的传输层通信协议。建立TCP连接需要经过著名的“三次握手”过程: 1. SYN(同步序列编号):客户端发送一个SYN包给服务器,并进入SYN_SEND状态,等待服务器确认。 2. SYN-ACK:服务器收到SYN包后,回应一个SYN-ACK(SYN+ACKnowledgment)包,告诉客户端其接收到了请求,并同意建立连接,此时服务器进入SYN_RECV状态。 3. ACK(确认字符):客户端收到服务器的SYN-ACK包后,发送一个ACK包给服务器,确认收到了服务器的确
192 1
|
Linux Docker 容器
在Docker守护进程停机期间保持容器运行(即重启Docker时,正在运行的容器不会停止)
在Docker守护进程停机期间保持容器运行(即重启Docker时,正在运行的容器不会停止)
408 0
|
6月前
|
监控 Java Linux
linux下监控java进程 实现自动重启服务
linux下监控java进程 实现自动重启服务
|
6月前
|
监控
用c实现进程监控,如果某一进程退出则重启
用c实现进程监控,如果某一进程退出则重启
44 0
|
6月前
|
关系型数据库 数据库 OceanBase
重启集群中所有节点的 observer 进程
重启集群中所有节点的 observer 进程
60 0
|
11月前
|
消息中间件 数据库连接 数据库
py 多进程 引发的 各种数据库连接 消息队列连接 异常问题 简单分析
py 多进程 引发的 各种数据库连接 消息队列连接 异常问题 简单分析
67 0
|
Java 关系型数据库 MySQL
JSP教师辅助办公软件教学进程管理系统yeclipse开发mysql数据库bs框架java编程jdbc
JSP 教师辅助办公软件教学进程管理系统是一套完善的web设计系统,对理解JSP java编程开发语言有帮助,系统具有完整的源代码和数据库,开发环境为TOMCAT7.0,Myeclipse8.5开发,数据库为Mysql5.0,使用java语言开发,系统主要采用B/S模式开发。
64 0