背景
故事发生在某日,某公司的DBDBA小李接到监控人员的电话,平常需要30分钟的数据库备份作业从昨夜凌晨4点运行至今天上午都没有结束。同时开发人员反映应用程序的部分连接挂起,例如需要几秒钟完成的操作一直无法完成。
小李立刻登陆数据库,按照自己的经验尝试force掉数据库的备份连接以及挂起的数据库部分连接。就在小李处理故障的同时,领导也来到了现场,询问关于故障处理的进展以及问题发生的原因。由于小李刚从事DBA,对于此类问题的处理没有经验,领导及业务人员建议重启数据库,以便以最短的时间恢复业务。面对来自领导以及业务人员的压力,一时手足无措。
“无数据,无真相”,小李突然想起来前段时间IBMDB专家与他交流如何处理常见数据库故障的原则,立刻拨通了IBMDB专家的电话,询问对于此问题的处理建议。根据IBM专家的建议,数据库连接如果无法force,此类故障只能重启解决,重启前需要几分钟的时间收集诊断数据。最终在数据库重启前,小李向领导说明了故障的现象以及处理方法,同时向领导说明在重启前需要收集诊断数据(几分钟时间),以便事后对问题发生的原因进行定位分析。
故障分析过程
以下是IBMDB专家对于此问题的分析定过程:
首先,我们需要对故障发生时的现象有一个清楚的了解:平常需要30分钟的数据库备份作业从昨夜凌晨4点运行至今天上午都没有结束,同时数据库中部分application长时间处于UOW-executing的状态,尝试使用force命令无法正常终止此部分application。下边我们以onlinebackup挂起为例,对此类数据库application挂起的故障,介绍故障分析定位的方法。
1、检查数据库诊断日志
对于数据库故障的定位,第一步首先需要检查数据库的诊断日志文件dbdiag.log,如果诊断日志中无明显线索能分析出故障发生的原因,再进一步使用DBPD等工具收集故障发生时的诊断数据。
、检查备份实用程序的诊断数据(dbpd-utilitiesshowdetail):
DatabasePartition0--Active--Up80days13:4:04
Utilities:
AddressIDTypeStateInvokerPriorityStartTimeDBNameNumPhasesCurPhaseDescription
0xF4DBACKUPTueSep:04:1BCDL11onlinedb
Progress:
AddressIDPhaseNumCompletedWorkTotalWorkStartTimeDescription
0xF4DBbytesbytesTueSep:04:1n/a
从以上的输出可以看出:数据库备份实用程序总共需要备份的数据量为已经完成了bytes,当前已经完成了bytes;数据库备份操作发起的时间为凌晨04:04分。
3、检查当前数据库application的状态(dbpd-dbbcdl-agent–app):
DatabasePartition0--DatabaseBCDL--Active--Up6days1:41:9
Applications:
AddressAppHandl[nod-index]NumAgentsCoorEDUIDStatusC-AnchIDC-StmtUIDL-AnchIDL-StmtUIDAppidWorkloadIDWorkloadOccID
0xC[-]UOW-Executing.38.35.8..16
10.38.35.8..15
0x[-]UOW-Executing.38.35.19..36
0xED[-]PerformingBackup0*LOCAL.dbinst1.
0xAE[-]UOW-Executing.38.35.8..
从以上输出可以看出,执行数据库备份的applicationhandle为,对应的EDUID为。
注:EDU(enginedispatchableunits)即引擎分派单元,负责执行各种任务,例如处理数据库应用程序请求、读取数据库日志文件以及将日志记录从日志缓冲区刷新到磁盘上的日志文件。通常,DB服务器将每个任务作为一个单独的EDU进行处理。在DB9.5之前,大多数这样的EDU在UNIX和Linux环境中是进程,而在Windows环境中是线程。而在9.5中,DB的进程模型得到统一,现在EDU在Linux、UNIX和Windows环境中都是线程。
3、收集诊断数据
综合以上故障发生时的现象以及对dbpd诊断数据的初步分析,数据库备份一直无法完成是由于数据库的备份线程hang导致的。因此在重启前需要收集相应的诊断数据,收集完诊断数据后,重启数据库恢复业务,收集数据的脚本如下:
dbpd-eve-rep~/sqllib/dbdump/eve.out
dbpd-stackall–rep53
dbfodc-hang–dbbcdl
4、分析诊断数据
根据DBPD的输出,我们可以看出backup对应的EDUID为,因此需要分析的stacktrace,对应的文件为...stack.txt(由dbpd–stackall生成):
StackTrace
#####Object:/lib/sparcv9/libc.so.1
_syscall(0x1,0xa0a8,0xd5e8,0x1ffff,0x41a18,0x80)+0x70
#####Object:/opt/IBM/db/V9.5/lib64/libdbe.so.1
__
................................................_thr_slot_offset(0x0,0x0,0x0,0x0,0x0,0x0)+0x
/StackTrace
LatchInformation
Waitingonlatchtype:(SQLO_LT_SQLB_POOL_CB__readLatch)-Address:(d5e8),Line:,File:
/view/db_v10_sun64_s/vbs/engn/include/sqlbistorage_inlines.h
/LatchInformation
从以上信息我们发现backup的进程再等待一个latchSQLO_LT_SQLB_POOL_CB__readLatch,接下来就是分析那个applicationhold住了这个latch,根据dbpd-latch的输出,我们可以得到如下信息:
DatabasePartition0--Active--Up80days13:9:13
Latches:
AddressHolderWaiterFilenameLOC
LatchType
0xFBsqlofmga.CSQLO_LT_sqlofmga_C__SQLO_TLFL_m_fileLatch
0xEsqlofmga.CSQLO_LT_sqlofmga_C__SQLO_TLFL_m_fileLatch
0xBsqlofmga.CSQLO_LT_sqlofmga_C__SQLO_TLFL_m_fileLatch
0x00D5E8sqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5E8sqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
0x00D5Esqlbpacc.CSQLO_LT_SQLB_POOL_CB__readLatch
从latch的输出信息里边可以看到,backup()和DisconnectPending()等待的latch被,,hold住了,根据dbpd–edu的输出,我们可以如下信息:
dbpclnr(BCDL)07..
dbpclnr(BCDL)05..
dbpclnr(BCDL)03..
可以看到上述三个EDUid都是dbpclnr(缓冲池页面清除程序),dbpclnr以异步方式将“脏”页面从缓冲池写回到磁盘。接下来需要分析dbpclnr的stacktrace,对应的诊断数据文件为...stack.txt,...stack.txt,...stack.txt:
StackTrace
#####Object:/lib/sparcv9/libc.so.1
_syscall(0xffffffff48dc0,0xffffffff6a7fd,0xffffffff48dc4,0x0,0x1,0xffffffff6a7fcf98)+0x70
#####Object:/opt/IBM/db/V9.5/lib64/libdbe.so.1
__1cUSQdDLO_LIO_HANDLE_DATARsqloLioAIOCollect6MLpnXSQdDLO_LIO_COLLECT_STATUS_ppnLSQdDLO_IO_REQdD__i_(0xffffffff48d80,0x00fc46e0,0xffffffff6a7fd70,0x4,0xaec,0xffffffff7ef98)+0xe4sqloLioCollectNBlocks(0xffffffff6a7fd70,0x1,0x0,0xffffffff48d80,0x0,0x0)+0x51c
................................_thr_slot_offset(0x0,0x0,0x0,0x0,0x0,0x0)+0x
/StackTrace
LatchInformation
HoldingLatchtype:(SQLO_LT_SQLB_POOL_CB__readLatch)-Address:(d5e8),Line:,File:sqlbpacc.C
/LatchInformation
从stackTrace可以看出dbpclnr在做系统调用(_syscall),并且在stack里边发现了跟aio(sqloLioAIOCollect)相关的信息,由此我们需要去检查跟aio相关数据库edu,根据DB的体系结构,我们想到了dbaiothr线程(AIO收集器线程,管理数据库分区的异步I/O请求)。
检查dbpd–edu的输出,我们发现dbaiothr的eduid是4,分析对应的诊断数据文件.4..stack.txt:
StackTrace
#####Object:/lib/sparcv9/libc.so.1
_kaio(0xffffffff,0x4,0xffffffff6fbfdbec,0xffffffff6fbfd9f4,0x8,0x0)+0x8
#####Object:/lib/sparcv9/libaio.so.1
__aio_waitn(0xffffffff,0x4,0xffffffff6fbfdbec,0xffffffff6fbfd9f4,0x8,0x0)
+0x
#####Object:/opt/IBM/db/V9.5/lib64/libdbe.so.1
sqloStopAIOCollectorEDUs(0x3fffff,0x,0x1,0xffffffff6fbfdbb8,0x,0xe)+0xcb4
sqloEDUEntry(0xfffffffffb9b0,0xffffffff6fbfff58,0xa,0xffffffff7f,0x,0xffffffff7ef98)+0x3a4
#####Object:/lib/sparcv9/libc.so.1
_thr_slot_offset(0x0,0x0,0x0,0x0,0x0,0x0)+0x
/StackTrace
LatchInformation
Nolatchesheld.
/LatchInformation
分析到这里基本就发现了问题,此次故障与操作系统层面的系统调用(__aio_waitn)有关,在IBM官方网站中搜索对应的关键字,我们发现了如下的解决方法: