背景
客户反映HIS数据库在11点出现了长时间的阻塞,直到手动KILL掉阻塞的源头。请我们协助分析原因,最终定位到.NET程序中使用的SqlDataReader未正常关闭导致。
现象
登录SQL专家云,进入趋势分析,在活动会话中回溯11点一个小时内的运行情况,从11:28开始出现阻塞情况,一直持续到11:57。
转到活动会话原始数据,看到ID为418的会话是阻塞源头,阻塞了会话722,会话722又阻塞了其它大量的会话。
分析
首先分析阻塞的成因,会话418执行的是一个查询语句,在表上都加了NOLOCK查询提示,也就是说不加共享锁,不会阻塞其它会话对该表的INSERT、UPDATE、DELETE操作,但是还是要加架构共享锁的,而会话722执行的是TRUNCATE TABLE SYS_KSDMK,是要对表加架构排他锁的,产生互斥,从而造成阻塞。
接下来再分析为什么会造成这么长时间的阻塞,在不同时间点看会话418的运行情况,每个时间点的等待资源都是ASYNC_NETWORK_IO,CPU时间和逻辑读次数都非常小,而且一直不变。
ASYNC_NETWORK_IO从字面上有很强的迷惑性,第一反应是网络环境的问题,通过微软官方文档看到,客户端程序因为各种原因无法快速接收使用查询返回的数据也是很重要的原因。和客户进行确认,这个语句查询的都是字典表,数据量非常小,因此判断该查询语句在SQL Server端很快就执行完了,客户端程序在接收查询结果时出现异常。
根据推断,在客户端程序中果然找程序的错误日志。查看代码,程序用SqlDataReader逐行接收并处理查询结果,在数据类型转换时有报错。
为了更好的说明这个现象,特地写了一段演示代码。用SqlDataReader循环逐行接收查询返回的结果,当接收到ID>500的数据行时抛出异常。报错后程序无法运行到reader.Close()和connection.Close()来关闭SqlDataReader和SqlConnection。
因为程序没有异常处理机制,该连接(会话)已经被泄露,所以该会话和请求会一直存在,状态如下图。其它会话对表进行TRUNCATE TABLE操作时就会被阻塞。
解决
要修改应用程序,增加程序的健壮性。可以在异常处理时检查并关闭SqlDataReader和SqlConnection,也可以利用using的特性自动关闭。
自动查杀会话
因为很多客户是购买软件厂商的产品,修改程序不容易实施。因此只能在数据库端进行补偿性的措施,例如配置一个定期运行的自动查杀会话的作业,根据这种会话的特征KILL掉。也可以在SQL专家云中启用自动查杀会话的功能。
北京格瑞趋势科技有限公司是聚焦于数据服务的高新技术企业,成立于2008年,创始团队及核心技术人员来自微软和雅虎。微软数据平台金牌合作伙伴,卫宁健康数据平台战略合作伙伴。通过产品+服务双轮驱动的业务模式,14年间累计服务4000+客户,覆盖互联网、市政、交通、电信、医疗、教育、电力、制造业等各个领域。