从昨天起,我注意到我的机器出现了奇怪的行为。我有一个备份脚本来备份 sql 和文件。我注意到存档文件小了很多,而且损坏了。
我分析了日志,看起来 SQL 在备份期间正在重新启动,请看这里:
从晚上开始:
Dec 26 01:37:13 mysite.net mysqld_safe[393]: /usr/bin/mysqld_safe: line 182: 6468 Killed nohup /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/my
Dec 26 01:37:13 mysite.net mysqld_safe[393]: adb/mariadb.log 2>&1 >> /var/log/mariadb/mariadb.log 2>&1 >> /var/log/mariadb/mariadb.log 2>&1 >> /var/log/mariadb/mariadb.log 2>&1 >> /var/log/mariadb/ma
Dec 26 01:37:13 mysite.net mysqld_safe[393]: 151226 01:37:13 mysqld_safe Number of processes running now: 0
Dec 26 01:37:13 mysite.net mysqld_safe[393]: 151226 01:37:13 mysqld_safe mysqld restarted
Dec 26 01:37:13 mysite.net filesystem-monitor[12918]: Removed /var/www/pathtomysite/wp-snapshots/20151201_mysiteom_565da0c74c11b8955151201132943_installer.p
Dec 26 01:37:13 mysite.net postfix/smtpd[8786]: connect from unknown[127.0.0.1]
Dec 26 01:37:13 mysite.net postfix/proxymap[8787]: warning: connect to mysql server 127.0.0.1: Can't connect to MySQL server on '127.0.0.1' (111)
Dec 26 01:37:13 mysite.net postfix/trivial-rewrite[8790]: warning: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf: table lookup problem
Dec 26 01:37:13 mysite.net postfix/trivial-rewrite[8790]: warning: virtual_mailbox_domains lookup failure
Dec 26 01:37:13 mysite.net postfix/trivial-rewrite[8790]: warning: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf: table lookup problem
Dec 26 01:37:13 mysite.net postfix/trivial-rewrite[8790]: warning: virtual_mailbox_domains lookup failure
Dec 26 01:37:13 mysite.net postfix/smtpd[8786]: NOQUEUE: reject: RCPT from unknown[127.0.0.1]: 451 4.3.0 <[email protected]>: Temporary lookup failure; from=<[email protected]> to=<info@onesite
这是今天早上的情况:
Dec 26 06:00:06 mysite.net CROND[13626]: (root) CMD (python /root/script.py sql)
Dec 26 06:00:09 mysite.net backup[13626]: Started database backup, dumping sql to /tmp/mysql-20151226-0600.sql...
Dec 26 06:01:01 mysite.net systemd[1]: Starting Session c1371 of user root.
Dec 26 06:01:01 mysite.net systemd[1]: Started Session c1371 of user root.
Dec 26 06:01:01 mysite.net CROND[13635]: (root) CMD (run-parts /etc/cron.hourly)
Dec 26 06:01:02 mysite.net run-parts(/etc/cron.hourly)[13638]: starting 0anacron
Dec 26 06:01:03 mysite.net run-parts(/etc/cron.hourly)[13644]: finished 0anacron
Dec 26 06:01:03 mysite.net run-parts(/etc/cron.hourly)[13646]: starting awstats
Dec 26 06:01:31 mysite.net backup[13626]: Compressing database into /tmp/mysql-20151226-0600.7z...
Dec 26 06:01:31 mysite.net mysqld_safe[393]: /usr/bin/mysqld_safe: line 182: 11959 Killed nohup /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/my
Dec 26 06:01:31 mysite.net mysqld_safe[393]: adb/mariadb.log 2>&1 >> /var/log/mariadb/mariadb.log 2>&1 >> /var/log/mariadb/mariadb.log 2>&1 >> /var/log/mariadb/mariadb.log 2>&1 >> /var/log/mariadb/ma
Dec 26 06:01:32 mysite.net mysqld_safe[393]: 151226 06:01:32 mysqld_safe Number of processes running now: 0
Dec 26 06:01:32 mysite.net mysqld_safe[393]: 151226 06:01:32 mysqld_safe mysqld restarted
Dec 26 06:01:36 mysite.net backup[13626]: Compressed file size: 1835040 bytes
Dec 26 06:01:36 mysite.net backup[13626]: Connecting to FTP server backupserver.net...
这里我从 mysql 日志中摘录了一段内容:
151226 4:17:08 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
151226 4:17:08 InnoDB: Waiting for the background threads to start
151226 4:17:09 Percona XtraDB (http://www.percona.com) 5.5.40-MariaDB-36.1 started; log sequence number 8011823935
151226 4:17:09 [Note] Plugin 'FEEDBACK' is disabled.
151226 4:17:09 [Note] Server socket created on IP: '0.0.0.0'.
151226 4:17:09 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TA
BLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANS
I','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USE
R','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SU
BTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES'
,'STRICT_TRANS_TABLES','STRICT_A
151226 4:17:09 [ERROR] Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
151226 4:17:09 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.41-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
151226 4:17:09 [ERROR] mysqld: Table './mysite/dbprefix_options' is marked as crashed and should be repaired
151226 4:17:09 [Warning] Checking table: './mysite/dbprefix_options'
151226 4:17:10 [ERROR] mysqld: Table './site2/wpprfx_options' is marked as crashed and should be repaired
151226 4:17:10 [Warning] Checking table: './site2/wpprfx_options'
151226 4:17:11 [ERROR] mysqld: Table './mysite/dbprefix_visitor_maps_wo' is marked as crashed and should be repaired
151226 4:17:11 [Warning] Checking table: './mysite/dbprefix_visitor_maps_wo'
151226 4:17:11 [ERROR] mysqld: Table './mysite/dbprefix_usermeta' is marked as crashed and should be repaired
151226 4:17:11 [Warning] Checking table: './mysite/dbprefix_usermeta'
151226 4:17:19 [ERROR] mysqld: Table './site2/wpprfx_visitor_maps_wo' is marked as crashed and should be repaired
151226 4:17:19 [Warning] Checking table: './site2/wpprfx_visitor_maps_wo'
151226 4:17:19 [ERROR] mysqld: Table './site2/wpprfx_visitor_maps_st' is marked as crashed and should be repaired
151226 4:17:19 [Warning] Checking table: './site2/wpprfx_visitor_maps_st'
151226 4:17:19 [ERROR] mysqld: Table './site2/wpprfx_comments' is marked as crashed and should be repaired
151226 4:17:19 [Warning] Checking table: './site2/wpprfx_comments'
151226 4:20:14 [ERROR] mysqld: Table './mysite/dbprefix_comments' is marked as crashed and should be repaired
151226 4:20:14 [Warning] Checking table: './mysite/dbprefix_comments'
151226 4:22:20 [ERROR] mysqld: Table './site3/wp_options' is marked as crashed and should be repaired
151226 4:22:20 [Warning] Checking table: './site3/wp_options'
151226 4:22:21 [Warning] Checking table: './site3/wp_visitor_maps_wo'
151226 4:22:21 [ERROR] mysqld: Table './site3/wp_visitor_maps_st' is marked as crashed and should be repaired
151226 4:22:21 [Warning] Checking table: './site3/wp_visitor_maps_st'
151226 4:38:05 [ERROR] mysqld: Table './site4/wp_options' is marked as crashed and should be repaired
151226 4:38:05 [Warning] Checking table: './site4/wp_options'
151226 4:38:06 [ERROR] mysqld: Table './site4/wp_visitor_maps_wo' is marked as crashed and should be repaired
151226 4:38:06 [Warning] Checking table: './site4/wp_visitor_maps_wo'
151226 4:38:06 [ERROR] mysqld: Table './site4/wp_visitor_maps_st' is marked as crashed and should be repaired
151226 4:38:06 [Warning] Checking table: './site4/wp_visitor_maps_st'
151226 5:22:25 [ERROR] mysqld: Table './mysite/dbprefix_commentmeta' is marked as crashed and should be repaired
151226 5:22:25 [Warning] Checking table: './mysite/dbprefix_commentmeta'
151226 6:00:31 [ERROR] mysqld: Table './mysite/dbprefix_visitor_maps_ge' is marked as crashed and should be repaired
151226 6:00:31 [Warning] Checking table: './mysite/dbprefix_visitor_maps_ge'
151226 6:01:06 [ERROR] mysqld: Table './site5/short_stats' is marked as crashed and should be repaired
151226 6:01:06 [Warning] Checking table: './site5/short_stats'
151226 6:01:12 [ERROR] mysqld: Table './proftpd/users' is marked as crashed and should be repaired
151226 6:01:12 [Warning] Checking table: './proftpd/users'
151226 6:01:17 [ERROR] mysqld: Table './site2/wpprfx_commentmeta' is marked as crashed and should be repaired
151226 6:01:17 [Warning] Checking table: './site2/wpprfx_commentmeta'
151226 06:01:32 mysqld_safe Number of processes running now: 0
151226 06:01:32 mysqld_safe mysqld restarted
151226 6:01:32 InnoDB: The InnoDB memory heap is disabled
151226 6:01:32 InnoDB: Mutexes and rw_locks use GCC atomic builtins
151226 6:01:32 InnoDB: Compressed tables use zlib 1.2.7
151226 6:01:32 InnoDB: Using Linux native AIO
151226 6:01:32 InnoDB: Initializing buffer pool, size = 128.0M
151226 6:01:32 InnoDB: Completed initialization of buffer pool
151226 6:01:32 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
151226 6:01:32 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
151226 6:01:33 InnoDB: Waiting for the background threads to start
151226 6:01:34 Percona XtraDB (http://www.percona.com) 5.5.40-MariaDB-36.1 started; log sequence number 8012470316
151226 6:01:35 [Note] Plugin 'FEEDBACK' is disabled.
151226 6:01:35 [Note] Server socket created on IP: '0.0.0.0'.
151226 6:01:36 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USER','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_A
151226 6:01:36 [ERROR] Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
151226 6:01:36 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.41-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
151226 6:01:46 [ERROR] mysqld: Table './mysite/dbprefix_options' is marked as crashed and should be repaired
151226 6:01:46 [Warning] Checking table: './mysite/dbprefix_options'
151226 6:01:48 [ERROR] mysqld: Table './mysite/dbprefix_visitor_maps_wo' is marked as crashed and should be repaired
151226 6:01:48 [Warning] Checking table: './mysite/dbprefix_visitor_maps_wo'
151226 6:02:07 [ERROR] mysqld: Table './mysite/dbprefix_comments' is marked as crashed and should be repaired
151226 6:02:07 [Warning] Checking table: './mysite/dbprefix_comments'
这是配置文件:
cat /etc/my.cnf
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
# Settings user and group are ignored when systemd is used.
# If you need to run mysqld under a different user or group,
# customize your systemd unit file for mariadb according to the
# instructions in http://fedoraproject.org/wiki/Systemd
[mysqld_safe]
log-error=/var/log/mariadb/mariadb.log
pid-file=/var/run/mariadb/mariadb.pid
#
# include all files from the config directory
#
!includedir /etc/my.cnf.d
有人遇到过这种情况吗? 造成这种情况的根本原因是什么以及如何解决?
我找到了一个解决方法 - 我运行shutdown -r
它并用 sql 重新启动。现在一切似乎都运行正常。但是我想知道为什么 mysqld_safe 无法正常工作。如何分析?
重启后的内存:
total used free shared buffers cached
Mem: 3072 2971 100 148 0 1827
-/+ buffers/cache: 1144 1927
Swap: 512 59 452