WaitType：ASYNC

标签：finish   wait   buffer   other   splay   command   操作   其他   log   

项目组有一个数据库备份的Job运行异常，该Job将备份数据存储到remote server上，平时5个小时就能完成的备份操作，现在运行19个小时还没有完成，backup命令的Wait type是 ASYNC_IO_COMPLETION：

根据MSDN 官方文档的定义：Occurs when a task is waiting for asynchronous I/O operations to finish.

该等待类型表示：Task在等待异步IO操作的完成。进程申请了一个IO操作，但是系统（Disk/Network）不能立即完成该IO请求，因此该进程进入等待状态，等待Async IO完成。

查看SQL Server的Error Log，发现大量IO请求超时的记录，从File 的路径 [D:\xxx\yyy.ndf] 上看到，IO 请求是发送给Local Server，说明SQL Server发出的IO请求，Local Server的Disk不能及时完成：

SQL Server has encountered 1 occurrence(s) of I/O requests taking longer than 15 seconds to complete on file [D:\xxx\yyy.ndf] in database [database_name] (8).  The OS file handle is 0x00000000000010E4.  The offset of the latest long I/O is: 0x00000482f60000

出现长时间的ASYNC_IO_COMPLETION 等待的原因可能是：

1. 同时有其他Application在进行大量的IO操作，导致用来存储备份数据的Disk特别忙，备份操作必须等待Disk IO完成。
2. 如果备份数据存储到remote server上，那么可能是network被其他application占用，导致用于传输备份数据的带宽变小。

我看到的这个异常的备份操作，是将备份数据存储到远程Server上，打开ResouceMonitor（点击Windows+R，输入resmon），发现Disk Activity是2MB-4MB之间，而Network Activity在18MB-46MB之间，如图：

这说明，Remote Server的network相对比较忙，网络传输很可能是导致备份操作长时间运行的root cause。但是，从SQL Server的Error Log中得知，是本地Disk的不能及时响应IO请求。

由于备份操作已经结束，没有办法查看Local Server的Disk IO和 Network Activity，而此时，Remote Server上的Disk Activity 和 Network Activity 十分平静，都在几百KB水平上，间接说明Remote Server不是backup操作等待异步IO操作完成的root cause，Local Server的Disk IO是瓶颈。

分析Disk IO的性能，最好的方法是分析Performance Counter。打开Local Server的Performance Monitor（点击Windows+R，输入perfmon），没有记录Data Collection，这样没有办法进行深入的分析了，下次遇到时，继续分析。

总之：在数据库备份或还原的过程中，出现长时间的ASYNC_IO_COMPLETION 等待，表示backup/restore操作正在等待获取IO资源，导致backup/restore 进程处于挂起状态（suspended），只有获取到IO资源，该操作才会继续进行下去。

在执行长时间的IO密集的操作时，SQL Server进程经常会发生ASYNC_IO_COMPLETION等待，同时会在Error Log中记录 “I/O requests are taking longer than 15 seconds to complete” 消息，IO密集的操作主要有：backup/restore操作，新建一个大的数据库文件，和数据库文件增长。长时间执行IO密集操作，本来就需要大量的IO才能完成，但是，长时间处于ASYNC_IO_COMPLETION 等待，在很大程度上，表明IO是系统的瓶颈，Disk的读写能力或Network的传输能力是系统的短板。

Appendix：使用以下脚本查看备份操作的等待类型，已经完成的百分比，对于预估的剩余时间，只是个预估值，不可信。

select  r.session_id,
        r.blocking_session_id as blocking,
        r.wait_type as Current_Wait_Type,
        r.wait_time/1000/60/60 as wait_h,
        r.status,
        r.command,
        r.total_elapsed_time/1000/60/60 as total_h,
        r.percent_complete,
        r.estimated_completion_time/1000/60/60 as estimated_h
from sys.dm_exec_requests r
outer APPLY sys.dm_exec_sql_text(r.sql_handle) as st
where (r.wait_type<>‘MISCELLANEOUS‘ or r.wait_type is null)
    and r.session_id>50
    and r.session_id<>@@spid

推荐阅读《ASYNC_IO_COMPLETION Wait type》：

参考文档：

ASYNC_IO_COMPLETION Wait type

ASYNC_IO_COMPLETION

WaitType：ASYNC

标签：finish   wait   buffer   other   splay   command   操作   其他   log   

原文地址：http://www.cnblogs.com/wangsicongde/p/7551134.html