您当前的位置:首页 > 电脑百科 > 站长技术 > 服务器

一次诡异的Mysql服务不断重启故障排查

时间:2020-09-01 16:42:37  来源:  作者:
一次诡异的Mysql服务不断重启故障排查

 

前段时间,有测试人员联系我,寻求帮助,让我帮忙看看,测试环境的一台MySQL数据库不断的重启,导致他们的测试无法进行,时间拖的长了,会影响上线进度。

下面就来说说现象

在一个测试环境,mysql5.7部署在centos7.4的系统上,测试人员用LoadRunner进行应用的一个压测测试,压测并发为128,启动LoadRunner过几秒,LoadRunner日志就报错,显示mysql服务断开了,过几秒又恢复,然后又断开,异常诡异。

排查定位

于是就登录到服务器,看一下数据库服务器的内存,内存已经用完了,紧接着就看centos的系统日志(/var/log/messages),在这个日志里发现mysql服务因为OOM,导致进程被系统给kill掉了,然后因为mysql服务有守护进程存在,又被自动启动了。

一个经验丰富的mysql数据库运维人员,应该很快就知道什么原因导致OOM了。
第一:mysql数据库的buffer pool内存参数配置不合理
第二:mysql数据库的session初始化内存参数配置不合理
第三:数据库连接总数配置不合理

测试环境的数据库服务器内存为4G,在这里就不谈,为什么测试人员要在这个服务器上做压测,其实做应用压测,应该要用准用的压测环境,而不是随便找个环境就压测,不展开说了。

模拟复盘

测试环境
mysql5.7,centos7.7,内存2G

为了更好的模拟复盘上述故障,这里关闭掉模拟环境的swap,关闭步骤如下所示

[root@localhost data]# free -m
              total        used        free      shared  buff/cache   available
Mem:           2124         565         640           9         917        1398
Swap:          2047           0        2047
[root@localhost data]# swapon -s
文件名                          类型            大小    已用    权限
/dev/dm-1                               partition       2097148 264     -2
[root@localhost data]# swapoff /dev/dm-1
[root@localhost data]# free -m
              total        used        free      shared  buff/cache   available
Mem:           2124         254         944           9         925        1709
Swap:             0           0           0

从上面free -m结果中,可以看到swap已经变成0了。

释放cache占用的内存

[root@localhost data]# sync
[root@localhost data]# echo 1 > /proc/sys/vm/drop_caches ;  
[root@localhost data]# free -m
              total        used        free      shared  buff/cache   availableMem:           2124         254        1784           9          84        1748
Swap:             0           0           0

可以看到目前剩余的内存为1784M,mysql数据库占用内存主要有2大块,第一是:buffer pool占用,第二是:初始化连接占用的内存

在这里设置mysql的buffer pool为1500M,会话的参数设置如下

read_buffer_size = 32M
read_rnd_buffer_size = 32M
sort_buffer_size = 32M
tmp_table_size = 32M
max_heap_table_size=32M
join_buffer_size=32M

然后5个连接,开始做大查询操作,没过多久,mysql进程就因为OOM被kill了

Aug 31 05:37:40 localhost kernel: Out of memory: Kill process 2534 (mysqld) score 658 or sacrifice child
Aug 31 05:37:40 localhost kernel: Killed process 2534 (mysqld), UID 1001, total-vm:1825792kB, anon-rss:654388kB, file-rss:0kB, shmem-rss:0kB

mysql守护进程就开始启动mysql服务

/u02/mysql/bin/mysqld_safe: 行 198:  2534 已杀死                  nohup /u02/mysql/bin/mysqld --defaults-file=/u02/conf/my3308.cnf --basedir=/u02/mysql --datadir=/u02/data/3308 --plugin-dir=/u02/mysql/lib/plugin --user=mysql --log-error=/u02/log/3308/error.log --open-files-limit=65535 --pid-file=/u02/run/3308/mysqld.pid --socket=/u02/run/3308/mysql.sock --port=3308 < /dev/null > /dev/null 2>&1
2020-08-30T21:37:40.375749Z mysqld_safe Number of processes running now: 0
2020-08-30T21:37:40.407781Z mysqld_safe mysqld restarted
2020-08-30T21:37:40.666886Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2020-08-30T21:37:40.667059Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2020-08-30T21:37:40.667112Z 0 [Note] /u02/mysql/bin/mysqld (mysqld 5.7.26-log) starting as process 2954 ...
2020-08-30T21:37:40.782412Z 0 [Warning] InnoDB: Using innodb_file_format is deprecated and the parameter may be removed in future releases. See http://dev.mysql.com/doc/refman/5.7/en/innodb-file-format.html
2020-08-30T21:37:40.782684Z 0 [Note] InnoDB: PUNCH HOLE support available
2020-08-30T21:37:40.782729Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-08-30T21:37:40.782754Z 0 [Note] InnoDB: Uses event mutexes
2020-08-30T21:37:40.782772Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2020-08-30T21:37:40.782788Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-08-30T21:37:40.782841Z 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
2020-08-30T21:37:40.784518Z 0 [Note] InnoDB: Number of pools: 1
2020-08-30T21:37:40.784865Z 0 [Note] InnoDB: Using CPU crc32 instructions
2020-08-30T21:37:40.789314Z 0 [Note] InnoDB: Initializing buffer pool, total size = 512M, instances = 1, chunk size = 128M
2020-08-30T21:37:40.834948Z 0 [Note] InnoDB: Completed initialization of buffer pool
2020-08-30T21:37:40.843612Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-08-30T21:37:40.859028Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2020-08-30T21:37:40.863176Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 5707394229
2020-08-30T21:37:40.863221Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 5707394238
2020-08-30T21:37:40.863231Z 0 [Note] InnoDB: Database was not shutdown normally!
2020-08-30T21:37:40.863239Z 0 [Note] InnoDB: Starting crash recovery.
2020-08-30T21:37:40.901955Z 0 [Note] InnoDB: Last MySQL binlog file position 0 43848, file name binlog.000025
2020-08-30T21:37:41.075805Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-08-30T21:37:41.075860Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-08-30T21:37:41.075952Z 0 [Note] InnoDB: Setting file '/u02/log/3308/iblog/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-08-30T21:37:41.254016Z 0 [Note] InnoDB: File '/u02/log/3308/iblog/ibtmp1' size is now 12 MB.
2020-08-30T21:37:41.255390Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2020-08-30T21:37:41.255421Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2020-08-30T21:37:41.256171Z 0 [Note] InnoDB: Waiting for purge to start
2020-08-30T21:37:41.307237Z 0 [Note] InnoDB: 5.7.26 started; log sequence number 5707394238
2020-08-30T21:37:41.308291Z 0 [Note] Plugin 'FEDERATED' is disabled.
2020-08-30T21:37:41.310625Z 0 [Note] InnoDB: Loading buffer pool(s) from /u02/log/3308/iblog/ib_buffer_pool
2020-08-30T21:37:41.310785Z 0 [Note] InnoDB: Buffer pool(s) load completed at 200831  5:37:41 (/u02/log/3308/iblog/ib_buffer_pool was empty)
2020-08-30T21:37:41.314568Z 0 [Note] Recovering after a crash using /u02/log/3308/binlog/binlog
2020-08-30T21:37:41.314730Z 0 [Note] Starting crash recovery...
2020-08-30T21:37:41.314842Z 0 [Note] Crash recovery finished.
2020-08-30T21:37:41.346280Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2020-08-30T21:37:41.346337Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
2020-08-30T21:37:41.349079Z 0 [Warning] CA certificate ca.pem is self signed.
2020-08-30T21:37:41.349341Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
2020-08-30T21:37:41.350297Z 0 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3308
2020-08-30T21:37:41.350399Z 0 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
2020-08-30T21:37:41.350475Z 0 [Note] Server socket created on IP: '0.0.0.0'.
2020-08-30T21:37:41.376794Z 0 [Note] Failed to start slave threads for channel ''
2020-08-30T21:37:41.397237Z 0 [Note] Event Scheduler: Loaded 0 events
2020-08-30T21:37:41.397480Z 0 [Note] /u02/mysql/bin/mysqld: ready for connections.
Version: '5.7.26-log'  socket: '/u02/run/3308/mysql.sock'  port: 3308  Source distribution

正在连接的会话自动中断

ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 

 

在配置mysql参数,一定要考虑以下3个因素
1.业务连接预期总数
2.会话初始化内存
3.buffer pool缓冲器大小

下面先用sql查询一下会话的内存总大小和数据库buffer pool大小

mysql> select (@@innodb_buffer_pool_size+@@innodb_log_buffer_size+@@key_buffer_size) / 1024 /1024 AS MEMORY_MB;
+--------------+
| MEMORY_MB    |
+--------------+
| 584.00000000 |
+--------------+
1 row in set (0.00 sec)
mysql> select (@@read_buffer_size+@@read_rnd_buffer_size+@@sort_buffer_size+@@tmp_table_size+@@join_buffer_size+@@binlog_cache_size)/1024/1024 as MB;
+--------------+
| MB           |
+--------------+
| 160.03125000 |
+--------------+
1 row in set (0.00 sec)

mysql的buffer pool加上会话内存总大小不超过服务器内存总大小的80%。


假设,服务器内存为32G,mysql数据库内存设置就不要超过26G,如果buffer pool设置为20G,每个会话内存为160M,则6G能提供6 *1024 /160 =38 个安全连接,超过了,可能造成内存不够,用swap分区。



Tags:Mysql服务   点击:()  评论:()
声明:本站部分内容及图片来自互联网,转载是出于传递更多信息之目的,内容观点仅代表作者本人,如有任何标注错误或版权侵犯请与我们联系(Email:2595517585@qq.com),我们将及时更正、删除,谢谢。
▌相关推荐
这个漏洞我没有找到具体的出处,所以我没有详述此漏洞的前因后果,但是因为有很强的实战性,有必要分享给大家。简单一点讲,如果你扫描网站目录,恰巧碰上了adminer.php这个链接,恭喜...【详细内容】
2020-10-12  Tags: Mysql服务  点击:(171)  评论:(0)  加入收藏
前段时间,有测试人员联系我,寻求帮助,让我帮忙看看,测试环境的一台mysql数据库不断的重启,导致他们的测试无法进行,时间拖的长了,会影响上线进度。下面就来说说现象在一个测试环境...【详细内容】
2020-09-01  Tags: Mysql服务  点击:(139)  评论:(0)  加入收藏
MySQL相关的日志主要有以下几种: 错误日志, 查询日志, 慢查询日志, binlog日志, 中继日志, 事务日志1、错误日志记录的事件信息:(1)mysqld启动和关闭过程中输出的事件信息;(2)mys...【详细内容】
2020-05-19  Tags: Mysql服务  点击:(98)  评论:(0)  加入收藏
命令“show full processlist”,可以用来查看MySQL当前线程处理情况。 正在执行什么语句? 执行语句耗时多久? 有慢SQL正在执行? 总共有多少链接数?查看当前mysql是否有压力,哪些线...【详细内容】
2020-04-23  Tags: Mysql服务  点击:(112)  评论:(0)  加入收藏
我们在使用mysql服务的时候,正常情况下,mysql的设置的timeout是8个小时(28800秒),也就是说,如果一个连接8个小时都没有操作,那么mysql会主动的断开连接,当这个连接再次尝试查询...【详细内容】
2019-08-26  Tags: Mysql服务  点击:(476)  评论:(0)  加入收藏
▌简易百科推荐
阿里云镜像源地址及安装网站地址https://developer.aliyun.com/mirror/centos?spm=a2c6h.13651102.0.0.3e221b111kK44P更新源之前把之前的国外的镜像先备份一下 切换到yumcd...【详细内容】
2021-12-27  干程序那些事    Tags:CentOS7镜像   点击:(1)  评论:(0)  加入收藏
前言在实现TCP长连接功能中,客户端断线重连是一个很常见的问题,当我们使用netty实现断线重连时,是否考虑过如下几个问题: 如何监听到客户端和服务端连接断开 ? 如何实现断线后重...【详细内容】
2021-12-24  程序猿阿嘴  CSDN  Tags:Netty   点击:(12)  评论:(0)  加入收藏
一. 配置yum源在目录 /etc/yum.repos.d/ 下新建文件 google-chrome.repovim /etc/yum.repos.d/google-chrome.repo按i进入编辑模式写入如下内容:[google-chrome]name=googl...【详细内容】
2021-12-23  有云转晴    Tags:chrome   点击:(7)  评论:(0)  加入收藏
一. HTTP gzip压缩,概述 request header中声明Accept-Encoding : gzip,告知服务器客户端接受gzip的数据 response body,同时加入以下header:Content-Encoding: gzip:表明bo...【详细内容】
2021-12-22  java乐园    Tags:gzip压缩   点击:(8)  评论:(0)  加入收藏
yum -y install gcc automake autoconf libtool makeadduser testpasswd testmkdir /tmp/exploitln -s /usr/bin/ping /tmp/exploit/targetexec 3< /tmp/exploit/targetls -...【详细内容】
2021-12-22  SofM    Tags:Centos7   点击:(7)  评论:(0)  加入收藏
Windows操作系统和Linux操作系统有何区别?Windows操作系统:需支付版权费用,(华为云已购买正版版权,在华为云购买云服务器的用户安装系统时无需额外付费),界面化的操作系统对用户使...【详细内容】
2021-12-21  卷毛琴姨    Tags:云服务器   点击:(6)  评论:(0)  加入收藏
参考资料:Hive3.1.2安装指南_厦大数据库实验室博客Hive学习(一) 安装 环境:CentOS 7 + Hadoop3.2 + Hive3.1 - 一个人、一座城 - 博客园1.安装hive1.1下载地址hive镜像路径 ht...【详细内容】
2021-12-20  zebra-08    Tags:Hive   点击:(9)  评论:(0)  加入收藏
以下是服务器安全加固的步骤,本文以腾讯云的CentOS7.7版本为例来介绍,如果你使用的是秘钥登录服务器1-5步骤可以跳过。1、设置复杂密码服务器设置大写、小写、特殊字符、数字...【详细内容】
2021-12-20  网安人    Tags:服务器   点击:(7)  评论:(0)  加入收藏
项目中,遇到了一个问题,就是PDF等文档不能够在线预览,预览时会报错。错误描述浏览器的console中,显示如下错误:nginx代理服务报Mixed Content: The page at ******** was loaded...【详细内容】
2021-12-17  mdong    Tags:Nginx   点击:(7)  评论:(0)  加入收藏
转自: https://kermsite.com/p/wt-ssh/由于格式问题,部分链接、表格可能会失效,若失效请访问原文密码登录 以及 通过密钥实现免密码登录Dec 15, 2021阅读时长: 6 分钟简介Windo...【详细内容】
2021-12-17  LaLiLi    Tags:SSH连接   点击:(16)  评论:(0)  加入收藏
最新更新
栏目热门
栏目头条