DBPRoxy 监控用户(backend-monitor-pwds)未配置,引起后端DB日志出现登陆报错

最近,在新上线的一套DBProxy+MySQL项目过程中,发现后端MySQL DB出现登陆报错:

[Warning] Access denied for user ‘apps’@’192.168.1.146’ (using password: NO)

以上报错为测试环境,模拟产生的报错信息,实际生产环境是 Access denied for user ‘root’@’proxy IP’ (using password: NO)

查看了其它DBProxy后端的DB,没有此类报错。

对比问题DBPrroxy和正常DBProxy的配置文件,版本等信息,发现都是一样,无差异。

这样看来,好紧张,居然有root用户尝试远程登陆,这是多危险,被攻击了????当时的第一反应(其实要说明一点,root用户其实设置了只能本地登录)。

登陆问题DBProxy服务器,查询进程,top,抓包,看proxy日志,系统日志,都未发现异常,但是,后端所有DB的报错还在持续。

果断,在测试环境复现问题,复现环境如下:

MySQL Version:MySQL 5.7.22

DBPrroxy Version:5.0.99-agent-admin

MySQL 重要参数配置:log_warnings = 2 (设定是否将警告信息记录进错误日志。默认设定为1,表示启用;可以将其设置为0以禁用;而其值为大于1的数值时表示将新发起连接时产生的“失败的连接”和“拒绝访问”类的错误信息也记录进错误日志)

后端DB报错截图如下:

4

在测试环境复现,我们发现如下几个问题:

1.如果用错误的账号来连接DBProxy时,DBProxy的日志会打印出报错信息(这里的192.168.1.146 为DBProxy的IP地址),但我们生产环境上DBProxy没有任何相关报错日志

测试命令如下:

[apps@unify-mysql mysql]$ mysql -uapp -p -h192.168.1.146 -P8888
Enter password:
ERROR 1045 (28000): Access denied for user ‘app’@’192.168.1.146’ (using password: YES)

DBProxy报错截图如下:

2

2.从DB后端错误日志,我们发现一些问题:

生产环境是root@proxy ip 登陆报错,root账号,后端DB是存在这个账号的,这个也就是我们第一反应被攻击的缘由

测试环境是apps@proxy ip登陆报错,apps账号,后端DB不存在这个账号,这是怎么回事呢?大家猜猜!!!文章结尾,我揭晓原因~~~

3.我们尝试从DBProxy,剔除一台从库,看看还会不会报错,剔除后,发现日志干净了,一点报错也没有,到这里,我们心里就踏实了,不是被攻击了,是DBProxy自己去连后端DB的!!

4.于是我们仔细检查DB日志,发现登陆存在一定的规律性,每隔4秒,出现一次报错,截图如下:

1

同时,我们看了DBProxy的相关参数,发现有一项参数,正好设置的是4秒,同时,我咨询了官方的海涛同学,证实了我们刚才的猜想,答复是这样的:

MySQL协议里,如果没有显示的指明用户名的话,会使用root连接。DBProxy里,如果没有配置monitor账号,DBProxy在监控后端DB的时候,会使用NULL用户名去连接DB,MySQL端会认为是root账号连接的。默认proxy的monitor周期检测是4s一次,但是每次检测会遍历每个DB,所以并非完全4s精准~

于是,我们设置monitor账号,命令如下:

set backend-monitor-pwds=dbproxy_user:dbproxy_user;

此时参数的截图如下:

3

此时,我们再看后端DB的日志,发现错误消失了,问题到此,算是找到原因,并解决了

总结:

1.为什么线上环境报错日志是root连,而测试环境报错日志是用apps连??

如果贵司已经进行目录标准化后,我相信您的部署,肯定不是用官方的脚本,而是按照自己的规则定义,比如目录属主,安装路径,启动用户等等,这里就是因为线上用root用户启动,目录属主为root。而测试环境是我自定义安装的,属主为apps用户,启动用户也是apps用户

2.线上DBProxy文件,对比一致,为什么只有这一套环境有报错??

由于DB配置文件不标准化,部署因人而异,log_warnings设置成0了,这个因公司而异,很多公司,这个参数的确设置为0

3.最后,要说明的,任何自动化的前提,都需要标准化,这里不仅目录标准化,还有配置标准化,部署标准化,操作标准化等等。任重而道远~~~

DBProxy Warning: Syntax Forbidden Set option:^A 分析及应对方案

      在我们的日常运维中,随着公司业务的持续发展,DB的单机性能逐渐满足不了要求,大家首先想到的可能是拆表,拆库,扩容,归档,提升硬件配置等等,但实际业务场景中,往往优先出现瓶颈的是读的性能,这也就是,我下面要说的数据库读写分离。
       目前,每个公司的读写分离策略都不太一样,有的采用的是开源的数据库中间件,对应用开发来说,是透明的;有的公司采用的是代码层时间读写分离,需要对代码有一定的倾入性;也有采用自研其他方案。
       现阶段,由于我们绝大多数应用是PHP应用,业务持续发展,代码层实现读写分离,过于繁琐,持续时间长,研发经历有限,最终,经过调研,先后选型了Atlas/DBProxy,目前,公司读写分离中间件,90%都是使用DBProxy。在使用过程中,难免会碰到各种问题,但相对来说,DBProxy的稳定性不错,官方答复问题的速度也是非常迅速,是一个非常棒的开源团队,这里特别需要感谢一下,DBProxy官方团队的海涛同学,多次协助分析问题。
       DBProxy的下载,部署等环节,这里忽略,请移步官方文档,文档写的非常明确详实。
       DBProxy github地址:https://github.com/Meituan-Dianping/DBProxy
       我们使用DBProxy过程中,也并非一帆风顺,也遇到一些问题,比如,业务代码里有一些,Proxy不支持的语法问题,如Proxy Warning – Syntax Forbidden Set option:^A
———————————————————————————————————
下面,我们重点进行分析这个警告的来源及处理方案:
1.报错产生的环境:
         DBProxy Version:5.0.99-agent-admin
         MySQL Version:5.6.25 / 5.5.5-10.2.14-MariaDB-log
         PHP Version:5.6.11
         WARNING:2018-06-25 15:16:24.281125: (critical)proxy-plugin.c:2125(proxy_read_query) event_thread(1) C:192.168.1.146:52396 S:192.168.1.146:8888(thread_id:0) Usr:dbproxy_user Db:dbproxy Proxy Warning – Syntax Forbidden Set option:^A
2.遇到这个问题,首先,我们第一时间打开sql log,因为从日志看,没法知道具体是什么set操作,proxy不支持。
        mysql> set sql-log=on;
        mysql> set sql-log-slow-ms=0;
        mysql> set long-query-time=0;
3.查看SQL日志,这个目录一般在安装路径下的log/sql目录下,部分日志如下:(这里我们利用测试代码,重现错误,后面提供php测试代码)
       2018-06-25 15:16:24.281250: C:192.168.1.146:52396 C_db:dbproxy C_usr:dbproxy_user [Slow Query] 0.164(ms) Set option ^A
       2018-06-25 15:16:24.281876: C_begin:2018-06-25 15:16:24.281327 C:192.168.1.146:52396 C_db:dbproxy C_usr:dbproxy_user S:192.168.1.146:3307(thread_id:1041192) S_db:dbproxy S_usr:dbproxy_user inj(type:4
 bytes:0 rows:0) 0.438(ms) OK Query:SET character_set_connection=utf8, character_set_results=utf8, character_set_client=binary
       2018-06-25 15:16:24.281977: C:192.168.1.146:52396 C_db:dbproxy C_usr:dbproxy_user [Slow Query] 0.648(ms) Query SET character_set_connection=utf8, character_set_results=utf8, character_set_client=bina
ry
       2018-06-25 15:16:24.282334: C_begin:2018-06-25 15:16:24.282083 C:192.168.1.146:52396 C_db:dbproxy C_usr:dbproxy_user S:192.168.1.146:3307(thread_id:1041192) S_db:dbproxy S_usr:dbproxy_user inj(type:4
bytes:0 rows:0) 0.204(ms) OK Query:SET sql_mode=”
       从上面的日志看,最初认为是SET character_set_connection=utf8, character_set_results=utf8, character_set_client=binary,SET sql_mode=” 这些操作的不支持造成,但是,反复测试发现,这些不是根源,而且,从日志观察看,提示OK Query,说明,这个操作,Proxy是支持的,并且是成功,如果不支持的话,Proxy日志应该报ERRQuery.
       所以,从日志看,就是一个Set option ^A,让研发按关键字搜索代码,研发表示懵逼,代码里没有这个操作,搜索其他set操作,如SET character_set_connection=utf8 ,代码倒是有,于是,排查问题,陷入僵局,代码里没有,那么是哪里的问题,但是,直觉告诉你,这肯定和代码有关系,于是,有了下面的抓包分析问题。
       测试代码:测试代码1
4.在DB层或proxy层抓包分析:
抓包:tcpdump -i any tcp and port 3306 -s 500 -w proxy.pcap
分析工具:wireshark
定位截图:
QQ图片20180628104223
       从抓包分析,我们看到,做了multi statements off 操作造成,但是代码里的确没有这个操作,此时,我们判断,可能是PHP自身的函数造成的。
        搜了很多multi statement相关文档后,怀疑是使用了multi_query()这个函数,我们用multi_query()进行查询,的确可以复现问题,感觉快要看到光明了。呵呵….,再次让研发帮忙搜索代码,研发又一次懵逼,代码里没有用到这个函数,擦,瞬间掉到冰窟窿里了,这是哪里出了问题。
       使用mysqli_quey()函数测试代码:测试代码2
       于是,重新模拟代码测试发现(见测试代码1),模拟的代码里只有mysql_connect()和mysql_query()这两个关键函数,会不会是这两个函数的问题呢???
       于是,我们进行了替换,修改为:mysqli_query(),mysql_connect 修改为 mysqli_connect() 问题解决
       见测试代码:测试代码3
       有关mysql_connect()/mysql_query(),PHP官方是这样说的:
       mysql_connect — 打开一个到 MySQL 服务器的连接
       Warning
       本扩展自 PHP 5.5.0 起已废弃,并在自 PHP 7.0.0 开始被移除。应使用 MySQLi 或 PDO_MySQL 扩展来替换之
       这也就是,为什么php7的应用代码,没有这个问题。其实,虽然php5开始废弃,但是并没有被移除,所以,老的函数依然可以使用。这也就是我这边是php5.6的代码,为什么有这个问题
5.最终处理方案:
       mysql_connect()/mysql_query() 替换为 mysqli_connect()/mysqli_query()
6.测试代码如下:
       每段代码的开头和结尾分别加上<?php 和 ?>,进行测试

1.测试代码1:
$con = mysql_connect("192.168.1.146:8888","dbproxy_user","dbproxy_user");
if (!$con)
{
die('Could not connect: ' . mysql_error());
}
mysql_select_db("dbproxy", $con);
$sql_1 = "SET character_set_connection=utf8, character_set_results=utf8, character_set_client=binary";
mysql_query($sql_1,$con);
$sql_2 = "SET sql_mode=''";
mysql_query($sql_2,$con);
$sql_3 = "select * from shirt limit 1;";
mysql_query($sql_3,$con);
mysql_close($con);

2.测试代码2:
$mysqli = new mysqli("192.168.1.146", "dbproxy_user", "dbproxy_user", "",'8888');
if ($mysqli->connect_errno) {
echo "Failed to connect to MySQL: (" . $mysqli->connect_errno . ") " . $mysqli->connect_error;
}
$mysqli->query("SET NAMES 'UTF8'");
$mysqli->query("SET sql_mode=''");
$mysqli->query("SET character_set_connection=utf8, character_set_results=utf8, character_set_client=binary");
$sql = "INSERT INTO test(id) VALUES (1);";
$sql.= "select id from test;";
if (!$mysqli->query($sql)) {
echo "Multi query failed: (" . $mysqli->errno . ") " . $mysqli->error;
}
if (!$mysqli->multi_query($sql)) {
echo "Multi query failed: (" . $mysqli->errno . ") " . $mysqli->error;
}

3.测试代码3:
$con = mysqli_connect("192.168.1.146","dbproxy_user","dbproxy_user","dbproxy","8888");
if (!$con)
{
die('Could not connect: ' . mysql_error());
}
$sql_1 = "SET character_set_connection=utf8, character_set_results=utf8, character_set_client=binary";
$sql_2 = "SET sql_mode=''";
$sql_3 = "select * from shirt limit 1;";
mysqli_query($con,$sql_1);
mysqli_query($con,$sql_2);
mysqli_query($con,$sql_3);
mysqli_close($con);