导读
什么情况下会出现 unauthenticated user,该怎么办?
前几天,我的朋友小明同学微信上找到我,说mysql错误日志很频繁的打印下面的日志:
Aborted connection 16021014 to db: 'unconnected' user: 'unauthenticated' host: 'connecting host' (Can't get hostname for your address)
我的第一反应是可能有几种情况:
1、开了线程池,且thread_pool_size可能开太小了,或者thread_pool_stall_limit采用默认值(也就是500)。如果有较高并发请求,且每次请求的SQL效率都比较低的话,是有可能会造成线程池切换响应不过来,有些连接请求会失败。
2、可能有来自外部的不安全扫描、探测,就是简单的测试下3306端口是否能连通,以及探测mysql版本号,想借此寻求机会入侵。这种情况,有较大可能性是mysql不是只绑定到内部网卡,在公网网卡上也绑定了。
3、应用端疯狂连接,mysql端响应较慢,主机名反解析较慢导致。
4、在mysql的前端有监控、探测程序,时不时要检测其是否存活。比如zabbix agent会定期连接mysql获取监控数据,也有可能是高可用组件或SLB(Server Load Balancer,服务器负载均衡)组件定期探测mysql是否存活。
5、前端某些应用程序配置了错误的账号密码。不过这种情况会报告类似 Access denied 这样的日志,和本案例中的日志不一样。
再交代下这个mysql实例的大概情况:
当前系统负载和mysqld进程负载都不高。
采用Percona-Server-5.6.34版本,且开启了线程池(thread pool)。
这是一个游戏后端数据库。
游戏程序端采用连接池+长连接方式(这...都长连接了还开线程池嘎哈),平时保持的连接数约有将近1000个。
交代完背景,我们就照着上面的几个可能性逐个排查吧。
1、线程池
线程池相关的配置如下:
thread_handling = pool-of-threadsthread_pool_high_prio_mode = transactionsthread_pool_high_prio_tickets = 4294967295thread_pool_idle_timeout = 60thread_pool_max_threads = 100000thread_pool_oversubscribe = 3thread_pool_size = 16thread_pool_stall_limit = 500
可以看到,thread_pool_size 和 thread_pool_stall_limit 这两个选项看起来都不是太合理,先尝试调整成:
thread_pool_size = 128thread_pool_stall_limit = 10
调整完后,继续观察,发现无果。看来不是线程池设置不合理导致的了,继续下一个疑点。
2、外部扫描、探测
这个实例只绑定了内部网卡,并未对公网开放,执行了 netstat -nat 查看也未发现有看起来比较怪异的源IP连接。
跳过。
3、主机名反解析慢导致
本例中,不是这个原因引起的,因为已经设置了 skip_name_resolve = 0。
4、前端有监控、探测程序
首先检查zabbix agent程序,账号、密码配置是正确的,还不死心,干脆把agent程序先临时停一下,发现也还是跟它没关系。跳过。
看来大概率是有什么高可用或SLB组件做存活探测了。一问之下,果真是用了某公有云的SLB服务,它会频繁(约1秒3、4次)的探测mysql端口。事实上,这个情况以前也遇到过,甚至还发生过因为SLB探测太过频繁,结果被mysql给blocked的“故障”,所以后来要求把选项 max_connect_errors的值加大,检查了下,还真是设置很大:
max_connect_errors = 100000000000
把SLB服务先临时停一下,开头所说的告警日志果真就不再产生了。找到问题原因所在。
解决问题
在本案中,因为应用程序已经采用了连接池+长连接,因此也就没必要启用线程池了,所以就先把线程池给关了吧。
神奇的一幕发生了,关闭线程池之后,在SLB服务仍旧启用的情况下,上述日志居然不再产生了,这特么的...手动黑人问号脸???.jpg
经过测试验证,发现的确是只要开了线程池(采用Percona版本),在这种情况下就会一直发出告警,好吧,忍了,关掉就好了。
同时,因为长连接约有1000个,因此调整 thread_cache_size = 2000。
至此,这个问题算是暂时解决了(其实只算解决了一半)。
后记
我又在MySQL 5.6和8.0的环境下做了测试,用 telnet 或 nc 模拟探测 3306 端口的行为,发现确实是会出现类似下面的状态:
| 10165 | unauthenticated user | 127.0.0.1:59004 | | Connect | 3 | login |
此外,错误日志上也会打印类似下面的内容:
...[Note]...Got an error reading communication packets...[Note]...Got packets out of order
顺便对公有云厂商们提个建议,SLB服务可以增加针对mysql数据库的探测方式,比如下面这样用:
这样就不会导致日志里记录大量的Note事件了。
延伸阅读
END
扫码加入QQ技术交流群
(群号:793818397)
长期坚持原创不易,转发、点“在看”、打赏都是对我最好的支持