首页 » ORACLE 9i-23ai » 一次存储链路抖动因I/O timeout不同在AIX和HPUX上的不同表现

一次存储链路抖动因I/O timeout不同在AIX和HPUX上的不同表现

去年一个故障案例经过时间的沉淀问题没在发生今天有时间简单的总结一下,当时正时午睡时分,突然告警4库8个实例同时不可用,这么大面积的故障多数是有共性的关连,当时查看数据库DB ALERT日志都是I/O错误写失败,后确认8个实例都是使用了存储层的同步容灾技术,且存储为同一品牌日立。

2017-01-22 13:02:14.213000 +08:00
KCF: read, write or open error, block=0x1ad85 online=1    
        file=443 '/dev/anbob_oravg01/ranbob_lv15_062'
        error=27063 txt: 'HPUX-ia64 Error: 11: Resource temporarily unavailable
Additional information: -1
Additional information: 32768'
Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_dbw7_17700.trc:
Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_lgwr_17702.trc:
ORA-00345: redo log write error block 95667 count 10
ORA-00312: online log 4 thread 1: '/dev/anbob_oravg02/ranbob_redo04'
ORA-27063: number of bytes read/written is incorrect
HPUX-ia64 Error: 11: Resource temporarily unavailable
Additional information: -1
Additional information: 10240
KCF: read, write or open error, block=0x5c699 online=1
KCF: read, write or open error, block=0x168297 online=1
        file=29 '/dev/anbob_oravg01/ranbob_lv15_024'
        file=142 '/dev/anbob_oravg04/ranbob_lv30_273'
        error=27063 txt: 'HPUX-ia64 Error: 11: Resource temporarily unavailable
        error=27063 txt: 'HPUX-ia64 Error: 11: Resource temporarily unavailable
Additional information: -1
Additional information: -1
Additional information: 8192'
Additional information: 8192'
Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_dbw1_17688.trc:

再回头看一下这些数据库的环境, 使用的是同步的异地容灾技术,也就是存储上层的应用I/O一次要写两处,本地和远程都写成功才算完成,这里的应用也就是ORACLE DB,这算是过去容灾环境中常用技术,对于存储同步通常也有异步技术需要购买更贵的license. 这些环境中的DB 因为远程的链路抖动导致I/O写失败导致HPUX平台的数据库重启。

不过有意思的时同样异地容灾的数据库还有其它环境并未重启,如下

OS Storage IS_Restart
AIX EMC NO
AIX HDS NO
HPUX EMC NO
HPUX HDS YES

Note:
这里看到只有HPUX和HDS的配合重启了数据库,在存储上EMC工程师当时说从日志发现错了错误和切换链路,但HDS工程师说并未发现错误日志,但是提出日立存储判断是当链路发生问题时, 切换的超时时间为30+10 秒。那么再回到上层OS层,HPUX主机的IO timeout时间为30秒, AIX主机为60秒. 所以存在日立存储切换链路前HPUX已I/O 超时,返回了I/O失败. 而故障时间也可能刚好>30 <60秒所以在AIX timeout前存储已恢复正常, AIX可以继续并未重启。

当然假设以上都是成立的,那究竟当链路不可用时,短时内宕掉数据库保证数据库一致,还是再增加多一些的时间retry, 为存储短时内恢复争取时间正为合适,需要一个时间的权衡。 这个时间也就是PL/SQL 中的commit.

数据库的ACID中的D也就是持久性,要求COMMIT后的事务要持久化也就是不能丢失,所以在SQL中的COMMIT,都是强置redo log刷到磁盘才可以继续,如下:

when a session issues a commit, it generates the redo describing how to update its transaction table slot in the undo segment header block, puts this redo into the log buffer, applies it to the undo segment header block, calls the log writer to flush the log buffer to disk, and then goes into a log file sync wait until the log writer lets it know that its entry in the log buffer has been copied to disk.
This commit/rollback mechanism that makes transactions Durable.(D OF ACID )

但是PL/SQL 中的commit是做了优化,为了权衡LOOP 中的COMMIT的性能,commit只是发关给LGWR一个提交的message, 然而并不会一直等lgwr写磁盘完成就可以继续下一个事务,这点区别与SQL中事务的认识。可以使用一段PL/SQL测试。

[oracle@anbob ~]$ sqlplus anbob/anbob@anbob/pdbanbob.com

SQL*Plus: Release 12.2.0.0.0 Beta on Tue Feb 7 15:00:27 2017
Copyright (c) 1982, 2015, Oracle.  All rights reserved.
Last Successful login time: Tue Feb 07 2017 14:57:44 +08:00
Connected to:
Oracle Database 12c EE Extreme Perf Release 12.2.0.1.0 - 64bit Production

SQL> create table anbob.t(id int,a date);
Table created.

SQL> @statn commit
     STAT# HEX#      OFFSET NAME                                                                  VALUE
---------- ----- ---------- ---------------------------------------------------------------- ----------
         6 6             48 user commits                                                              1 
       219 DB          1752 commit cleanouts                                                          3
       220 DC          1760 commit cleanouts successfully completed                                   3
       647 287         5176 IMU commits                                                               1
...
45 rows selected.

SQL> @statn sync

     STAT# HEX#      OFFSET NAME                                                                  VALUE
---------- ----- ---------- ---------------------------------------------------------------- ----------
       338 152         2704 redo synch time                                                           9
...
       346 15A         2768 redo synch writes                                                         2
...

17 rows selected.

declare
 i int:=0;
begin
  while i<100 loop
  insert into t values(i,sysdate);
  commit;
  dbms_lock.sleep(1);
  i:=i+1;
  end loop;
end; 
  /  

PL/SQL procedure successfully completed.

SQL>@statn commit

     STAT# HEX#      OFFSET NAME                                                                  VALUE
---------- ----- ---------- ---------------------------------------------------------------- ----------
         6 6             48 user commits                                                            101
       201 C9          1608 BPS commit wait                                                           0
...
       219 DB          1752 commit cleanouts                                                        103
       220 DC          1760 commit cleanouts successfully completed                                 103
       647 287         5176 IMU commits                                                             101

45 rows selected.

SQL> @statn sync

     STAT# HEX#      OFFSET NAME                                                                  VALUE
---------- ----- ---------- ---------------------------------------------------------------- ----------
       338 152         2704 redo synch time                                                           9
 ...
       346 15A         2768 redo synch writes                                                         3

17 rows selected.

Note:
user commits 值是和PLSQL 中 COMMIT一致,但是redo synch writes才增加了一次,注意如果在PL/SQL中使用DBLINK就不再这样。而SQL中的COMMIT如下

SQL> @statn sync

     STAT# HEX#      OFFSET NAME                                                                  VALUE
---------- ----- ---------- ---------------------------------------------------------------- ----------
       338 152         2704 redo synch time                                                           9
       346 15A         2768 redo synch writes                                                         4
17 rows selected.

SQL> insert into t values(200,sysdate);
1 row created.

SQL> commit;
Commit complete.

SQL> insert into t values(200,sysdate);
1 row created.

SQL> commit;
Commit complete.

SQL> @statn sync

     STAT# HEX#      OFFSET NAME                                                                  VALUE
---------- ----- ---------- ---------------------------------------------------------------- ----------
       338 152         2704 redo synch time                                                          10
       346 15A         2768 redo synch writes                                                         6

Note:
每一次commit都会触发redo synch writes。

the statistic redo synch writes counts the number of times a session has sent a message (statistic messages sent) to lgwr on a commit. This is an approximation; in fact, “sending a message” may not involve a real message.

Clearly the user session is not behaving as expected—it has posted lgwr to write a few times, but it
has only incremented redo synch writes once, which suggests it didn’t stop and wait for lgwr to wake it
up again. The user’s session is breaching the durability requirement; if the instance crashed somewhere
in the middle of this loop, it’s entirely possible that a transaction that had been committed would not be
recovered.

If we saw this output we could interpret it as 25 cycles of the following sequence:
• User session issues a commit
• User session posts lgwr and increments redo synch writes
• User session goes into a wait (log file sync) waiting to be posted by lgwr
• Lgwr gets woken up
• Lgwr writes the log buffer to disk, waiting a short time on each write

This strategy does not get used if the code is doing updates across database links, so there have been occasions in the
past where I’ve used a totally redundant loopback database link to ensure that some PL/SQL code would wait for a
log file sync on every commit.

所以如果在PLSQL 使用LOOP commit, 像上面如果存储最终都没有恢复,那么commit的事务会丢失。

当然为了保持HPUX和AIX 的一致,数据库环境都使用了异步IO(AIO)和RAW裸设备的共享存储,对于数据库的I/O请求,数据库只是发送给OS层后就结束,timeout的时间多数取决于OS和存储层。对于HP平台而言,与IO timeout相关的内核参数主要是PV timeout、LV timeout、ESD_SECS、asyncdsk_io_timeout等。

HPUX做如下修改:

1,  PV timeout默认为30s, 据了解AIX平台为60s, 调整该参数为60s.
pv_timeout = (n * esd_secs) + ((n-1) * Δ)
esd_secs = 10
n = lunpath数量
Δ= IO切换延迟(Qlogic HBA =13,其它HBA = 2)

2,LV timout默认依赖PV timeout, 建议值如下LV timeout value = (# of paths * PV Timeout) + 10 seconds

3,ESD_SECS=120  esd_secs attribute determines the timeout of I/O operations to block devices.默认是30s, 在MOS中有案例调整了该参数,因使用RAW device本次未做调整。

4,asyncdsk_io_timout  默认值30s ,调整为120s。如果dump controlfile reader时的call stack ,会发现包含kfk_reap_ufs_async_io, 所以对于controlfile/online redo logfile都是致命文件,如果超过异步IO延迟,数据库就会crash。 datafiles(non system datafiles) I/O错误是否crash数据库受隐藏参数_datafile_write_errors_crash_instance.影响。

在做了如上调整后,手动的切断远程链路,并在120s 前恢复,数据库并未crash.

其它相关参数:

path_fail_secs=10, 10秒之内没有成功IO,这条lunpath就标记为offline
ping_type=extended,系统定时向offline的lunpath发送INQ, TUR and Read Capacity cmds以检查lunpath是否恢复
ping_recovery=time_based,基于时间的检查,相对于基于次数
ping_time_threshold=10,系统持续ping一个lunpath如果超过10秒都是成功的,那么就将这个lunpath标记为online

transient_secs ,说明配置的在 LUN OFFLINE 后、failing I/O前的一段静默期,这个值默认是120s。(Seconds to wait after a LUN has gone OFFLINE before failing I/Os,default 120s) scsimgr save_attr -N /escsi/esdisk -a path_fail_secs=30 -a transient_secs=10。

提示:本案例仅供参考,具体调整需要咨询OS和存储厂商。

12c R2 RAC instance crash due to CKPT is hung, using Multipathing

打赏

, ,

对不起,这篇文章暂时关闭评论。