故障分析 | 从一则错误日志到 MySQL 认证机制与 bug 的深入分析

时间:2022-01-23 01:09:29

作者:李锡超
一个爱笑的江苏苏宁银行 数据库工程师,主要负责数据库日常运维、自动化建设、DMP平台运维。擅长MySQL、Python、Oracle,爱好骑行、研究技术。
本文来源:原创投稿

* 爱可生开源社区出品,原创内容未经授权不得随意使用,转载请联系小编并注明来源。


研发同学反馈某系统性能测试环境MySQL数据库相关的业务系统运行正常,但存在大量警告日志,需配合分析原因。

一、异常现象

MySQL 错误日志文件中存在大量如下信息:

2023-01-10T01:07:23.035479Z 13 [Warning] [MY-013360] [Server] Plugin sha256_password reported: 
''sha256_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'

关键环境信息

数据库版本
MySQL 8.0.27
操作系统版本
RHEL 7.3
数据库架构
单机(测试环境)
错误日志级别(log_error_verbosity) 2(输出 ERROR,WARNING)
授权插件
caching_sha2_password(默认)

二、初步分析

当看到如上警告日志时,根据经验主义,第一反应应该是客户端的版本过低,其授权认证插件是服务端将要废弃的版本,所以产生了以上告警信息。特别是一些常见的客户端工具,可能会由于更新频率,会很容易触发该问题。

尝试复现

根据初步分析建议,将初步分析建议与研发同学沟通后,通过常见的数据库工具访问数据库,看能否复现该错误。但通过数据库里面常见的数据库用户,通过不同的工具访问数据库,均未在访问时刻触发该异常。由此,第一次尝试复现失败。难道是因为其它原因?

在第一次尝试访问的过程,通过实时观察数据库错误日志。在用客户端尝试访问的过程中,没有复现该错误。但是仍然看到对应的警告日志在持续输出到错误日志文件。且频率较高、间隔时间固定,由此也证明该错误不是数据库工具人工访问的。

应用系统运行正常,又不是客户端导致的!作为DBA的你,应该如何进一步分析呢?

初放小招

由于所处测试环境,针对该错误,可以执行如下操作启用MySQL的一般日志:

-- 开通一般日志:
show variables like 'general_log';
set global general_log=on;
show variables like 'general_log';
-- 查看一般日志路径:
show variables like 'general_log_file';
启用日志后,观察错误日志,发现一般日志中如下记录:
故障分析 |  从一则错误日志到 MySQL 认证机制与 bug 的深入分析

提示:发现异常后,立即关闭一般日志,避免产生过多日志耗尽磁盘空间:

-- 开通一般日志:
show variables like 'general_log';
set global general_log=off;
show variables like 'general_log';
即用户 dbuser2 在问题时刻从10.x.y.43 服务器发起了访问数据库的请求。确认异常访问的用户和服务器后,检查数据库mysql.user表、skip-grant-tables等配置,发现数据库并不存在该用户,且没有跳过授权表等配置。使用该用户将无法登录到数据库。
将信息反馈至研发同学,很快就确认了是由于部分应用配置不合理,使用了不存在的数据库用户,并定时连接数据库执行任务。于是研发同学修改配置后,警告日志不再产生。
那么该问题分析到此,可以结束了么?
修改配置后,警告日志不再发生!但既然是不存在的用户,访问时为什么还提示认证插件将废弃呢?

三、源码分析

带着问题,首先想到的是:既然数据库用户为存在于mysql.user表,登录也会产生警告,难道这个用户是MySQL的内部用户,被硬编码了么!于是取到对应版本源码,通过如下命令进行确认:
cd mysql-8.0.27/
grep -rwi "dbuser2" *
其访问结果为空,即不存在猜想的“内部用户”。

正常登录认证逻辑

既然没有硬编码,那就只能是内部逻辑导致。于是首先对正常情况下MySQL用户登录过程,源码分析结果如下:

|—> handle_connection
 |—> thd_prepare_connection
   |—> login_connection
     |—> check_connection
       // 判断客户端的主机名是否可以登录(mysql.user.host),如果 mysql.user.host 有 '%' 那么将 allow_all_hosts,允许所有主机。
       |—> acl_check_host  
       |—> acl_authenticate
         |—> server_mpvio_initialize // 初始化mpvio对象,包括赋值 mpvio->ip / mpvio->host
         |—> auth_plugin_name="caching_sha2_password"
         |—> do_auth_once
           |—> caching_sha2_password_authenticate // auth->authenticate_user
             |—> server_mpvio_read_packet // vio->read_packet(vio, &pkt) // pkt=passwd
               |—> parse_client_handshake_packet
                 |—> char *user = get_string(&end, &bytes_remaining_in_packet, &user_len);
                 |—> passwd = get_length_encoded_string(&end, &bytes_remaining_in_packet, &passwd_len);
                 |—> mpvio->auth_info.user_name = my_strndup(key_memory_MPVIO_EXT_auth_info, user, user_len, MYF(MY_WME))
                 // 根据 user 搜索 mysql.user.host ,并与客户端的 hostname/ip 进行比较:匹配记录后,赋值 mpvio->acl_user
                 |—> find_mpvio_user(thd, mpvio)
                   |—> list = cached_acl_users_for_name(mpvio->auth_info.user_name); // 根据 user 搜索 mysql.user.host
                   |—> acl_user_tmp->host.compare_hostname(mpvio->host, mpvio->ip) //  与客户端的 hostname/ip 进行比较
                   |—> mpvio->acl_user_plugin = mpvio->acl_user->plugin; // 赋值 acl_user_plugin 属性为用户的plugin名
                   |—> mpvio->auth_info.multi_factor_auth_info[0].auth_string = mpvio->acl_user->credentials[PRIMARY_CRED].m_auth_string.str;
                   |—> mpvio->auth_info.auth_string = mpvio->auth_info.multi_factor_auth_info[0].auth_string;
                 |—> if (my_strcasecmp(system_charset_info, mpvio->acl_user_plugin.str,plugin_name(mpvio->plugin)->str) != 0)
                 |—> my_strcasecmp(system_charset_info, client_plugin,user_client_plugin_name) //检查客户端的认证插件与用户插件是否相同
             |—> make_hash_key(info->authenticated_as, hostname ? hostname : nullptr, authorization_id);  // 生成 authorization_id = user1\000%
             |—> g_caching_sha2_password->fast_authenticate(authorization_id,*scramble,20,pkt,false) // 进行快速授权操作
               |—> m_cache.search(authorization_id, digest) // 根据 user、host 搜索密码,赋值到digest
               |—> Validate_scramble validate_scramble_first(scramble, digest.digest_buffer[0], random, random_length);
               |—> validate_scramble_first.validate(); // 校验 scramble
             // 如验证成功
             |—> vio->write_packet(vio, (uchar *)&fast_auth_success, 1)
             |—> return CR_OK;
             // 否则进行进行慢授权操作
             |—> g_caching_sha2_password->authenticate( authorization_id, serialized_string, plaintext_password);
         |—> server_mpvio_update_thd(thd, &mpvio);
         |—> check_and_update_password_lock_state(mpvio, thd, res);
         // 继续其它授权操作
即核心的认证操作在函数 caching_sha2_password_authenticate() 中执行,先调用函数find_mpvio_user(),通过user、hostname找到已经配置的用户,然后调用函数fast_authenticate()对密码进行快速验证。

使用不存在用户认证逻辑

当用户不存在时,MySQL用户登录过程,源码分析结果如下:

|—> handle_connection
 |—> thd_prepare_connection
   |—> login_connection
     |—> check_connection
       // 判断客户端的主机名是否可以登录(mysql.user.host),如果 mysql.user.host 有 '%' 那么将 allow_all_hosts,允许所有主机。
       |—> acl_check_host  
       |—> acl_authenticate
         |—> server_mpvio_initialize // 初始化mpvio对象,包括赋值 mpvio->ip / mpvio->host
         |—> auth_plugin_name="caching_sha2_password"
         |—> do_auth_once
           |—> caching_sha2_password_authenticate // auth->authenticate_user
             |—> server_mpvio_read_packet // vio->read_packet(vio, &pkt) // pkt=passwd
               |—> parse_client_handshake_packet
                 |—> char *user = get_string(&end, &bytes_remaining_in_packet, &user_len);
                 |—> passwd = get_length_encoded_string(&end, &bytes_remaining_in_packet, &passwd_len);
                 |—> mpvio->auth_info.user_name = my_strndup(key_memory_MPVIO_EXT_auth_info, user, user_len, MYF(MY_WME))
                 |—> find_mpvio_user(thd, mpvio)
                   |—> list = cached_acl_users_for_name(mpvio->auth_info.user_name); // 根据 user 搜索 mysql.user.host, 由于用户不存在,搜索不到记录
                   |—> mpvio->acl_user = decoy_user(usr, hst, mpvio->mem_root, mpvio->rand, initialized); //
                     |—> Auth_id key(user);
                     // 判断是否用户存在于 unknown_accounts
                     |—> unknown_accounts->find(key, value)
                     // 如存在:
                     |—> user->plugin = Cached_authentication_plugins::cached_plugins_names[value];
                     // 如不存在:
                     |—> const int DECIMAL_SHIFT = 1000;
                     |—> const int random_number = static_cast<int>(my_rnd(rand) * DECIMAL_SHIFT);
                     |—> uint plugin_num = (uint)(random_number % ((uint)PLUGIN_LAST));
                     |—> user->plugin = Cached_authentication_plugins::cached_plugins_names[plugin_num];
                     |—> unknown_accounts->insert(key, plugin_num)
                   |—> mpvio->acl_user_plugin = mpvio->acl_user->plugin; // 赋值 acl_user_plugin 属性为用户的plugin名
                   |—> mpvio->auth_info.multi_factor_auth_info[0].auth_string = mpvio->acl_user->credentials[PRIMARY_CRED].m_auth_string.str; // ""
                   |—> mpvio->auth_info.auth_string = mpvio->auth_info.multi_factor_auth_info[0].auth_string; // ""
                   |—> mpvio->auth_info.additional_auth_string_length = 0; // 0
                   |—> mpvio->auth_info.auth_string_length = mpvio->auth_info.multi_factor_auth_info[0].auth_string_length; // 0
                 |—> if (my_strcasecmp(system_charset_info, mpvio->acl_user_plugin.str,plugin_name(mpvio->plugin)->str) != 0)
                 |—> return packet_error;
               |—> if (pkt_len == packet_error) goto err;
               |—> return -1;
         |—> auth_plugin_name = mpvio.acl_user->plugin;
         |—> res = do_auth_once(thd, auth_plugin_name, &mpvio);
           |—> sha256_password_authenticate() //auth->authenticate_user(mpvio, &mpvio->auth_info);
             |—> LogPluginErr // Deprecate message for SHA-256 authentication plugin.
             // 打印: 2023-01-10T01:07:23.035479Z 13 [Warning] [MY-013360] [Server] Plugin sha256_password reported: ''sha256_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'
             |—> server_mpvio_read_packet() // vio->read_packet(vio, &pkt)
             |—> if (info->auth_string_length == 0 && info->additional_auth_string_length == 0) // info -> auth_info
             |—>   return CR_ERROR;
           |—> return res; // 0
         |—> server_mpvio_update_thd(thd, &mpvio);
         |—> check_and_update_password_lock_state(mpvio, thd, res); // 直接返回
         ...
         |—> login_failed_error // 打印登录报错信息
         // 2023-01-10T02:02:44.659796Z 19 [Note] [MY-010926] [Server] Access denied for user 'user2'@'localhost' (using password: YES)
     |—> thd->send_statement_status();  // 客户端终止
即当使用不存在的用户登录数据库时,通过函数 decoy_user() 创建的 acl_user 对象。在创建这个对象时,其 plugin 属性采用随机方式从 cached_plugins_enum 选择。从而有可能选择到 PLUGIN_SHA256_PASSWORD 插件。但在函数sha256_password_authenticate() 的入口,就会生成Warning级别的提示,以提示该验证PLUGIN_SHA256_PASSWORD 将被废弃。随后,由于在decoy_user() 创建的 acl_user 对象auth_string_length 长度未0,在后续的认证逻辑中会直接返回CR_ERROR,即认证失败。

根因总结

根据以上认证过的分析,导致错误日志存在 PLUGIN_SHA256_PASSWORD 将被废弃的根本原因为:在当前版本,当使用不存在的用户登录数据库时,mysql会随机选择用户的密码认证插件,在当前的版本版本中,有1/3的概率会选择到  PLUGIN_SHA256_PASSWORD 插件。选择该插件后,在后续的认证逻辑将会触发警告日志生成。

四、问题解决

综合以上分析过程,导致该问题的直接原因是应用配置了不存在的数据库用户,根本原因为数据库登录认证逻辑存在一定缺陷。那么解决该问题可参考如下几种方案:

1. 参考初步分析中的方案,将应用的连接配置修改为正确的用户信息;

2. 可以在MySQL数据库中通过参数将该告警过滤,避免该告警信息输入到错误日志文件。相关配置如下:

show variables like 'log_error_suppression_list';
set global log_error_suppression_list='MY-013360;
show variables like 'log_error_suppression_list';
注意,使用该方案也会导致某个存在且使用SHA256_PASSWORD认证插件产生的告警。可以作为临时方案;
3. 修改MySQL代码,避免在使用不存在用户登录数据库时,选择 SHA256_PASSWORD认证插件。目前针对该方案已提交Bug #109635。

附:关键函数位置

find_mpvio_user() (./sql/auth/sql_authentication.cc:2084)
parse_client_handshake_packet() (./sql/auth/sql_authentication.cc:2990)
server_mpvio_read_packet() (./sql/auth/sql_authentication.cc:3282)
caching_sha2_password_authenticate() (./sql/auth/sha2_password.cc:955)
do_auth_once() (./sql/auth/sql_authentication.cc:3327)
acl_authenticate() (./sql/auth/sql_authentication.cc:3799)
check_connection() (./sql/sql_connect.cc:651)
login_connection() (./sql/sql_connect.cc:716)
thd_prepare_connection() (./sql/sql_connect.cc:889)
handle_connection() (./sql/conn_handler/connection_handler_per_thread.cc:298)
文关键字:#MySQL 源码# #认证授权机制# #decoy_user#