标签：style blog http tar com strong
症状：
端午发布后，服务器出现大量报错日志，并且平均响应时间不断上升。重启机器后立刻恢复正常，但还是运行一段时间后，响应时间又开始上升。
从报错日志中发现很多DB连接池满的错误。导致这种错误一般有两个原因：
1：SQL 执行完后，DbConnection 及时没有释放。
2：SQL 执行慢，占用了大量 DbConnection 。
通过对代码彻底扫描，发现有几个 DataReader 没有显示关闭的地方。但这些都是运行很久老代码应该不是引用这次现象的原因。修改代码重新上线后的确没有得到改善。
继续找原因：
观察单台服务器的平均响应时间曲线。基本上是按一分钟一个周期上下波动。
对每个接口的平均响应时间曲线分析，发现所有接口的平均响应时间都有上升，再分析每个接口的调用量，除了六一期间，没有明显增加。可以排除是单个接口影响了整体响应时间。
同时对比多个接口的最大响应时间曲线，发现都是按一个频率上下波动，并且和整体平均响应时间的曲线是吻合的。
有规律性的上下波动，我猜测可能是由于什么堵塞，造成线程等待。再从代码上进行排查后，没有发现什么线索。还是找来DUMP 文件进行分析。
!threadpool 显示程序池信息
CPU不高 和 线程数量没有什么异常
!syncblk 显示同步块
发现有40来个线程来等待000000017f636630 这个同步块。51这个线程拥有这个同步块，其它的线程都在等待这个同步块的释放。看到这似乎找到了方向。
~51s 切找到51这个线程
!clrstack 列出当前线程的调用堆栈
51这个线程 正在执行 clearCache这个方法
!clrstack -l 列出当前线程的调用堆栈及其使用的局部变量
可以看到clearCache这个方法有引用 000000017f636630 这个同步块
~52s 切换到其中一个等待线程
可以看也有引用000000017f636630 这个同步块。System.Threading.Monitor.Enter(System.Object) 获取排他锁。
由于~51 clearCache 这个方法内LOCK 了这个对象，造成~52 Validate这方法等待锁的释放。
切换到它几个线程也是同样的情况。
这是引用的框架部门的DLL的两个方法，反编译这个DLL 找到这两个方法。
是一个清除日志的操作，每次清除 n 小时以前的数据。 N小时到当前时间内产生的数据，如果满足 > CountMax ，则一直会执行 这个FOR循环。
而且 remove(i) 会引起LogEntryCache.Count;的值变化，这样每次只能遍历一半。并发量大的情况，会造成每个线程漫长的等待。
并且在执行 ExecuteReader 内部就被锁住了。产生的DataReader还没有return,
DbConnection没有释放，就很有可能造成数据库连接池满。
!dumpstackobjects 打印当前thread的stack中保存的所有托管的object
找到System.Data.SqlClient.SqlCommand 的地址
!do 00000001805619e8 显示Command对象的内容
!do 0000000180561b30 显示SqlConnection
000000017f613c98 _poolGroup 该连接使用的连接池
下面找到这个连接池
!dumpheap –stat 检查当前所有托管类型的统计信息
找到System.Data.ProviderBase.DbConnectionPool
!dumpheap -mt 000007feedd23a98 查看函数表地址中的各个对象信息
!do 0x000000017f614748 显示DbConnectionPool
000000017f613c98 _connectionPoolGroup 这个连接池有14个等待。
更新DLL 后，问题解决。
标签：style blog http tar com strong
原文地址：http://www.cnblogs.com/zrhai/p/3784206.html
