暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

MySQL备份失败,一波三折的问题分析和处理

一森咖记 2020-02-14
530

今天和同事一起处理了一个奇怪的MySQL空间异常问题,从这个问题的处理中可以找到一些问题处理的方式。


问题的背景是有一个实例的备份总是失败,在排查了多次之后,在保证Slave可用的情况先搁置了,刚好借着这几天的时间做了下收尾和梳理。

备份失败的报错提示信息是:

    innobackupex: Error writing file '/tmp/xbtempevLQbf' (Errcode: 28 - No space left on device)
    xtrabackup: Error: write to logfile failed
    xtrabackup: Error: xtrabackup_copy_logfile() failed.

    看起来多直白的问题,空间不足嘛,是不是空间配置的问题。

    但是在本地进行模拟测试的时候,使用了如下的脚本开启本机测试。

      /usr/local/mysql_tools/percona-xtrabackup-2.4.8-Linux-x86_64/bin/innobackupex --defaults-file=/data/mysql_4308/my.cnf --user=xxxx --password=xxxx --socket=/data/mysql_4308/tmp/mysql.sock  --stream=tar data/xxxx/mysql/xxxx_4308/2020-02-11   > /data/xxxx/mysql/xxxx_4308/2020-02-11.tar.gz

      发现所在的/tmp目录却没有空间异常的情况,而相反是根目录的空间使用出现了异常,这是测试中截取到的一个空间异常的截图。

      而在抛出异常之后,备份失败,空间使用率马上恢复。

      综合目前得到的信息,我的直观感觉是问题貌似和/tmp没有太直接的联系,那一定是在根目录的使用过程中的其他目录产生了异常。

      于是我开始了第二次测试,这一次我着重关注根目录的整体使用,看看到底是哪个目录的使用异常了,但是尴尬的是,尽管做了脚本的快速采集,竟然没有发现在我们常见的目录下有空间异常。

        332K    ./home
        411M ./lib
        26M ./lib64
        16K ./lost+found
        4.0K ./media
        4.0K ./misc
        4.0K ./mnt
        0 ./net
        184M ./opt
        du: cannot access `./proc/40102/task/40102/fd/4': No such file or directory
        du: cannot access `./proc/40102/task/40102/fdinfo/4': No such file or directory
        du: cannot access `./proc/40102/fd/4': No such file or directory
        du: cannot access `./proc/40102/fdinfo/4': No such file or directory
        0 ./proc
        2.3G ./root
        56K     ./tmp
        。。。

        所以从目前的情况来看,应该是/proc相关的目录下的空间异常了。

        事情到了这个时候,似乎可用的方式已经不多了。

        我排查了脚本,排查了参数文件,整体来看没有和其他环境相比明显的问题,但是有一个细节引起了我的注意,那就是使用top的时候,看到这个实例的内存使用了6G(服务器内存是8G),但是buffer pool的配置才是3G左右,这是一个从库环境,也没有应用连接,所以也不大可能存在太多的连接资源消耗,所以综合来看,应该是和服务器的内存异常有关。

        这个时候尝试了在线resize,发现已经没有收缩的空间了。因为是从库服务,于是我开始重启从库的服务。

        但是意外的是重启数据库的时候卡住了,大概过了有2分钟,只是看到一些输出的小数点,大概输出了两行,还是没有反应,查看后台日志没有任何输出,于是我开始尝试plan B,准备Kill 进程重启服务。

        这一次kill操作生效了,过一会服务启动起来了。但是报出了从库复制异常。

                          Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.'
          。。。
          Master_Server_Id: 190
          Master_UUID: 570dcd0e-f6d0-11e8-adc3-005056b7e95f
          。。。
          Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
          Master_Retry_Count: 86400
          Master_Bind:
                Last_IO_Error_Timestamp: 200211 14:20:57
          Retrieved_Gtid_Set: 570dcd0e-f6d0-11e8-adc3-005056b7e95f:821211986-2157277214
          Executed_Gtid_Set: 570dcd0e-f6d0-11e8-adc3-005056b7e95f:1-820070317:821211986-2157277214

          这个错误的信息是比较明显了,是主库的binlog被purge掉了,导致在从库去复制应用的时候失败了。

          为什么会有这么奇怪的一个问题呢,因为主库的binlog默认还是保留了一些天数,不至于把1个小时前的binlog删除。

          关于GTID的一些变量值如下:

          Retrieved_Gtid_Set: 570dcd0e-f6d0-11e8-adc3-005056b7e95f:821211986-2157277214

          Executed_Gtid_Set: 570dcd0e-f6d0-11e8-adc3-005056b7e95f:1-820070317:821211986-2157277214

          gtid_purged     : 570dcd0e-f6d0-11e8-adc3-005056b7e95f:1-820070317:821211986-2131381624

          Master端的GTID_Purged为:

          gtid_purged      :570dcd0e-f6d0-11e8-adc3-005056b7e95f:1-2089314252

          综合这些信息来看,Slave端的GTID和主库没有完整的衔接起来,也就意味着在之前对这个Slave做过一些操作,导致GTID在Master和Slave端产生了一些偏差。

          而这个遗漏的变更部分570dcd0e-f6d0-11e8-adc3-005056b7e95f:821211986保守来估计也是1个月以前了,binlog是肯定没有保留的。

          我们在此先暂时修复这个复制问题。

          停止Slave没想到又出问题了,一个看似简单的stop Slave操作竟然持续了1分多钟。

          >>stop slave;

          Query OK, 0 rows affected (1 min 1.99 sec)

          尝试减小Buffer pool配置,重启,stop slave,这个操作依然很慢,所以可以在这个方向上排除延迟的问题和Buffer Pool关系不大,而相对和GTID的关系更大一些。

          Slave端修复步骤如下:

            reset master;
            stop slave;
            reset slave all;
            SET @@GLOBAL.GTID_PURGED='570dcd0e-f6d0-11e8-adc3-005056b7e95f:1-2157277214';
            CHANGE MASTER TO MASTER_USER='dba_repl', MASTER_PASSWORD='xxxx' , MASTER_HOST='xxxxx',MASTER_PORT=4308,MASTER_AUTO_POSITION = 1;

            其中GTID_PURGED的配置是关键。 

            修复后,Slave端的延迟问题就解决了,而再次尝试重新备份,在根目录竟然没有了空间消耗。 


            小结:

            这个过程中主要是要快速解决问题,有些步骤的日志抓取的不够丰富和细致,从问题的分析来说,还是缺少了一些更有说服力的东西,对于问题的原因,本质上还是不合理的问题(比如bug或者配置异常等)导致了不合理的现象。

            在这一块还是可以借鉴的是分析的整体思路,而不是这个问题本身。 

            转文至此。

            转文至此。

             


            以下为个人公众号“一森咖记”,欢迎关注。
                                   

               

            近期热文

            你可能也会对以下话题感兴趣。点击链接便可查看。

            最后修改时间:2020-02-15 13:51:33
            文章转载自一森咖记,如果涉嫌侵权,请发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

            评论