mysqld如何处理磁盘打满情况

背景

测试环境一个数据库实例,磁盘满了导致数据库出现自动重启

环境配置

mysql_version:oracle mysql-5.7.17
expire_logs_days = 5
max_binlog_size = 1G
log_bin=xxxxx  
sync_binlog = 1000
binlog_error_action = ABORT_SERVER

错误日志

[root@wth 3306]# tail -f log/mysql-error.log
2020-07-11T17:35:15.212102+08:00 0 [Warning] 'proxies_priv' entry '@ root@wth' ignored in --skip-name-resolve mode.
2020-07-11T17:35:15.213660+08:00 0 [Note] InnoDB: Buffer pool(s) load completed at 200711 17:35:15
2020-07-11T17:35:15.279123+08:00 0 [Note] Event Scheduler: Loaded 0 events
2020-07-11T17:35:15.279318+08:00 0 [Note] /home/q/mysql/multi/3306/mysql57/bin/mysqld: ready for connections.
Version: '5.7.29-log'  socket: '/home/q/mysql/multi/3306/socket/mysql.sock'  port: 3306  MySQL Server (GPL)
2020-07-11T17:36:02.147455+08:00 4 [Note] Aborted connection 4 to db: 'unconnected' user: 'dba_agent' host: '127.0.0.1' (Got an error reading communication packets)
2020-07-11T17:37:01.346521+08:00 9 [Note] Aborted connection 9 to db: 'unconnected' user: 'dba_agent' host: '127.0.0.1' (Got an error reading communication packets)
2020-07-11T17:38:01.527849+08:00 14 [Note] Aborted connection 14 to db: 'unconnected' user: 'dba_agent' host: '127.0.0.1' (Got an error reading communication packets)
2020-07-11T17:38:46.758778+08:00 20 [ERROR] Disk is full writing '/home/q/mysql/multi/3306/binlog/mysql-bin.000013' (Errcode: 15421776 - No space left on device). Waiting for someone to free space...
2020-07-11T17:38:46.758800+08:00 20 [ERROR] Retry in 60 secs. Message reprinted in 600 secs
2020-07-11T17:39:46.758997+08:00 20 [ERROR] /home/q/mysql/multi/3306/mysql57/bin/mysqld: Binary logging not possible. Message: An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'ABORT_SERVER'. Hence aborting the server.
09:39:46 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=134217728
read_buffer_size=1048576
max_used_connections=8
max_threads=2000
thread_count=7
connection_count=7
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4253837 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f680c012550
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f682c491d40 thread_stack 0x40000
/home/q/mysql/multi/3306/mysql57/bin/mysqld(my_print_stacktrace+0x2c)[0xeb657c]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(handle_fatal_signal+0x451)[0x79b7e1]
/lib64/libpthread.so.0(+0xf630)[0x7f6853dd1630]
/lib64/libc.so.6(gsignal+0x37)[0x7f68520db387]
/lib64/libc.so.6(abort+0x148)[0x7f68520dca78]
/home/q/mysql/multi/3306/mysql57/bin/mysqld[0xe430c1]
/home/q/mysql/multi/3306/mysql57/bin/mysqld[0xe4be31]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_ZN13MYSQL_BIN_LOG14ordered_commitEP3THDbb+0x2ae)[0xe5345e]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_ZN13MYSQL_BIN_LOG6commitEP3THDb+0x7e3)[0xe56be3]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_Z15ha_commit_transP3THDbb+0x21e)[0x7ebc9e]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_Z12trans_commitP3THD+0x39)[0xd32859]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x605)[0xc8aa05]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_ZN18Prepared_statement7executeEP6Stringb+0x337)[0xcb7857]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_ZN18Prepared_statement12execute_loopEP6StringbPhS2_+0xca)[0xcba7ba]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_Z19mysqld_stmt_executeP3THDmmPhm+0xe4)[0xcbaa94]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x19e5)[0xc926e5]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_Z10do_commandP3THD+0x177)[0xc930b7]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(handle_connection+0x278)[0xd4fbf8]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(pfs_spawn_thread+0x1b4)[0xecce14]
/lib64/libpthread.so.0(+0x7ea5)[0x7f6853dc9ea5]
/lib64/libc.so.6(clone+0x6d)[0x7f68521a38dd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f680c001390): is an invalid pointer
Connection ID (thread ID): 20
Status: KILL_CONNECTION

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
2020-07-11T17:39:47.096102+08:00 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consid2020-07-11T17:39:47.549560+08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-07-11T17:39:47.549601+08:00 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-07-11T17:39:47.549632+08:00 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-07-11T17:39:47.550678+08:00 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions
2020-07-11T17:39:47.550700+08:00 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2020-07-11T17:39:47.689532+08:00 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2020-07-11T17:39:47.689587+08:00 0 [ERROR] InnoDB: Write to file ./ibtmp1failed at offset 11534336, 1048576 bytes should have been written, only 0 were written. Operating system error number 28. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2020-07-11T17:39:47.689618+08:00 0 [ERROR] InnoDB: Error number 28 means 'No space left on device'
2020-07-11T17:39:47.689626+08:00 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2020-07-11T17:39:47.689634+08:00 0 [ERROR] InnoDB: Could not set the file size of './ibtmp1'. Probably out of disk space
2020-07-11T17:39:47.689640+08:00 0 [ERROR] InnoDB: Unable to create the shared innodb_temporary
2020-07-11T17:39:47.689646+08:00 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2020-07-11T17:39:48.290240+08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-07-11T17:39:48.290278+08:00 0 [ERROR] Plugin 'InnoDB' init function returned error.
2020-07-11T17:39:48.290285+08:00 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2020-07-11T17:39:48.290291+08:00 0 [ERROR] Failed to initialize builtin plugins.
2020-07-11T17:39:48.290297+08:00 0 [ERROR] Aborting

2020-07-11T17:39:48.290307+08:00 0 [Note] Binlog end
2020-07-11T17:39:48.290387+08:00 0 [Note] Shutting down plugin 'MyISAM'
2020-07-11T17:39:48.293633+08:00 0 [Note] /home/q/mysql/multi/3306/mysql57/bin/mysqld: Shutdown complete

疑问

1.磁盘满了mysqld如何处理
2.binlog_error_action这个参数作用是什么
3.为什么测试环境mysqld实例出现了重启而不是等待写入完成
4.如何复现mysqld磁盘满了非正常操作导致mysqld异常重启
5.为什么mysqld_safe重新拉起mysqld会失败
6.磁盘满了应该怎么处理

疑问1分析(磁盘满了mysqld如何处理)

官方解释:
When a disk-full condition occurs, MySQL does the following:
    1)It checks once every minute to see whether there is enough space to write the current row. If there is enough space, it continues as if nothing had happened.
    2)Every 10 minutes it writes an entry to the log file, warning about the disk-full condition.

疑问2分析(binlog_error_action这个参数作用是什么)

1.由错误日志中'binlog_error_action' is set to 'ABORT_SERVER'可知binlog_error_action设置的值为默认值,即binlog_error_action=ABORT_SERVER
2.binlog_error_action参数控制flush or synchronize the binary logs失败后mysqld应该触发什么动作
    binlog_error_action=ABORT_SERVER    /*暂停记录binlog并且退出mysqld*/
    binlog_error_action= IGNORE_ERROR   /*暂停记录binlog,继续执行SQL,此时会出现主从不一致*/
3.源码逻辑
void MYSQL_BIN_LOG::handle_binlog_flush_or_sync_error(THD *thd,bool need_lock_log)
{
  char errmsg[MYSQL_ERRMSG_SIZE];
  sprintf(errmsg, "An error occurred during %s stage of the commit. "
          "'binlog_error_action' is set to '%s'.",
          thd->commit_error== THD::CE_FLUSH_ERROR ? "flush" : "sync",
          binlog_error_action == ABORT_SERVER ? "ABORT_SERVER" : "IGNORE_ERROR");
  if (binlog_error_action == ABORT_SERVER)
  {
    char err_buff[MYSQL_ERRMSG_SIZE];
    sprintf(err_buff, "%s Hence aborting the server.", errmsg);
    exec_binlog_error_action_abort(err_buff);
  }
  else
  {
    DEBUG_SYNC(thd, "before_binlog_closed_due_to_error");
    if (need_lock_log)
      mysql_mutex_lock(&LOCK_log);
    else
      mysql_mutex_assert_owner(&LOCK_log);
    if (is_open())
    {
      sql_print_error("%s Hence turning logging off for the whole duration "
                      "of the MySQL server process. To turn it on again: fix "
                      "the cause, shutdown the MySQL server and restart it.",
                      errmsg);
    }
    close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT);
    if (need_lock_log)
      mysql_mutex_unlock(&LOCK_log);
    DEBUG_SYNC(thd, "after_binlog_closed_due_to_error");
  }
}

static void exec_binlog_error_action_abort(const char* err_string)
{
  THD *thd= current_thd;
  thd->clear_error();
  my_error(ER_BINLOG_LOGGING_IMPOSSIBLE, MYF(ME_ERRORLOG + ME_FATALERROR),err_string);
  thd->send_statement_status();
  abort();
}

疑问3分析(为什么测试环境mysqld实例出现了重启而不是等待写入完成)

从疑问1、疑问2可知mysqld确实由于磁盘满导致出现了等待,但是为什么会写binlog失败导致重启有很大可能性是外界因素介入导致本应该等磁盘空间释放后binlog完成写入,但是写入失败了进而导致mysqld重启

疑问4分析(如何复现mysqld磁盘满了非正常操作导致mysqld异常重启)

1.sysbench压测打满磁盘
[root@wth log]# df -hT
Filesystem     Type      Size  Used Avail Use% Mounted on
devtmpfs       devtmpfs  911M     0  911M   0% /dev
tmpfs          tmpfs     920M     0  920M   0% /dev/shm
tmpfs          tmpfs     920M  848K  919M   1% /run
tmpfs          tmpfs     920M     0  920M   0% /sys/fs/cgroup
/dev/vda1      ext4       40G   38G     0 100% /
tmpfs          tmpfs     184M     0  184M   0% /run/user/0
2.观察processlist
mysql> show full processlist\G
*************************** 1. row ***************************
     Id: 2
   User: root
   Host: 127.0.0.1:56270
     db: test
Command: Execute
   Time: 68
  State: starting
   Info: COMMIT
*************************** 2. row ***************************
     Id: 3
   User: root
   Host: 127.0.0.1:56272
     db: test
Command: Execute
   Time: 68
  State: starting
   Info: COMMIT
*************************** 6. row ***************************
     Id: 110
   User: wthong
   Host: 39.97.247.142:54382
     db: devops
Command: Query
   Time: 8
  State: starting
   Info: COMMIT
*************************** 7. row ***************************
     Id: 111
   User: root
   Host: 127.0.0.1:56514
     db: NULL
Command: Query
   Time: 7
  State: starting
   Info: COMMIT

mysql> kill 111;
mysql> kill 110;
mysql> kill 3;


3.错误日志
2020-07-11T20:32:01.990029+08:00 2 [ERROR] Disk is full writing '/home/q/mysql/multi/3306/binlog/mysql-bin.000015' (Errcode: 15421776 - No space left on device). Waiting for someone to free space...
2020-07-11T20:32:01.990050+08:00 2 [ERROR] Retry in 60 secs. Message reprinted in 600 secs
2020-07-11T20:34:52.738433+08:00 115 [Note] Aborted connection 115 to db: 'unconnected' user: 'dba_agent' host: '127.0.0.1' (Got an error reading communication packets)
2020-07-11T20:35:49.528874+08:00 109 [Note] Aborted connection 109 to db: 'unconnected' user: 'dba_agent' host: '127.0.0.1' (Got an error reading communication packets)
2020-07-11T20:35:52.921423+08:00 120 [Note] Aborted connection 120 to db: 'unconnected' user: 'dba_agent' host: '127.0.0.1' (Got an error reading communication packets)
2020-07-11T20:36:01.994510+08:00 2 [ERROR] /home/q/mysql/multi/3306/mysql57/bin/mysqld: Binary logging not possible. Message: An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'ABORT_SERVER'. Hence aborting the server.
12:36:01 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=134217728
read_buffer_size=1048576
max_used_connections=13
max_threads=2000
thread_count=7
connection_count=7
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4253837 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f5da8000b30
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f5dcc08cd40 thread_stack 0x40000
/home/q/mysql/multi/3306/mysql57/bin/mysqld(my_print_stacktrace+0x2c)[0xeb657c]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(handle_fatal_signal+0x451)[0x79b7e1]
/lib64/libpthread.so.0(+0xf630)[0x7f5df3eca630]
/lib64/libc.so.6(gsignal+0x37)[0x7f5df21d4387]
/lib64/libc.so.6(abort+0x148)[0x7f5df21d5a78]
/home/q/mysql/multi/3306/mysql57/bin/mysqld[0xe430c1]
/home/q/mysql/multi/3306/mysql57/bin/mysqld[0xe4be31]
/home/q/mysql/multi/3306/mysql57/bin/mysqld(_ZN13MYSQL_BIN_LOG14ordered_commitE2020-07-11T12:36:02.274954Z mysqld_safe Number of processes running now: 0
2020-07-11T12:36:02.278686Z mysqld_safe mysqld restarted
2020-07-11T20:36:02.933967+08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-07-11T20:36:02.934008+08:00 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-07-11T20:36:02.934040+08:00 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-07-11T20:36:02.935054+08:00 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions
2020-07-11T20:36:02.935076+08:00 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2020-07-11T20:36:03.068437+08:00 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2020-07-11T20:36:03.068497+08:00 0 [ERROR] InnoDB: Write to file ./ibtmp1failed at offset 11534336, 1048576 bytes should have been written, only 0 were written. Operating system error number 28. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2020-07-11T20:36:03.068521+08:00 0 [ERROR] InnoDB: Error number 28 means 'No space left on device'
2020-07-11T20:36:03.068527+08:00 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2020-07-11T20:36:03.068536+08:00 0 [ERROR] InnoDB: Could not set the file size of './ibtmp1'. Probably out of disk space
2020-07-11T20:36:03.068542+08:00 0 [ERROR] InnoDB: Unable to create the shared innodb_temporary
2020-07-11T20:36:03.068549+08:00 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2020-07-11T20:36:03.669171+08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-07-11T20:36:03.669210+08:00 0 [ERROR] Plugin 'InnoDB' init function returned error.
2020-07-11T20:36:03.669217+08:00 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2020-07-11T20:36:03.669223+08:00 0 [ERROR] Failed to initialize builtin plugins.
2020-07-11T20:36:03.669229+08:00 0 [ERROR] Aborting

2020-07-11T20:36:03.669248+08:00 0 [Note] Binlog end
2020-07-11T20:36:03.669304+08:00 0 [Note] Shutting down plugin 'MyISAM'
2020-07-11T20:36:03.672700+08:00 0 [Note] /home/q/mysql/multi/3306/mysql57/bin/mysqld: Shutdown complete

2020-07-11T12:36:03.751950Z mysqld_safe mysqld from pid file /home/q/mysql/multi/3306/pid/mysql.pid ended

疑问5分析(为什么mysqld_safe重新拉起mysqld会失败)

日志:2020-07-11T20:36:03.068497+08:00 0 [ERROR] InnoDB: Write to file ./ibtmp1failed at offset 11534336, 1048576 bytes should have been written, only 0 were written. Operating system error number 28. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
原因:初始化临时表共享表空间失败,ibtmp1初始化默认为12M,如果服务器运行期间这个扩展超出12M,那么下次重新启动的时候会先移除这个文件然后初始化,这样就可以重启成功,但是服务器运行期间ibtmp1一直没有超出12M,则下次重启初始化删除再创建磁盘仍然不够就会导致重启失败

疑问6分析(磁盘满了应该怎么处理)

1.不要kill
2.不要ctrl +c
3.不要purge binlog
4.删除服务器无用文件,释放空间后让mysqld自己恢复
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,884评论 6 492
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,755评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 158,369评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,799评论 1 285
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,910评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,096评论 1 291
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,159评论 3 411
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,917评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,360评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,673评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,814评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,509评论 4 334
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,156评论 3 317
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,882评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,123评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,641评论 2 362
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,728评论 2 351