625某電商網站數據庫宕機故障解決實錄（上）

博客編輯器愈來愈用很差了，夥伴們將就看，須要排版更好的文檔請加Q羣246054962。

625某電商網站數據庫特大故障解決實錄(上)

 

這是一次，驚心動魄的企業級電商網站數據庫在線故障解決實錄，故障解決的過程遇到了不少問題，思想的碰撞，解決方案的決策，及實際操做的問題困擾，老男孩儘可能原汁原味的描述恢復的所有過程及思想思惟過程！老男孩教育版權全部，本內容禁止商業用途。

 

目錄：

625某電商網站數據庫特大故障解決實錄... 1

1接到電商客戶報警... 1

1.1與客戶初步溝通... 1

1.2深刻溝通肯定故障恢復方案... 2

1.3開始故障恢復準備... 4

1.4開始進行故障恢復*****. 6

1.5數據庫故障恢復後掃尾工做... 15

 

1接到電商客戶報警

1.1與客戶初步溝通

昨日接到某電商網站客戶電話，說搞秒殺贈送活動，數據庫遇到問題了，結果啓動起不來了。

[root@etiantian etc]# /etc/init.d/mysqld start
Starting MySQL. ERROR! The server quit without updating PID file (/var/run/mysqld/mysqld.pid).

提示：此部分客戶給的是截圖，是後期老男孩根據SSH日誌整理而來。

因爲時間緊急，本能的提示客戶看看/var/run/mysqld/mysqld.pid存在否，若是存在，刪除再啓動，客戶說沒有這個PID文件，提示用戶用mysqld_safe --user=mysql &啓動看看，結果能夠啓動成功done，可是，端口服務依然起不來。讓客戶查下mysql啓動日誌，報錯以下：

[root@etiantian etc]# cat /var/log/mysqld.log
140624 18:51:58 mysqld_safe Starting mysqld daemon with databases from /data/mysql/
140624 18:51:58 InnoDB: The InnoDB memory heap is disabled
140624 18:51:58 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140624 18:51:58 InnoDB: Compressed tables use zlib 1.2.3
140624 18:51:58 InnoDB: Initializing buffer pool, size = 768.0M
140624 18:51:58 InnoDB: Completed initialization of buffer pool
InnoDB: Error: auto-extending data file ./ibdata1 is of a different size
InnoDB: 2176 pages (rounded down to MB) than specified in the .cnf file:
InnoDB: initial 65536 pages, max 0 (relevant if non-zero) pages!
140624 18:51:58 InnoDB: Could not open or create data files.
140624 18:51:58 InnoDB: If you tried to add new data files, and it failed here,
140624 18:51:58 InnoDB: you should now edit innodb_data_file_path in my.cnf back
140624 18:51:58 InnoDB: to what it was, and remove the new ibdata files InnoDB created
140624 18:51:58 InnoDB: in this failed attempt. InnoDB only wrote those files full of
140624 18:51:58 InnoDB: zeros, but did not yet use them in any way. But be careful: do not
140624 18:51:58 InnoDB: remove old data files which contain your precious data!
140624 18:51:58 [ERROR] Plugin 'InnoDB' init function returned error.
140624 18:51:58 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
140624 18:51:58 [ERROR] Unknown/unsupported storage engine: InnoDB
140624 18:51:58 [ERROR] Aborting
 
140624 18:51:58 [Note] /install/mysql/bin/mysqld: Shutdown complete
 
140624 18:51:58 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

提示：此部分客戶給的是截圖，是後期老男孩根據SSH日誌整理而來。

紅色部分爲錯誤。
InnoDB: Error: auto-extending data file ./ibdata1 is of a different size140624 18:51:58 [ERROR] Plugin 'InnoDB' init function returned error.
140624 18:51:58 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
140624 18:51:58 [ERROR] Unknown/unsupported storage engine: InnoDB
140624 18:51:58 [ERROR] Aborting

根據客戶的信息和自身的經驗基本定位了客戶有可能強制終止了進程或者改變了數據文件！

因而，詢問客戶故障前和故障後，都作了啥操做，獲得的回答以下：

XXXX 18:53:41 
數據庫以前中止響應，killall以前已經沒辦法作restart重啓了
XXXX 18:53:32
我以爲有問題，而後killall掉了，而後就起不來了，別的沒作。
根據日誌以及客戶的描述，基本上判定是強制關閉服務致使innodb表空間或文件異常。
至此問題緣由及故障現象已經肯定。

1.2深刻溝通肯定故障恢復方案

因爲客戶比較着急，人很緊張，且恢復網站提供服務迫在眉睫，老闆就在旁邊緊盯着客戶。。，壓力比較大，所以，客戶要求老男孩項目團隊遠程鏈接介入，代爲操做解決。

和客戶確認了責任和風險後！

當即鏈接服務器，着手進行了一系列的搶救措施，沒有結果。搶救措施有：

1、殺掉服務重啓。2.調整my.cnf相關參數發現某些參數比較大，特別innodb_buffer，調整後依然沒法啓動。3.調整innodby recover參數。

因爲此前就知道客戶是近期剛上線的一個電商網站業務。

所以和客戶溝通。詢問客戶是否有全量備份及增量備份？獲得的回答是客戶作了全量備份了。增量沒作任何處理。

問完了客戶，咱們本身登錄服務器檢查客戶提供的信息看看是否都是正確的。

因爲時間極其緊迫，客戶比較慌張，不少內容本身沒法一下說清楚，和老男孩團隊又不在一個城市。

因而咱們直接登陸服務器，根據常規判斷及歷史記錄（history命令行及/root/.mysql_history文件）找到數據庫的配置文件/etc/my.cnf，進而找到了數據庫安裝路徑/install/mysql，數據文件路徑/data/mysql。binlog的路徑/data/mysql，db備份路徑/home/xx/。

此時急須要肯定的是兩件事：第一個就是binlog是否完整，第二個就是全備是否有效。因而根據客戶描述以及咱們本身登錄服務器查看，結果以下。

第一個binlog數據內容：

[root@etiantianmysql]# ll total118576 -rw-rw----1 mysql mysql 356515840 Jun 24 18:33 ibdata1 -rw-rw----1 mysql mysql  5242880 Jun 24 18:33ib_logfile0 -rw-rw----1 mysql mysql  5242880 Jun 24 18:33ib_logfile1 drwx------2 mysql mysql     4096 Jun 18 16:39 mysql ...... -rw-rw----1 mysql mysql      126 May 21 10:24mysql-bin.000012 -rw-rw---- 1 mysql mysql 1356022 May 21 10:35 mysql-bin.000013 -rw-rw---- 1 mysql mysql 14935771 Jun 18 16:35mysql-bin.000014 -rw-rw---- 1 mysql mysql 56588034 Jun 24 18:33mysql-bin.000015 -rw-rw----1 mysql mysql      285 Jun 18 16:39mysql-bin.index drwx------2 mysql mysql     4096 May 20 21:22performance_schema drwx------2 mysql mysql    20480 May 21 10:28eshop_ett drwx------2 mysql mysql    12288 Jun 18 13:53eshop_ett100 drwx------2 mysql mysql     4096 May 20 21:13 test

根據上述結果，肯定binlog內容是正常的。

開始查看數據庫的全備是否是OK的。

 [root@etiantian backup]# ll /home/xxx/eshop_ett100.0624.sql 
-rw-r--r-- 1 root root 55769500 Jun 24 02:21 /home/xxx/eshop_ett100.0624.sql

結論：全備也是OK的。並且，根據binlog日誌的時間以及全備的時間看，數據是對應的。

實際調查完畢後，和客戶進行溝通恢復方案：

1、若是繼續修復數據文件可能時間會比較長，暫時還沒頭緒。所以，詢問客戶是否是儘快恢復數據庫服務很是重要？獲得的答覆：「是」。

因爲客戶很是着急恢復網站業務（活動廣告早都打出去了），也就是馬上提供服務很是重要，可是做爲一個DBA來說，數據也是一樣重要的。

因而老男孩和客戶緊急溝通，給出了一個解決方案：因爲當時事情緊急，內容簡化，原話以下：

根據大家業務剛上線不久，數據量不是很大，比較好的故障解決方案，就是重建數據庫，而後導入備份及增量！我預計整個恢復時間大約10-30分鐘左右，數據基本能夠作到0損失。也就是說數據不會丟失，最快10分鐘可提供服務。

客戶對這個方案的回覆是：「很滿意」，馬上爽快的答應了咱們的數據庫故障解決方案。原文以下：

xxx 19:10:09
你說的我都贊成
老男孩 19:10:15 
那我開整了

1.3開始故障恢復準備

1、關閉web服務

目的：關閉web的考慮是，防止數據庫啓動後恢復前用戶寫入髒數據。

[root@etiantian data]# ps -ef|grep httpd
root     28697     1  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28699 28697  1 19:15 ?        00:00:02 /install/httpd//bin/httpd -k start
www      28702 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28703 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28704 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28707 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28709 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28711 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28712 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28713 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28714 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28715 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28716 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start
www      28720 28697  0 19:15 ?        00:00:00 /install/httpd//bin/httpd -k start

root     28850 26341  0 19:17 pts/5    00:00:00 grep httpd
[root@etiantian data]# /etc/init.d/httpd stop
[root@etiantian data]# ps -ef|grep httpd
root     28855 26341  0 19:17 pts/5    00:00:00 grep httpd
[root@etiantian data]# ps -ef|grep httpd
root     28857 26341  0 19:17 pts/5    00:00:00 grep httpd
[root@etiantian data]# ps -ef|grep httpd
root     28877 26341  0 19:18 pts/5    00:00:00 grep httpd
[root@etiantian data]# lsof -i :80

2、備份當前正在跑得全部線上數據庫數據

目的：不能對客戶的數據進行二次破壞數據

[root@etiantian mysql]# cd ../
[root@etiantian data]# tar zcvf /server/backup/mysql.tar.gz ./mysql/
[root@etiantian data]# cp -ap mysql /server/backup/
[root@etiantian data]# du -sh /server/backup/*
1230M    /server/backup/mysql
150M     /server/backup/mysql.tar.gz

3、確認全備數據是正常的。手動檢查查看

目的：驗證備份的數據確實是OK的，不然後果不堪設想。

[root@etiantian data]# ll /data/eshop_ett100.0624.sql 
-rw-r--r-- 1 root root 55769500 Jun 24 19:04 /data/eshop_ett100.0624.sql
[root@etiantian data]# less /data/eshop_ett100.0624.sql 
-- MySQL dump 10.13  Distrib 5.5.33, for Linux (x86_64)

4、蒐集db增量日誌

完全殺掉mysql服務

[root@etiantian data]# killall mysqld
mysqld: no process killed
[root@etiantian data]# killall mysqld
mysqld: no process killed
[root@etiantian data]# mv mysql /opt/
[root@etiantian opt]# cd mysql/
[root@etiantian mysql]# ll
total 118576
 -rw-r----- 1 mysql mysql        0 Jun 24 18:53 AY1405201820416899ebZ.err
-rw-rw---- 1 mysql mysql 35651584 Jun 24 18:33 ibdata1
-rw-rw---- 1 mysql mysql  5242880 Jun 24 18:33 ib_logfile0
-rw-rw---- 1 mysql mysql  5242880 Jun 24 18:33 ib_logfile1
drwx------ 2 mysql mysql     4096 Jun 18 16:39 mysql 
......
-rw-rw---- 1 mysql mysql      126 May 21 10:24 mysql-bin.000012
-rw-rw---- 1 mysql mysql  1356022 May 21 10:35 mysql-bin.000013
-rw-rw---- 1 mysql mysql 14935771 Jun 18 16:35 mysql-bin.000014
-rw-rw---- 1 mysql mysql 56588034 Jun 24 18:33 mysql-bin.000015
-rw-rw---- 1 mysql mysql      285 Jun 18 16:39 mysql-bin.index
drwx------ 2 mysql mysql     4096 May 20 21:22 performance_schema
drwx------ 2 mysql mysql    24576 May 21 10:28 eshop_ett
drwx------ 2 mysql mysql    12288 Jun 18 13:53 eshop_ett100
drwx------ 2 mysql mysql     4096 May 20 21:13 test

拷貝增量日誌，防止被二次破壞。等待恢復。

[root@etiantian mysql]# cp mysql-bin.000014  mysql-bin.000015 /server/backup/

至此所有故障修復的所有準備工做完畢。

欲知後事如何，請看下集。