背景
測(cè)試環(huán)境一個(gè)數(shù)據(jù)庫(kù)實(shí)例鹿霸,磁盤滿了導(dǎo)致數(shù)據(jù)庫(kù)出現(xiàn)自動(dòng)重啟
環(huán)境配置
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
錯(cuò)誤日志
[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
疑問(wèn)
1.磁盤滿了mysqld如何處理
2.binlog_error_action這個(gè)參數(shù)作用是什么
3.為什么測(cè)試環(huán)境mysqld實(shí)例出現(xiàn)了重啟而不是等待寫(xiě)入完成
4.如何復(fù)現(xiàn)mysqld磁盤滿了非正常操作導(dǎo)致mysqld異常重啟
5.為什么mysqld_safe重新拉起mysqld會(huì)失敗
6.磁盤滿了應(yīng)該怎么處理
疑問(wèn)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.
疑問(wèn)2分析(binlog_error_action這個(gè)參數(shù)作用是什么)
1.由錯(cuò)誤日志中'binlog_error_action' is set to 'ABORT_SERVER'可知binlog_error_action設(shè)置的值為默認(rèn)值灰羽,即binlog_error_action=ABORT_SERVER
2.binlog_error_action參數(shù)控制flush or synchronize the binary logs失敗后mysqld應(yīng)該觸發(fā)什么動(dòng)作
binlog_error_action=ABORT_SERVER /*暫停記錄binlog并且退出mysqld*/
binlog_error_action= IGNORE_ERROR /*暫停記錄binlog啦撮,繼續(xù)執(zhí)行SQL低散,此時(shí)會(huì)出現(xiàn)主從不一致*/
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();
}
疑問(wèn)3分析(為什么測(cè)試環(huán)境mysqld實(shí)例出現(xiàn)了重啟而不是等待寫(xiě)入完成)
從疑問(wèn)1盾碗、疑問(wèn)2可知mysqld確實(shí)由于磁盤滿導(dǎo)致出現(xiàn)了等待,但是為什么會(huì)寫(xiě)binlog失敗導(dǎo)致重啟有很大可能性是外界因素介入導(dǎo)致本應(yīng)該等磁盤空間釋放后binlog完成寫(xiě)入措嵌,但是寫(xiě)入失敗了進(jìn)而導(dǎo)致mysqld重啟
疑問(wèn)4分析(如何復(fù)現(xiàn)mysqld磁盤滿了非正常操作導(dǎo)致mysqld異常重啟)
1.sysbench壓測(cè)打滿磁盤
[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.錯(cuò)誤日志
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
疑問(wèn)5分析(為什么mysqld_safe重新拉起mysqld會(huì)失敗)
日志: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.
原因:初始化臨時(shí)表共享表空間失敗骏令,ibtmp1初始化默認(rèn)為12M,如果服務(wù)器運(yùn)行期間這個(gè)擴(kuò)展超出12M厉亏,那么下次重新啟動(dòng)的時(shí)候會(huì)先移除這個(gè)文件然后初始化董习,這樣就可以重啟成功,但是服務(wù)器運(yùn)行期間ibtmp1一直沒(méi)有超出12M爱只,則下次重啟初始化刪除再創(chuàng)建磁盤仍然不夠就會(huì)導(dǎo)致重啟失敗
疑問(wèn)6分析(磁盤滿了應(yīng)該怎么處理)
1.不要kill
2.不要ctrl +c
3.不要purge binlog
4.刪除服務(wù)器無(wú)用文件皿淋,釋放空間后讓mysqld自己恢復(fù)