Buffer Latch Timeout的解析
作者:互联网
【问题描述】
我们可能会在数据库的错误日志里,发现这么一条信息:
A time-out occurred while waiting for buffer latch -- type 4, bp 000000097BFDEDC0, page 1:19239, stat 0xc00009, database id: 5, allocation unit Id: 72057615247867904, task 0x0000000005E594C8 : 0, waittime 300, flags 0x1018, owning task 0x0000000000169DC8. Not continuing to wait.
我们的问题是,这个错误到底是什么含义,在什么情况下会报上面的错误,以及如何解决?
【背景介绍】
Latch是SQL Server内部用来同步资源访问的一个数据结构。和操作系统的Critical Section或ReaderWriterLock类似。Latch保护了那些想保护的资源,使得访问同步有序。比方说,当某个线程获得某个资源的Latch的独占使用权时候,别的线程如果也需要访问这个Latch,则它必须等待。
从大的方面来讲,有两种Latch, 一种叫Buffer Latch,另外一种叫I/O Latch.
我们先来简短介绍一下I/O Latch。当SQL Server从硬盘上读取一个页时,会先在内存预留该页的空间。并且在该预留空间的某一个位BUF_IO设为1. 如果数据从硬盘读写完成,则该位设为0. 从硬盘读取页的期间,其他也需要访问该页的线程当然要等待,等待类型为PAGEIOLATCH_SH,直到读写完成,BUF_IO被设为0为止。因此,如果我们看到大量PAGEIOLATCH_SH等待,则基本可以断定问题是出在磁盘性能上面。
另外一种Latch则称为Buffer Latch,用来保护内存里的数据结构,如Index, Data Pages, B树中的Non-Leaf页。当进程需要读取一个内存里的数据页时,该进程要先获取该数据页上的Buffer Latch。有各种类型的Latch, 包括独占Latch(PAGELATCH_EX)和共享Latch(PAGELATCH_SH)。
下面来演示,为什么我们需要Latch。如下图所示,我们在页面100上,已经存放了两条记录。
如果没有Latch锁的话,某进程在页面100上,插入如下数据:INSERT VALUES(3, 300),其结果如下:
这时,另外一个进程要在页面100上,插入如下数据: INSERT VALUES(4, 400), 因为没有Latch锁,所以会覆盖之前的数据。导致数据插入出问题。
正确的做法是,我们要在第一个线程进行操作时,加独占Latch锁。第二个线程必须要等待,直到第一个线程操作完成。如下图所示:
开始第一条记录插入,随后修改m_freedata(值为141)以及Row的指针(值为126),在此期间,第二条插入语句处于等待Latch状态。第一条记录插入完成后,释放独占Latch锁。
第二条记录开始插入,插入期间也会加独占Latch锁,以防止其他进程修改或读取页。完成后,也随即释放Latch锁。最后结果如图所示。由于有Latch锁,所以数据的插入可以有序的进行。
【LATCH申请模式】
Latch在申请的时候有以下几种模式,
- KP – Keep Latch 保证引用的结构不能被破坏
- SH – Shared Latch, 读数据页的时候需要
- UP – Update Latch 更改数据页的时候需要
- EX – Exclusive Latch 独占模式,主要用于写数据页的时候需要
- DT – Destroy Latch 在破坏引用的数据结构时所需要
下表显示各种Latch申请的兼容模式:
Y表明是兼容的,如果两个线程都去读某页,则他们都会去申请SH锁,因为SH锁是兼容的,则两个线程都不会互相妨碍。而N表明是不兼容的,必须要等待。直到前面一个Latch被释放为止。
【LATCH等待类型】
Latch的等待主要有三种。
- Buffer (BUF) Latch. 用来保护索引或数据页。也包括PFS, GAM, SGAM和IAM数据页。等待类型是PAGELATCH_*模式
- Non-buffer(Non-BUF) Latch, 除了上述数据结构以外的其他内存结构。等待类型是LATCH_*模式
- IO Latch, 保护数据从磁盘到页面的读写过程,等待类型是PAGEIOLATCH_*模式
我们可以查询下面的语句了解一下具体的等待种类:
SELECT * FROM sys.dm_os_wait_stats WHERE wait_type like '%Latch%'
【信息解读】
下面我们来解读这段信息。
A time-out occurred while waiting for buffer latch -- type 4, bp 000000097BFDEDC0, page 1:19239, stat 0xc00009, database id: 5, allocation unit Id: 72057615247867904, task 0x0000000005E594C8 : 0, waittime 300, flags 0x1018, owning task 0x0000000000169DC8. Not continuing to wait.
这里,type 4 是等待的类型。通过下面的查询,我们可以知道, type为4的Latch是EX模式。
SELECT * FROM sys.dm_xe_map_values where name = 'latch_mode'
bp 则是BUF结构的指针,如果没有内存转储,我们没有办法通过这个指针获取更有用的信息。Page (1:19239)则是等待的页编号。Stat 0xc00009则是BUF结构的位信息。其中的0x000004位则是我们上面提到的BUF_IO位。0xc00009 & 0x000004 = 0, 说明该页已经完全导入到内存里的BUF结构里了。Allocation unit id则是相对应的分配单元。一个数据库的表可以有多个分配单元,通常分配单元的个数和这个表的索引个数相同。
使用以下一些列查询,我们可以通过Allocation Unit ID得到其对应的表名。(当然我们也可以通过Page的具体信息来获得表名。用DBCC PAGE命令)
--结果中的container_id就是partition_id。
SELECT * FROM sys.allocation_units where allocation_unit_id=’72057615247867904’
--得到object_id
SELECT * FROM sys.partitions where partition_id = xxxx
--得到name
SELECT * FROM sys.objects where object_id = yyyy
Waittime为300,单位是秒,也就是说,我们申请在页(1:19239)上的一个独占的Latch锁,但是申请了300秒(5分钟),还是没申请到。
这里flags用来判断该latch是否是superLatch,对于分析latch等待用处不大,所以我们不进一步具体分析。
Task地址和owning task地址在内存转储分析中,非常重要。尤其是owning task, 是这个task阻塞了别的进程获得Latch锁。
【如何解决】
Latch申请不到,是由于被其他进程占用的缘故。所以我们需要找到哪个进程占用该Latch一直不释放。然后采取相应的办法进行解决。通常来讲,都是由于磁盘性能所造成的,如果需要得知确切的原因,我们可能需要对内存转储进行分析。对于第一个Latch Timeout的错误,SQL Server会产生一个内存转储。而对于后续的Latch Timeout,则会在SQL Server的错误日志里,报告一个错误信息,但不会产生内存转储。如果要改变这个行为,即要求每次碰到Latch Timeout,都要生成一个内存转储,我们可以用traceflag 838,如下面的命令:
dbcc traceon(838, -1)
由于生成内存转储需要一点时间,有可能在生成内存转储的时候,Latch等待现象消失,在内存转储中,没有足够的信息。因此,我们可能要多次抓取内存转储,以对问题进行分析。
【案例分析】
下面是一个案例分析。我们在数据库的错误日志里,发现有下面的错误,并且产生了一个内存转储。
A time-out occurred while waiting for buffer latch -- type 2, bp 0000000088FBFA40, page 1:153568, stat 0xc0010b, database id: 10, allocation unit Id: 72057594047758336, task 0x000000000C8E2988 : 0, waittime 300, flags 0x1a, owning task 0x0000000005A2F048. Not continuing to wait.
下面是对内存转储的的分析,为了简单起见,不相关的调用堆栈被省略。我们可以看到,下面的这个进程在获取Buffer Latch的时候,由于无法及时得到Latch锁,产生了上述错误信息,并生成一个内存转储。
0a 00000026`ebe09350 00000000`0215d1b8 sqlservr!CDmpDump::Dump+0x7c
0b 00000026`ebe093a0 00000000`0215dd0c sqlservr!SQLDumperLibraryInvoke+0x1a0
0c 00000026`ebe093d0 00000000`021503f7 sqlservr!CImageHelper::DoMiniDump+0x3d4
0d 00000026`ebe095d0 00000000`0206af82 sqlservr!stackTrace+0x82b
0e 00000026`ebe0ab20 00000000`02069f69 sqlservr!LatchBase::DumpOnTimeoutIfNeeded+0x19a
0f 00000026`ebe0abf0 00000000`008e7bcc sqlservr!LatchBase::PrintWarning+0x205
10 00000026`ebe0ace0 00000000`000e7a29 sqlservr!LatchBase::Suspend+0xd12
11 00000026`ebe0b950 00000000`000a0689 sqlservr!LatchBase::AcquireInternal+0x1ff
12 00000026`ebe0b9f0 00000000`000a1792 sqlservr!BUF::AcquireLatch+0x8d
13 00000026`ebe0bd10 00000000`000a166c sqlservr!BPool::Get+0xc7
14 00000026`ebe0bd70 00000000`000a35a0 sqlservr!PageRef::Fix+0xbc
15 00000026`ebe0bdd0 00000000`000a320a sqlservr!BTreeMgr::Seek+0x44d
16 00000026`ebe0bff0 00000000`000a2e5d sqlservr!BTreeMgr::GetHPageIdWithKey+0x20a
17 00000026`ebe0c070 00000000`000a38e8 sqlservr!IndexPageManager::GetPageWithKey+0xbd
这时,错误信息中的owning task地址0x0000000005A2F048对于问题的分析就很重要了。我们通过owning task的地址,结合内存转储分析,可以找到对应于该owning task的进程编号。其调用堆栈如下:
0:175> kM
# Child-SP RetAddr Call Site
00 00000026`f027fa68 000007fe`fcd910dc ntdll!ZwWaitForSingleObject+0xa
01 00000026`f027fa70 00000000`00083b1a KERNELBASE!WaitForSingleObjectEx+0x79
02 00000026`f027fb10 00000000`00082d76 sqlservr!SOS_Scheduler::SwitchContext+0x26d
03 00000026`f027ffa0 00000000`00082700 sqlservr!SOS_Scheduler::SuspendNonPreemptive+0xca
04 00000026`f027ffe0 00000000`000829ac sqlservr!SOS_Scheduler::Suspend+0x2d
05 00000026`f0280010 00000000`000e7e46 sqlservr!EventInternal<Spinlock<153,1,0> >::Wait+0x1a8
06 00000026`f0280060 00000000`000e7a29 sqlservr!LatchBase::Suspend+0x599
07 00000026`f0280cd0 00000000`00645aac sqlservr!LatchBase::AcquireInternal+0x1ff
08 00000026`f0280d70 00000000`00646a49 sqlservr!SQLServerLogMgr::GrowAFile+0x7c
09 00000026`f0281150 00000000`000cb38b sqlservr!SQLServerLogMgr::ReserveAndAppend+0x1fb
0a 00000026`f0281290 00000000`000cbe89 sqlservr!XdesRMReadWrite::GenerateLogRec+0x567
0b 00000026`f02813d0 00000000`000cbc23 sqlservr!XdesRMReadWrite::LogBeginXact+0x243
0c 00000026`f0281530 00000000`000cbc3f sqlservr!XdesRMReadWrite::MakeActive+0x64
0d 00000026`f0281560 00000000`001746c1 sqlservr!XdesRMReadWrite::GenerateLogRec+0x87
0e 00000026`f02816a0 00000000`00174860 sqlservr!PageRef::ModifyRow+0xce0
0f 00000026`f02818f0 00000000`00176749 sqlservr!PageRef::ModifyColumnsInternal+0x1b3
10 00000026`f0281b50 00000000`00175f71 sqlservr!IndexPageRef::Modify+0x2fd3
上面的调用堆栈显示,这是在增长数据库日志文件。由于数据库日志无法及时增长完成,因此导致了这个线程长时间拥有Latch锁而不释放,而其他进程无法及时获取相应的Latch锁。但查看该日志文件的增长设定,每次增长为300M。并不是以百分比增长。似乎没有什么大的问题。
进一步查看数据库的错误日志,在发生该警告之前,SQL Server已经有相关的磁盘性能警告:
SQL Server has encountered 18 occurrence(s) of I/O requests taking longer than 15 seconds to complete on file [F:\sqldata\logs\xxxx_log.ldf] in database [xxxx] (10). The OS file handle is 0x0000000000000A2C. The offset of the latest long I/O is: 0x000004e6511e00
通过收集磁盘性能信息,我们发现,在出问题的点上,Avg. Disk sec/Read达到了1.444. 通常这个值在0.03左右比较正常。而1.444这个值显然偏差非常大。
【结论】
在这个点附近,磁盘压力变得比较大,所以磁盘性能变差)。导致日志文件增长300M无法及时完成。因此该线程拥有的Latch锁无法释放,而其他进程则等待该Latch导致超时。对于这个问题,有以下几种解决方案:
- 更换更好的磁盘。即使在有压力的情况下,性能也不会变得特别差。
- 修改日志文件增长幅度,以每次增长50M为幅度。期望日志文件增长能快速完成。
- 预先对日志文件扩容。这样,就不会有增长日志文件的情况发生。
由于短时间内无法更换磁盘,所以采用第三种方案,预先对日志文件扩容。采用这方案后,再也没有发生Latch timeout。
当然,对于每个Latch timeout的现象,原因可能有所不同,不过通常都是以磁盘性能或操作系统性能造成的原因居多。我们有时候不需要对内存转储进行分析,而是看一下操作系统的日志和数据库的错误日志,也可能找到原因。
【参考资料】
- Diagnosing and Resolving Latch Contention on SQL Server: http://sqlcat.com/sqlcat/b/whitepapers/archive/2011/07/05/diagnosing-and-resolving-latch-contention-on-sql-server.aspx
- Q&A on Latches in the SQL Server Engine http://blogs.msdn.com/b/psssql/archive/2009/07/08/q-a-on-latches-in-the-sql-server-engine.aspx
- Debugging that latch timeout http://troubleshootingsql.com/2011/08/26/debugging-that-latch-timeout/
标签:sqlservr,Buffer,00000000,转储,00000026,内存,Timeout,Latch 来源: https://www.cnblogs.com/zping/p/11063285.html