【问题描述】
在应用端,偶尔看到有如下报错:
Authentication to host 'xxxx' for user 'yyyy' using method 'mysql_native_password' failed with message: Reading from the stream has failed.
表现特征:
"color: #ff0000">【问题分析】
我们在应用服务器端和数据库端抓包。两边抓到的包是一致的。可以排除网络问题。下面是抓到的包,以及时间点:
编号
绝对时间
相对时间(秒)
源头
目的
网络包内容
"background-color: #ffff99">"background-color: #ffff99">"background-color: #ffff99">"background-color: #ffff99">"background-color: #ffff99">"background-color: #ffff99">"text-align: center">
对比正常的数据库连接和上面异常的数据库连接。 应用服务器发送第5个包到数据库端后, 应该紧接着发送下面的网络包到数据库端的。这个包主要是发送账号,驱动版本,操作系统信息等到数据库服务器端。【下面是部分的正常的网络包截图】。在出现异常报错的场景,客户端是延迟发送这个包的。在Frame 8才发送的。而此时连接已经被Finish了,在Frame 9,数据库端发送了一个Reset包到应用服务器,彻底中断连接。
我们现在具体分析,为何客户端发送账号,驱动版本,操作系统信息到数据库端这么慢。这部分的代码在Connector/NET MySQLAuthenticationPlugin.cs文件中。 我们修改这部分代码,进行时间埋点,来进一步定位问题。下面是根据时间埋点,打印出来的跟踪信息。
从跟踪的Trace来看,有30秒左右的操作延时。返回MySQLDefs::OSDetails的时候。这部分代码如下:
[DisplayName("_os_details")] public string OSDetails { get { string os = string.Empty; try { var searcher = new System.Management.ManagementObjectSearcher("SELECT * FROM Win32_OperatingSystem"); var collection = searcher.Get(); foreach (var mgtObj in collection) { os = mgtObj.GetPropertyValue("Caption").ToString(); break; } } catch (Exception ex) { System.Diagnostics.Debug.WriteLine(ex.ToString()); } return os; } }
这段代码是通过WMI查询,来获得Caption信息。也就是操作系统的版本信息。由于是WMI调用,所以依赖的关系比较多。
【问题验证】
我们把这段代码抽出来。下面是一段简短的Repro代码:
static void Main(string[] args) { Stopwatch watch = new Stopwatch(); while (true) { watch.Restart(); var searcher = new System.Management.ManagementObjectSearcher("SELECT * FROM Win32_OperatingSystem"); var collection = searcher.Get(); foreach (var mgtObj in collection) { string os = mgtObj.GetPropertyValue("Caption").ToString(); } watch.Stop(); Console.WriteLine(watch.ElapsedMilliseconds); if (watch.ElapsedMilliseconds >= 1000) { Console.WriteLine("-------------"); File.AppendAllText("abc.txt", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff") +","+ watch.ElapsedMilliseconds + "\r\n"); } } }
在有问题的应用服务器上,我们运行上述代码,确实可以发现WMI查询有超时:下面这些点是我们抓到的超过30秒的点:
2017-11-21 17:19:30.208, 33638
2017-11-21 17:20:09.193, 33199
2017-11-21 17:20:53.086, 33201
2017-11-21 17:27:05.114, 32976
2017-11-21 17:28:19.178, 33635
2017-11-21 17:30:07.130, 65977
2017-11-21 17:30:49.051, 40478
2017-11-21 17:31:15.126, 26072
2017-11-21 17:38:16.048, 66671
2017-11-21 17:38:49.204, 33152
2017-11-21 17:39:53.161, 33828
2017-11-21 17:40:38.121, 33549
2017-11-21 17:47:09.179, 33775
2017-11-21 17:47:57.174, 33164
【解决思路】
WMI查询慢,可能是由于多种原因所致。如操作系统CPU高,或者查询本身有死锁。这个问题有待于进一步分析。但看代码,我们知道做这个WMI查询,只是为了获得操作系统的信息。这个信息完全可以缓存起来。而不必要每次连接的时候,去进行WMI查询。
此处确定该错误的根本原因在于MySQL的C# connector中对操作系统信息的获取时间过久,导致触发服务器的连接超时。注释掉该部分(可能导致长时间的操作),进行进一步的验证,再无任何的超时错误出现。
public string OSDetails { get { dbglog.dolog("MysqlDefs::OSDetails1"); string os = string.Empty; /*try { var searcher = new System.Management.ManagementObjectSearcher("SELECT * FROM Win32_OperatingSystem"); var collection = searcher.Get(); foreach (var mgtObj in collection) { os = mgtObj.GetPropertyValue("Caption").ToString(); dbglog.dolog(String.Format("MysqlDefs::OSDetails::foreach{0}", os.ToString())); break; } } catch (Exception ex) { System.Diagnostics.Debug.WriteLine(ex.ToString()); }*/ dbglog.dolog("MysqlDefs::OSDetails2"); return os; } }
总结
以上就是这篇文章的全部内容了,希望本文的内容对大家的学习或者工作具有一定的参考学习价值,如果有疑问大家可以留言交流,谢谢大家对的支持。
更新日志
- 小骆驼-《草原狼2(蓝光CD)》[原抓WAV+CUE]
- 群星《欢迎来到我身边 电影原声专辑》[320K/MP3][105.02MB]
- 群星《欢迎来到我身边 电影原声专辑》[FLAC/分轨][480.9MB]
- 雷婷《梦里蓝天HQⅡ》 2023头版限量编号低速原抓[WAV+CUE][463M]
- 群星《2024好听新歌42》AI调整音效【WAV分轨】
- 王思雨-《思念陪着鸿雁飞》WAV
- 王思雨《喜马拉雅HQ》头版限量编号[WAV+CUE]
- 李健《无时无刻》[WAV+CUE][590M]
- 陈奕迅《酝酿》[WAV分轨][502M]
- 卓依婷《化蝶》2CD[WAV+CUE][1.1G]
- 群星《吉他王(黑胶CD)》[WAV+CUE]
- 齐秦《穿乐(穿越)》[WAV+CUE]
- 发烧珍品《数位CD音响测试-动向效果(九)》【WAV+CUE】
- 邝美云《邝美云精装歌集》[DSF][1.6G]
- 吕方《爱一回伤一回》[WAV+CUE][454M]