今天就跟大家聊聊有關MySQL中一條SQL使磁盤暴漲并導致MySQL Crash該怎么辦，可能很多人都不太了解，為了讓大家更加了解，小編給大家總結了以下內容，希望大家根據這篇文章可以有所收獲。

十余年的寬城網站建設經驗，針對設計、前端、開發、售后、文案、推廣等六對一服務，響應快，48小時及時工作處理。成都營銷網站建設的優勢是能夠根據用戶設備顯示端的尺寸不同，自動調整寬城建站的顯示方式，使網站能夠適用不同顯示終端，在瀏覽器中調整網站的寬度，無論在任何一種瀏覽器上瀏覽網站，都能展現優雅布局與設計，從而大程度地提升瀏覽體驗。創新互聯公司從事“寬城網站設計”,“寬城網站推廣”以來，每個客戶項目都認真落實執行。

收到一個MySQL實例的磁盤告警，看到監控圖，磁盤使用率增長速度非常快，在兩個多小時的時間里，已經漲了170多G。
檢查到binlog目錄并不大，而datadir已經180多G了，發現ibtmp1非常大，并且持續增長。

趕緊上去看processlist，線程不多，檢查到有一個SELECT case ... when ... 的線程，狀態是sending data，并且已經持續幾千秒了。
有點懵，沒有第一時間kill掉這個線程，再一次show processlist的時候……發現大概已經掛了………………

1. mysql> show processlist;

2. ERROR 2006 (HY000): MySQL server has gone away

3. No connection. Trying to reconnect...

4. ERROR 2002 (HY000): Can't connect to local MySQL server through socket '$datadir/mysqld.sock' (2)

5. ERROR: Can't connect to the server

那好，既然已經掛了，那么開始找原因吧…

看一下datadir掛載的磁盤，已經釋放空了，果然已經被重啟了。
ext4    197G  4.6G  191G   3% $datadir


檢查一下mysqld進程，發現已經被mysqld_safe拉起來了。

檢查一下error log：
紅字是關于mysqld crash的信息，很顯然，datadir掛載的磁盤滿了。
沒有多余的空間寫binlog和ibtmp1臨時表空間文件（5.7新增）。
而且ibtmp1文件最后達到了201876045824bytes，將近190G，而掛載的磁盤總大小才不到200G。

藍字是關于sql thread的問題，在mysqld起來之后，sql thread也出現了問題。
這個之后再修復。

1. [ERROR] InnoDB: posix_fallocate(): Failed to preallocate data for file $datadir/ibtmp1, desired size 67108864 bytes. Operating system error number 28. Check that the disk is not full or a disk quota exceeded. Make sure the file system supports this function. Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/ operating-system-error-codes.html

2. [ERROR] Disk is full writing '$datadir/mysql-bin.000004' (Errcode: 15870576 - No space left on device). Waiting for someone to free space...

3. [ERROR] Retry in 60 secs. Message reprinted in 600 secs

4. [Warning] InnoDB: 1048576 bytes should have been written. Only 647168 bytes written. Retrying for the remaining bytes.

5. [Warning] InnoDB: Retry attempts for writing partial data failed.

6. [ERROR] InnoDB: Write to file $datadir/ibtmp1 failed at offset 201911697408, 1048576 bytes should have been written, only 647168 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.

7. [ERROR] InnoDB: Error number 28 means 'No space left on device'

8. [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html

9. [Warning] InnoDB: Error while writing 67108864 zeroes to $datadir/ibtmp1starting at offset 201876045824

10. [ERROR] $basedir/bin/mysqld: The table '$tmpdir/#sql_37c5_0' is full

11. [ERROR] InnoDB: posix_fallocate(): Failed to preallocate data for file ./thread_quartz/QRTZ_FIRED_TRIGGERS.ibd, desired size 32768 bytes. Operating system error number 28. Check that the disk is not full or a disk quota exceeded. Make sure the file system supports this function. Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/ operating-system-error-codes.html

12. [Warning] InnoDB: Retry attempts for writing partial data failed.

13. [Warning] InnoDB: Error while writing 32768 zeroes to ./thread_quartz/QRTZ_FIRED_TRIGGERS.ibd starting at offset 442362017-07-06T11:49:21.893377Z mysqld_safe Number of processes running now: 0

14. mysqld_safe mysqld restarted

15. ……………………………………………………………………………………………………………………

16. [Note] InnoDB: Last MySQL binlog file position 0 690908428, file name mysql-bin.000004

17. [Note] InnoDB: Starting in background the rollback of uncommitted transactions

18. [Note] InnoDB: Rollback of non-prepared transactions completed

19. [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"

20. [Note] InnoDB: Creating shared tablespace for temporary tables

21. [Note] InnoDB: Setting file '$datadir/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

22. [Note] InnoDB: File '$datadir/ibtmp1' size is now 12 MB.

23. [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.

24. [Note] InnoDB: 32 non-redo rollback segment(s) are active.

25. [Note] InnoDB: Waiting for purge to start

26. [Note] InnoDB: 5.7.12 started; log sequence number 4828513952

27. [Note] InnoDB: page_cleaner: 1000ms intended loop took 7748ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)

28. [Note] InnoDB: Loading buffer pool(s) from $datadir/ib_buffer_pool

29. [Note] Plugin 'FEDERATED' is disabled.

30. [Note] InnoDB: Buffer pool(s) load completed at 170706 19:49:30

31. [Note] Recovering after a crash using $basedir/mysql-bin

32. [ERROR] Error in Log_event::read_log_event(): 'read error', data_len: 579, event_type: 2

33. [Note] Starting crash recovery...

34. [Note] InnoDB: Starting recovery for XA transactions...

35. [Note] InnoDB: Transaction 6729603 in prepared state after recovery

36. [Note] InnoDB: Transaction contains changes to 1 rows

37. [Note] InnoDB: 1 transactions in prepared state after recovery

38. [Note] Found 1 prepared transaction(s) in InnoDB

39. [Note] Crash recovery finished.

40. [Note] Crashed binlog file $basedir/mysql-bin.000004 size is 690909184, but recovered up to 690908428. Binlog trimmed to 690908428 bytes.

41. [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key

42. ……………………………………………………………………………………………………………………

43. [ERROR] Error in Log_event::read_log_event(): 'read error', data_len: 835, event_type: 2

44. [Warning] Error reading GTIDs from relaylog: -1

45. [Note] Slave I/O thread: Start asynchronous replication to master '*****' in log 'mysql-bin.000014' at position 286486095

46. [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.

47. [Note] Slave I/O thread for channel '': connected to master '*****',replication started in log 'mysql-bin.000014' at position 286486095

48. [Warning] Slave SQL for channel '': If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0

49. [Note] Slave SQL thread for channel '' initialized, starting replication in log 'mysql-bin.000014' at position 286485153, relay log '$datadir/mysql-relay.000013' position: 286485326

50. [ERROR]Error in Log_event::read_log_event(): 'read error', data_len: 835, event_type: 2

51. [ERROR] Error reading relay log event for channel '': slave SQL thread aborted because of I/O error

52. [ERROR] Slave SQL for channel '': Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave. Error_code: 1594

53. [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'mysql-bin.000014' position 286485153

54. [Note] Event Scheduler: Loaded 0 events

55. [Note] $basedir/mysqld: ready for connections.

56. Version: '5.7.12'  socket: '$datadir/mysqld.sock'  port: 3306  Source distribution

因為已經掛了，而且沒有來得及將當時執行的sql完整記錄下來，只能看到show processlist前面的一小部分。

聯系到業務，業務說這一臺是slave，無讀的業務，但偶爾會手動執行報表相關的SELECT操作。

那么檢查一下crash前的兩個小時的slow log：
發現反復有這么幾條SQL：

1. ……………………

2. 00:00:11.392881 select*from tb ……………………

3. 00:00:04.779748select(casewhen ……………………

4. 00:00:04.779748 select ( case when t2.col1……………………

5. 00:00:03.328248 select ( case when t2.col1 ……………………

6. 00:00:04.276773 select count(t1.id) from tb1 

7. 00:00:05.039027 select (case when t2.col ……………………

8. 00:00:10.263063 select (case when t2.col ……………………

9. 00:00:03.131713 select t2.* from tb1 t1 ……………………

10. 00:00:15.909456 select t2.* from tb1 t1 ……………………

11. 00:00:14.367047 select * from tb ……………………

12. ……………………

雖然沒有一條超過20秒的，但不要忘了，在磁盤被打爆之前的一秒，有一條執行了幾千秒的SQL。
并且case when只有一個order by。
出于取出其中一條，檢查一下執行計劃：

1. +--------+---------------+---------+---------+---------------------+--------+----------+----------------------------------------------+

2. | type   | possible_keys | key     | key_len | ref                 | rows   | filtered | Extra                                        |

3. +--------+---------------+---------+---------+---------------------+--------+----------+----------------------------------------------+

4. | ALL    | NULL          | NULL    | NULL    | NULL                | 472765 | 20.99    | Using where; Using temporary; Using filesort |

5. | eq_ref | PRIMARY       | PRIMARY | 8       | $tb1.col1           | 1      | 10.00    | Using where                                  |

6. +--------+---------------+---------+---------+---------------------+--------+----------+----------------------------------------------+

看起來不是很好，但是也不至于用到190G臨時表。
雖然臨時表是長期積累下來的，但看監控，磁盤使用率確實是在這一個多小時迅速積攢起來的。

首先這個從庫是沒有業務的，而是通過客戶那邊可能手動連接過來做一些查詢服務的。
知道這個信息之后，繼續對照slow log，發現slow log關于case when的這一條sql并不完全一樣……
這可能意味著客戶仍然在不停地調試這條SQL…
而那條執行了幾千秒的case when可能寫得十分爛。

可惜的是，在mysqld crash的最后一瞬間，該sql仍然沒有執行完成，導致沒有被記錄到slow log。
那條sql估計也永遠無法再復現。

那么究竟是多爛的SQL，或者多大的表，可以用到這么多基于磁盤的臨時表或文件排序呢？？
趕緊檢查一下庫表的情況：

    ①表1：100w，表2：40w，也沒有blob，text等字段。
    ② 重啟后的datadir只有3、4G的數據量

所以我有個大但的想法：
可能客戶在調試的過程中，產生了一條類似這樣的SQL：
我對照了已經記錄在slow log的幾條sql，脫敏，格式化之后還原如下：

1. SELECT ( CASE

2.     WHEN t2.col='$info_000' THEN '$a'

3.     WHEN t2.col='$info_001' THEN '$b'

4.     WHEN t2.col='$info_002' THEN '$c'

5.     WHEN t2.col='$info_003' THEN '$d'

6.     WHEN t2.col='$info_004' THEN '$e'

7.     WHEN t2.col='$info_005' THEN '$f'

8.     WHEN t2.col='$info_006' THEN '$g'

9.     ELSE t2.col

10.     END ) AS 來源XX,

11.     ( CASE

12.     WHEN t2.clo2='$info_000' THEN '$a'

13.     WHEN t2.clo2='$info_001' THEN '$b'

14.     WHEN t2.clo2='$info_002' THEN '$c'

15.     WHEN t2.clo2='$info_003' THEN '$d'

16.     WHEN t2.clo2='$info_004' THEN '$e'

17.     WHEN t2.clo2='$info_005' THEN '$f'

18.     WHEN t2.clo2='$info_006' THEN '$g'

19.     ELSE t2.col 

20.     END ) AS 目標XX,

21.     t2.col4 AS XX時間,

22.     t2.col5 AS 金額

23. FROM $tb1 t1 JOIN $tb2 t2

24. WHERE t1.col3 = 4 AND (t2.col LIKE '$info%' OR t2.clo2 LIKE '$info%')

25. ORDER BY t1.col4 DESC;

對，這兩張表做了一個JOIN，但是沒有條件。
產生了一個很大很大很大的笛卡爾積。

那么算一下：
列：13 + 19 = 32 
行： 1088181*440650 = 479,506,957,650 rows

再測試一下：
將兩張表dump成sql文件，看了一下大小：330MB，并不大。
導入自己的實驗環境，再將上述產生笛卡爾積的SQL跑一下。

經過一段時間等待：


已經執行了半個小時多了。并且該SQL仍然在執行：
說出來你們可能不信，此時的ibtmp1大小：

1. # du -sh *

2. 4.0K    auto.cnf

3. 4.0K    ib_buffer_pool

4. 2.9G    ibdata1

5. 48M     ib_logfile0

6. 48M     ib_logfile1

7. 54G     ibtmp1

8. 12M     mysql

9. 1.1M    performance_schema

10. 676K    sys

11. 633M    test

12. 47M     test_2

大概也好解釋，為什么兩張并不是很大的表，在執行某些查詢之后會產生這么大的臨時表了…

當然，在做實驗的等待時間里，已經將復制的ERROR給修復了。
當時復制的報錯：

1. ……

2. Slave_IO_Running: Yes

3. Slave_SQL_Running: No

4. ……

5. Seconds_Behind_Master: NULL

6. Master_SSL_Verify_Server_Cert: No

7. Last_IO_Errno: 0

8. Last_IO_Error:

9. Last_SQL_Errno: 1594

10. Last_SQL_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.

結合之前貼的error log可以看到更多信息，推斷是relay log有損壞。


那么就好解決了：

1. STOP SLAVE;

3. -- master_log_file和master_log_pos為報錯時所記錄的位置。

4. CHANGE MASTER master_log_file='xxx', master_log_pos=xxx;

6. START SLAVE;

此處不再贅述。


到目前為止，我實驗環境的datadir已經滿了，但是和此處正式環境有區別的是。
在磁盤寫滿之時，并沒有馬上導致mysql crash，而是輸出了：

1. [ERROR] InnoDB: Write to file ./ibtmp1failed at offset 83579895808, 1048576 bytes should have been written, only 958464 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.

2. [ERROR] InnoDB: Error number 28 means 'No space left on device'

3. [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html

4. [Warning] InnoDB: Error while writing 67108864 zeroes to ./ibtmp1 starting at offset 83563118592

5. [ERROR] /data/mysql-base/mysql57/bin/mysqld: The table '#sql_b26_0' is full

6. [ERROR] Disk is full writing '/data/mysql-data/mysql57-3357/binlog/mysql-bin.000015' (Errcode: 15868064 - No space left on device). Waiting for someone to free space...

7. [ERROR] Retry in 60 secs. Message reprinted in 600 secs

實際上正常情況下，mysql在磁盤滿了的情況下，會每隔1分鐘做一次檢查，每隔10分鐘將檢查信息輸出到錯誤日志。

既然mysqld沒有被干掉，我再次執行了一下那條可怕的sql呢？……

當然……error log如愿輸出被kill的消息……
并且mysqld進程被殺掉，此時：

1. [ERROR] /data/mysql-base/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.

2. 14:42:48 UTC - mysqld got signal 6 ;

3. This could be because you hit a bug. It is also possible that this binary

4. or one of the libraries it was linked against is corrupt, improperly built,

5. or misconfigured. This error can also be caused by malfunctioning hardware.

6. Attempting to collect some information that could help diagnose the problem.

7. As this is a crash and something is definitely wrong, the informati

有趣的是，“information”這個單詞都沒有輸出完，大概是真的一個字符都寫不下了吧。


試圖用vim在error log里添加幾個字符并保存，也報錯。

總結一下：
〇在線上環境執行的sql，建議進行審核，報表等OLAP需求也需要正式一些。
〇考慮是否可以限制ibtmp1的大小，也就是設定innodb_temp_data_file_path的最大值。
〇可能需要定期重啟mysqld來收縮臨時表空間。
〇做好監控和及時響應，這次就是響應時間過長，達到閾值，然后到機子上檢查時，已經晚了，眼睜睜地看到mysqld在我眼前crash。

看完上述內容，你們對MySQL中一條SQL使磁盤暴漲并導致MySQL Crash該怎么辦有進一步的了解嗎？如果還想了解更多知識或者相關內容，請關注創新互聯行業資訊頻道，感謝大家的支持。

本文標題：MySQL中一條SQL使磁盤暴漲并導致MySQLCrash該怎么辦
標題鏈接：http://m.jcarcd.cn/article/pcjoso.html