月归档：六月 2018

UNIFORM_LOG_TIMESTAMP_FORMAT—控制alert日志时间格式

发表于 2018 年 6 月 13 日 由 惜分飞

细心的朋友可能注意到了在12.2中oracle alert日志的时间格式显示发生了改变,根据对oracle的理解,一般新特性有event或者参数进行控制的,通过分析确定是由于UNIFORM_LOG_TIMESTAMP_FORMAT进行控制的

2018-06-13T19:52:30.014659+08:00
RFS[21]: Selected log 12 for T-1.S-5589 dbid 1787743346 branch 957530932
2018-06-13T11:52:30.473314+00:00
Archived Log entry 5178 added for T-1.S-5582 ID 0x6a8e9d72 LAD:1

UNIFORM_LOG_TIMESTAMP_FORMAT修改为false

[oracle@xff ~]$ ss

SQL*Plus: Release 12.2.0.1.0 Production on Wed Jun 13 19:52:59 2018

Copyright (c) 1982, 2016, Oracle.  All rights reserved.


Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

SQL> show parameter UNIFORM_LOG_TIMESTAMP_FORMAT ;

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
uniform_log_timestamp_format         boolean     TRUE
SQL> alter system set uniform_log_timestamp_format=false;

System altered.

验证UNIFORM_LOG_TIMESTAMP_FORMAT=false效果

018-06-13T19:53:16.374197+08:00
RFS[19]: Selected log 14 for T-1.S-5120 dbid 1787743346 branch 957530932
2018-06-13T11:53:16.782388+00:00
Archived Log entry 5181 added for T-1.S-5117 ID 0x6a8e9d72 LAD:1
2018-06-13T19:53:19.797345+08:00
RFS[18]: Selected log 11 for T-1.S-5121 dbid 1787743346 branch 957530932
2018-06-13T11:53:20.268621+00:00
Archived Log entry 5182 added for T-1.S-5118 ID 0x6a8e9d72 LAD:1
Wed Jun 13 19:53:35 2018
ALTER SYSTEM SET uniform_log_timestamp_format=FALSE SCOPE=BOTH;
Wed Jun 13 11:53:37 2018
Wed Jun 13 19:53:37 2018
RFS[21]: Selected log 13 for T-1.S-5596 dbid 1787743346 branch 957530932
Wed Jun 13 11:53:38 2018
Archived Log entry 5183 added for T-1.S-5589 ID 0x6a8e9d72 LAD:1

UNIFORM_LOG_TIMESTAMP_FORMAT修改为true

SQL> alter system set uniform_log_timestamp_format=true;

System altered.

SQL>

验证UNIFORM_LOG_TIMESTAMP_FORMAT=true效果

Wed Jun 13 11:54:07 2018
Media Recovery Waiting for thread 1 sequence 5122 (in transit)
Wed Jun 13 11:54:07 2018
Recovery of Online Redo Log: Thread 1 Group 10 Seq 5122 Reading mem 0
  Mem# 0: /u01/app/oracle/oradata/xifenfei/std_redo10.log
2018-06-13T19:54:23.396030+08:00
ALTER SYSTEM SET uniform_log_timestamp_format=TRUE SCOPE=BOTH;
2018-06-13T11:54:24.597999+00:00
2018-06-13T19:54:24.615045+08:00
RFS[21]: Selected log 11 for T-1.S-5601 dbid 1787743346 branch 957530932
2018-06-13T11:54:25.054848+00:00
Archived Log entry 5187 added for T-1.S-5596 ID 0x6a8e9d72 LAD:1
发表在 ORACLE 12C | 标签为 | 评论关闭

ORA-604 ORA-607 ORA-600

发表于 2018 年 6 月 11 日 由 惜分飞

有客户数据库经过一系列恢复之后,出现ORA-604 ORA-607 ORA-600的错误,尝试各种方法无法打开,希望我们介入处理

Sat May 12 21:18:56 2018
SMON: enabling cache recovery
Sat May 12 21:18:57 2018
Errors in file d:\oracle\admin\xifenfei\udump\xifenfei_ora_3448.trc:
ORA-00600: 内部错误代码，参数: [4194], [34], [28], [], [], [], [], []

Sat May 12 21:19:00 2018
Recovery of Online Redo Log: Thread 1 Group 1 Seq 644 Reading mem 0
  Mem# 0 errs 0: D:\ORACLE\ORADATA\xifenfei\REDO01.LOG
Recovery of Online Redo Log: Thread 1 Group 1 Seq 644 Reading mem 0
  Mem# 0 errs 0: D:\ORACLE\ORADATA\xifenfei\REDO01.LOG
Sat May 12 21:19:01 2018
Errors in file d:\oracle\admin\xifenfei\udump\xifenfei_ora_3448.trc:
ORA-00604: 递归 SQL 层 1 出现错误
ORA-00607: 当更改数据块时出现内部错误
ORA-00600: 内部错误代码，参数: [4194], [34], [28], [], [], [], [], []

Error 604 happened during db open, shutting down database
USER: terminating instance due to error 604
Sat May 12 21:19:02 2018
Errors in file d:\oracle\admin\xifenfei\bdump\xifenfei_pmon_1840.trc:
ORA-00604: error occurred at recursive SQL level 

Instance terminated by USER, pid = 3448
ORA-1092 signalled during: alter database open...

ORA-600 4194 trace文件
分析trace文件,确定ORA-600 4194对应的sql语句为update undo$ set name=:2……

*** 2018-05-12 21:18:57.000
ksedmp: internal or fatal error
ORA-00600: 内部错误代码，参数: [4194], [34], [28], [], [], [], [], []
Current SQL statement for this session:
update undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,
xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
_ksedmp+147          CALLrel  _ksedst+0            
_ksfdmp.108+e        CALLrel  _ksedmp+0            3
_kgeriv+89           CALLreg  00000000             212778 3
_kseipre.107+3f      CALLrel  _kgeriv+0            
_ksesic2+24          CALLrel  _kseipre.107+0       
__VInfreq__kturdb+8  CALLrel  _ksesic2+0           1062 0 22 0 1C
b                                                  
_kcoapl+1df          CALLreg  00000000             30A0F94 30A100A 11 6BB7E014
_kcbapl+71           CALLrel  _kcoapl+0            30A0F90 6BB7E000 1 0 2000
_kcrfwr+734          CALLrel  _kcbapl+0            30A0F90 6BBFC844 3014F9C
_kcbchg1+7ec         CALLrel  _kcrfwr+0            
_ktuchg+630          CALLrel  _kcbchg1+0           0 4 3015224 301523C 0 0
_ktbchg2+75          CALLrel  _ktuchg+0            2 672D50F4 1 310DCD8 310DCE0
                                                   30A0F90 310D2F0 30A0ED0 0 0
_kddchg+18f          CALLrel  _ktbchg2+0           0 672D50F4 310DCD8 310DCE0
                                                   30A0F90 310D2E8 30A0ED0 0 0
_kduovw.53+6e3       CALLrel  _kddchg+0            310D2AC 310DCD8 310DCE0
                                                   30A0F90 30A0ED0 0 0
_kduurp.53+61a       CALLrel  _kduovw.53+0         310D2AC
_kdusru+aa5          CALLrel  _kduurp.53+0         310D2AC 672D514C
_kauupd+12e          CALLrel  _kdusru+0            310D6E0 672D514C 310D2AC 0
_updrow+729          CALLrel  _kauupd+0            310D6DC 672D514C 310D2AC 0
                                                   672D539C E F 672E4E48 12
                                                   301BBA0 301BBA4
_qerupFetch+107      CALLrel  _updrow+0            
_updaul+202          CALL???  00000000             672DE9C4 0 672EC040 7FFF
_updThreePhaseExe+b  CALLrel  _updaul+0            672EBDD4 301BD30 0
6                                                  
_updexe+105          CALLrel  _updThreePhaseExe+0  672EBDD4 0 310D2AC 301BE0C
                                                   672EBDD4 1 301BE0C 0
_opiexe+f97          CALLrel  _updexe+0            672EBDD4 301BF48
_opiodr+4cd          CALLreg  00000000             4 3 301C894
_rpidrus.43+99       CALLrel  _opiodr+0            4 3 301C894 B
_skgmstack+71        CALLreg  00000000             301C484
_rpidru+6d           CALLrel  _skgmstack+0         301C49C 212600 F618 778198
                                                   301C484
_rpiswu2+17e         CALLreg  00000000             301C7BC
_rpidrv+109          CALLrel  _rpiswu2+0           
_rpiexe+33           CALLrel  _rpidrv+0            B 4 301C894 8
_ktuscu+2a8          CALLrel  _rpiexe+0            B
_kqrcmt+2c2          CALL???  00000000             672EA898 3
..1.18_2.filter.95+  CALLrel  _kqrcmt+0            67B9C5F4 1 0 212778 212778 FF
159                                                0 0 0
..1.23_5.filter.99+  CALLrel  _ktcrcm+0            67B9C5F4 0 0 0 0 1 0 0
14d                                                
_ktuini+64           CALLrel  _ktuiup.99+0         301D990
_adbdrv+2665         CALLrel  _ktuini+0            301D990
..1.5_1.filter.29+2  CALLrel  _adbdrv+0            
9d                                                 
_opiosq0+9a4         CALLrel  _opiexe+0            4 0 301DDD8
_kpooprx+c6          CALLrel  _opiosq0+0           3 E 301DE70 24
_kpoal8+225          CALLrel  _kpooprx+0           301E738 301E680 13 1 0 24
_opiodr+4cd          CALLreg  00000000             5E 14 301E734
_ttcpip+a86          CALLreg  00000000             5E 14 301E734 0
_opitsk+2f4          CALLrel  _ttcpip+0            
_opiino+5fc          CALLrel  _opitsk+0            0 0 2188C8 30CF020 E6 0
_opiodr+4cd          CALLreg  00000000             3C 4 301FBD4
_opidrv+233          CALLrel  _opiodr+0            3C 4 301FBD4 0
_sou2o+19            CALLrel  _opidrv+0            
_opimai+10a          CALLrel  _sou2o+0             
_OracleThreadStart@  CALLrel  _opimai+0            
4+35c                                              
7C80B726             CALLreg  00000000             
 
--------------------- Binary Stack Dump ---------------------

进一步分析确定为system rollback segment header 异常

Block image after block recovery:
buffer tsn: 0 rdba: 0x00400009 (1/9)
scn: 0x0000.d794070f seq: 0x01 flg: 0x04 tail: 0x070f0e01
frmt: 0x02 chkval: 0x2320 type: 0x0e=KTU UNDO HEADER W/UNLIMITED EXTENTS
  Extent Control Header
  -----------------------------------------------------------------
  Extent Header:: spare1: 0      spare2: 0      #extents: 6      #blocks: 47    
                  last map  0x00000000  #maps: 0      offset: 4128  
      Highwater::  0x00400183  ext#: 2      blk#: 2      ext size: 8     
  #blocks in seg. hdr's freelists: 0     
  #blocks below: 0     
  mapblk  0x00000000  offset: 2     
                   Unlocked
     Map Header:: next  0x00000000  #extents: 6    obj#: 0      flag: 0x40000000
  Extent Map
  -----------------------------------------------------------------
   0x0040000a  length: 7     
   0x00400011  length: 8     
   0x00400181  length: 8     
   0x00400189  length: 8     
   0x00400191  length: 8     
   0x00400199  length: 8     
  
  TRN CTL:: seq: 0x0056 chd: 0x0054 ctl: 0x0052 inc: 0x00000000 nfb: 0x0001
            mgc: 0x8002 xts: 0x0068 flg: 0x0001 opt: 2147483646 (0x7ffffffe)
            uba: 0x00400183.0056.1b scn: 0x0000.d77996ab
Version: 0x01
  FREE BLOCK POOL::
    uba: 0x00400183.0056.1b ext: 0x2  spc: 0x794   
    uba: 0x00000000.002f.21 ext: 0x5  spc: 0x1334  
    uba: 0x00000000.002e.37 ext: 0x4  spc: 0x788   
    uba: 0x00000000.0000.00 ext: 0x0  spc: 0x0     
    uba: 0x00000000.0000.00 ext: 0x0  spc: 0x0 
…………    
ORA-00604: 递归 SQL 层 1 出现错误
ORA-00607: 当更改数据块时出现内部错误
ORA-00600: 内部错误代码，参数: [4194], [34], [28], [], [], [], [], []

这种问题需要通过通过bbed/ue修改ktuxc的相关内容,实现数据库open成功,可以参考另外几篇文章:
使用bbed解决ORA-00607/ORA-00600[4194]故障
通过bbed模拟ORA-00607/ORA-00600 4194 故障
ORA-607/ORA-600[4194]不一定是重大灾难
数据库报ORA-00607/ORA-00600[4194]错误

发表在 Oracle备份恢复 | 标签为 , | 评论关闭

Automatic datafile offline due to write error on

发表于 2018 年 6 月 8 日 由 惜分飞

由于存储突然掉线导致数据文件无法访问,导致部分数据文件被自动offline

Thu May 17 14:49:03 2018
KCF: read, write or open error, block=0xe93b8 online=1
Thu May 17 14:49:03 2018
KCF: read, write or open error, block=0x24eb65 online=1
        file=25 'F:\ORACLE\ORADATA\ORCL\QYSCZH12.ORA'
        file=28 'F:\ORACLE\ORADATA\ORCL\QYSCZH15.ORA'
        error=27070 txt: 'OSD-04016: 异步 I/O 请求排队时出错。
O/S-Error: (OS 2) 系统找不到指定的文件。'
Automatic datafile offline due to write error on
file 25: F:\ORACLE\ORADATA\ORCL\QYSCZH12.ORA
Thu May 17 14:49:03 2018
KCF: read, write or open error, block=0x22b0a1 online=1
        file=28 'F:\ORACLE\ORADATA\ORCL\QYSCZH15.ORA'
        error=27070 txt: 'OSD-04016: 异步 I/O 请求排队时出错。
O/S-Error: (OS 2) 系统找不到指定的文件。'
Automatic datafile offline due to write error on
file 28: F:\ORACLE\ORADATA\ORCL\QYSCZH15.ORA
Thu May 17 14:49:03 2018
KCF: read, write or open error, block=0x138def online=1
        file=11 'F:\ORACLE\ORADATA\ORCL\QYSCZH4'
        error=27070 txt: 'OSD-04016: 异步 I/O 请求排队时出错。
O/S-Error: (OS 2) 系统找不到指定的文件。'
        file=30 'F:\ORACLE\ORADATA\ORCL\QYSCZH17.ORA'
        file=11 'F:\ORACLE\ORADATA\ORCL\QYSCZH4'
        error=27070 txt: 'OSD-04016: 异步 I/O 请求排队时出错。
        error=27070 txt: 'OSD-04016: 异步 I/O 请求排队时出错。
O/S-Error: (OS 2) 系统找不到指定的文件。'
O/S-Error: (OS 2) 系统找不到指定的文件。'
……
        file=15 'F:\ORACLE\ORADATA\ORCL\QYSCZH6.ORA'
        error=27072 txt: 'OSD-04008: WriteFile() 失败, 无法写入文件
O/S-Error: (OS 21) 设备未就绪。'
Automatic datafile offline due to write error on
file 15: F:\ORACLE\ORADATA\ORCL\QYSCZH6.ORA
KCF: read, write or open error, block=0xade96 online=1
        file=9 'F:\ORACLE\ORADATA\ORCL\QYSCZH2'
        error=27072 txt: 'OSD-04008: WriteFile() 失败, 无法写入文件
O/S-Error: (OS 21) 设备未就绪。'
Automatic datafile offline due to write error on
file 9: F:\ORACLE\ORADATA\ORCL\QYSCZH2
Thu May 17 14:49:28 2018
KCF: read, write or open error, block=0x378c66 online=1
        file=15 'F:\ORACLE\ORADATA\ORCL\QYSCZH6.ORA'
        error=27072 txt: 'OSD-04008: WriteFile() 失败, 无法写入文件
O/S-Error: (OS 21) 设备未就绪。'
Automatic datafile offline due to write error on
file 15: F:\ORACLE\ORADATA\ORCL\QYSCZH6.ORA
KCF: read, write or open error, block=0x35f6de online=1
……

存储掉线是悲剧的起点,按理说数据库是归档模式,存储恢复之后,继续recover datafile,然后online应该问题不大,但是由于客户没有及时处理这个问题(也许业务实时性要求不高,可能挂几个小时也没人知道),导致第二个悲剧发生,删除归档的定时任务把数据库的归档日志给删除了.导致后面存储挂载上来之后,数据文件也无法正常online成功

Tue May 22 16:28:13 2018
ALTER DATABASE RECOVER  datafile 'F:\ORACLE\ORADATA\ORCL\QYSCZH'  
Media Recovery Start
Serial Media Recovery started
ORA-279 signalled during: ALTER DATABASE RECOVER  datafile 'F:\ORACLE\ORADATA\ORCL\QYSCZH'  ...
Tue May 22 16:28:42 2018
ALTER DATABASE RECOVER    CONTINUE DEFAULT  
Media Recovery Log D:\ORALCE\ADMINISTRATOR\FLASH_RECOVERY_AREA\ORCL\ARCHIVELOG\2018_05_22\O1_MF_1_267346_%U_.ARC
Errors with log D:\ORALCE\ADMINISTRATOR\FLASH_RECOVERY_AREA\ORCL\ARCHIVELOG\2018_05_22\O1_MF_1_267346_%U_.ARC
ORA-308 signalled during: ALTER DATABASE RECOVER    CONTINUE DEFAULT  ...
ALTER DATABASE RECOVER    CONTINUE DEFAULT  
Media Recovery Log D:\ORALCE\ADMINISTRATOR\FLASH_RECOVERY_AREA\ORCL\ARCHIVELOG\2018_05_22\O1_MF_1_267346_%U_.ARC
Errors with log D:\ORALCE\ADMINISTRATOR\FLASH_RECOVERY_AREA\ORCL\ARCHIVELOG\2018_05_22\O1_MF_1_267346_%U_.ARC
ORA-308 signalled during: ALTER DATABASE RECOVER    CONTINUE DEFAULT  ...

通过Oracle数据库异常恢复检查脚本(Oracle Database Recovery Check)脚本检测发现结果如下:
recover

遭遇这种情况,常规方法无法恢复,考虑使用bbed或者其他方法强制online文件,由于存储突然掉线,这样恢复的库可能后续还有大量工作需要处理,最常见的可能有表和index不一致,表的segment header信息和extent实际信息不匹配等

发表在 非常规恢复 | 标签为 , , , | 评论关闭