故障分析 | MySQL 耗盡主機記憶體一例分析

愛可生雲資料庫發表於2022-07-12

作者:付祥

現居珠海,主要負責 Oracle、MySQL、mongoDB 和 Redis 維護工作。

本文來源:原創投稿

*愛可生開源社群出品,原創內容未經授權不得隨意使用,轉載請聯絡小編並註明來源。


異常現象

開發人員反饋,有一臺伺服器記憶體幾乎被 MySQL 耗盡了,執行 top 命令,輸出如下:

這臺機器是個測試環境,MySQL 是開發自己安裝的,資料庫版本 5.6.51 ,機器總記憶體32G,MySQL 佔了29G。

分析過程

檢視 MySQL 啟動時間發現1個星期前才啟動,猜測之前由於主機記憶體耗盡觸發了 OOM ,檢視 MySQL 錯誤日誌,發現每隔10幾天,MySQL 就異常關閉一次:

2022-02-24 03:03:42 20981 [Note] InnoDB: Database was not shutdown normally!
2022-03-13 02:31:40 4134 [Note] InnoDB: Database was not shutdown normally!
2022-03-31 02:31:08 6846 [Note] InnoDB: Database was not shutdown normally!
2022-04-12 02:31:41 1159 [Note] InnoDB: Database was not shutdown normally!
2022-04-23 04:41:51 6773 [Note] InnoDB: Database was not shutdown normally!
2022-05-04 02:31:52 2499 [Note] InnoDB: Database was not shutdown normally!
2022-05-13 04:56:06 23010 [Note] InnoDB: Database was not shutdown normally!
2022-05-30 02:31:33 3244 [Note] InnoDB: Database was not shutdown normally!

檢視作業系統日誌,進一步驗證了 MySQL 耗盡主機記憶體,觸發 OOM :

# grep oom-killer /var/log/messages* /var/log/messages-20220605:May 30 02:31:30 vm10-136-9-24 kernel: mysqld invoked
oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0

檢視 my.cnf 配置檔案,發現幾乎都是預設配置,innodb_buffer_pool_size 等於預設值128M :

mysql> show variables like 'innodb_buffer_pool_size'; 
+-------------------------+-----------+
| Variable_name | Value               | 
+-------------------------+-----------+
| innodb_buffer_pool_size | 134217728 | 
+-------------------------+-----------+

當前資料庫有500多個連線,都是 Sleep 狀態,從 MySQL 錯誤日誌發現 performance_schema 下的表結構全是錯誤的,估計 MySQL 版本做了升級,沒有執行 upgrade升 級資料字典,意味著一些記憶體診斷資訊便不能從 PS 獲取:

2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'cond_instances' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_current' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_history' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_history_long' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_summary_by_host_by_event_name' has the wrong
structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_summary_by_instance' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_summary_by_thread_by_event_name' has the wrong
structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_summary_by_user_by_event_name' has the wrong
structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_summary_by_account_by_event_name' has the wrong
structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'events_waits_summary_global_by_event_name' has the wrong
structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'file_instances' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'file_summary_by_event_name' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'file_summary_by_instance' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table 'performance_schema'.'host_cache'
has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'mutex_instances' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'objects_summary_global_by_type' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'performance_timers' has the wrong structure
2022-06-09 11:19:08 27468 [ERROR] Native table
'performance_schema'.'rwlock_instances' has the wrong structure
.....省略輸出.........
mysql> show variables like 'performance_schema'; +--------------------+-------+
| Variable_name | Value | +--------------------+-------+
| performance_schema | ON | +--------------------+-------+
1 row in set (0.00 sec)
mysql> use performance_schema
Database changed
mysql> show tables;
Empty set (0.00 sec)

show engine innodb status ,擷取記憶體資訊如下:

BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137363456; in additional pool allocated 0
Dictionary memory allocated 736104382
Buffer pool size 8191
Free buffers 1024
Database pages 6851
Old database pages 2508
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1280745, not young 1337956473
1.59 youngs/s, 0.10 non-youngs/s
Pages read 97753005, created 121179, written 1163360
0.06 reads/s, 0.88 creates/s, 12.12 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 6851, unzip_LRU len: 0 I/O sum[597]:cur[0], unzip sum[0]:cur[0]

資料字典分配記憶體竟然達到700M,通過 lsof 命令發現,MySQL 開啟了大量的 MyISAM 表分割槽檔案,每個分割槽佔用2個檔案控制程式碼,這應該是其記憶體使用高的原因:

lsof|grep "#P#"|grep -E "MYD$|MYI$"|wc -l
29826

MyISAM 儲存引擎,資料塊通過作業系統快取,索引塊由 key buffer 快取,大小通過引數 key_buffer_size 控制,當前預設值如下:

mysql> show variables like 'key_buffer_size'; 
+-----------------+---------+
| Variable_name | Value     | 
+-----------------+---------+
| key_buffer_size | 8388608 | 
+-----------------+---------+
1 row in set (0.00 sec)

MySQL 預設使用 GLIBC 記憶體分配器,通過 gdb 呼叫 malloc_stats()函式分析記憶體使用情況:

gdb -ex "call (void) malloc_stats()" --batch -p $(pidof mysqld)

上述命令執行完成後,會將記憶體使用情況列印到 MySQL 錯誤日誌:

Arena 0:
system bytes = 2001301504
in use bytes = 250961264
Arena 1:
system bytes = 12181504
in use bytes = 1000800
Arena 2:
system bytes = 164257792
in use bytes = 8032368
Arena 3:
system bytes = 1363267584
in use bytes = 468958176
Arena 4:
system bytes = 335654912
in use bytes = 708240
Arena 5:
system bytes = 2150400
in use bytes = 254576
Arena 6:
system bytes = 32059392
in use bytes = 1078000
Arena 7:
system bytes = 671559680
in use bytes = 4884688
Arena 8:
system bytes = 44052480
in use bytes = 935904
Arena 9:
system bytes = 43302912
in use bytes = 2630256
Arena 10:
system bytes = 21729280
in use bytes = 618848
Arena 11:
system bytes = 702341120
in use bytes = 2745648
Arena 12:
system bytes = 63066112
in use bytes = 1537360
Arena 13:
system bytes = 467128320
in use bytes = 2199648
Arena 14:
system bytes = 1682067456
in use bytes = 23873712
Arena 15:
system bytes = 1613938688
in use bytes = 929648
Arena 16:
system bytes = 150749184
in use bytes = 1593600
Arena 17:
system bytes = 1554382848
in use bytes = 343840
Arena 18:
system bytes = 514367488
in use bytes = 38418976
Arena 19:
system bytes = 88248320
in use bytes = 3488848
Arena 20:
system bytes = 703705088
in use bytes = 5674256
Arena 21:
system bytes = 469848064
in use bytes = 417632
Arena 22:
system bytes = 172064768
in use bytes = 2259808
Arena 23:
system bytes = 391884800
in use bytes = 763104
Arena 24:
system bytes = 1414455296
in use bytes = 26260272
Arena 25:
system bytes = 316915712
in use bytes = 596432
Arena 26:
system bytes = 702865408
in use bytes = 623840
Arena 27:
system bytes = 516800512
in use bytes = 371040
Arena 28:
system bytes = 175669248
in use bytes = 3301776
Arena 29:
system bytes = 26525696
in use bytes = 1406640
Arena 30:
system bytes = 51970048
in use bytes = 375072
Arena 31:
system bytes = 525869056
in use bytes = 515651936
Arena 32:
system bytes = 363950080
in use bytes = 696912
Arena 33:
system bytes = 1816637440
in use bytes = 13213184
Arena 34:
system bytes = 1470251008
in use bytes = 13774880
Arena 35:
system bytes = 703832064
in use bytes = 2624144
Arena 36:
system bytes = 115941376
in use bytes = 3248720
Arena 37:
system bytes = 777551872
in use bytes = 978896
Arena 38:
system bytes = 45363200
in use bytes = 45081504
Arena 39:
system bytes = 374652928
in use bytes = 341904
Arena 40:
system bytes = 26222592
in use bytes = 25993760
Arena 41:
system bytes = 20140032
in use bytes = 386384
Arena 42:
system bytes = 702484480
in use bytes = 700284096
Arena 43:
system bytes = 54947840
in use bytes = 1650880
Arena 44:
system bytes = 516972544
in use bytes = 3178016
Arena 45:
system bytes = 66084864
in use bytes = 1186080
Arena 46:
system bytes = 1672466432
in use bytes = 3988320
Arena 47:
system bytes = 3727360
in use bytes = 1518624
Arena 48:
system bytes = 471752704
in use bytes = 66314288
Arena 49:
system bytes = 491962368
in use bytes = 2521952
Arena 50:
system bytes = 12431360
in use bytes = 3573216
Arena 51:
system bytes = 58073088
in use bytes = 720512
Arena 52:
system bytes = 24412160
in use bytes = 1166080
Arena 53:
system bytes = 34963456
in use bytes = 1003856
Arena 54:
system bytes = 28745728
in use bytes = 3283728
Arena 55:
system bytes = 703614976
in use bytes = 423398352
Arena 56:
system bytes = 31150080
in use bytes = 30834032
Arena 57:
system bytes = 397848576
in use bytes = 757680
Arena 58:
system bytes = 416169984
in use bytes = 1561520
Arena 59:
system bytes = 702533632
in use bytes = 4707824
Arena 60:
system bytes = 26615808
in use bytes = 8339040
Arena 61:
system bytes = 174006272
in use bytes = 317760
Arena 62:
system bytes = 3846144
in use bytes = 3525664
Arena 63:
system bytes = 26365952
in use bytes = 693104
Total (incl. mmap):
system bytes = 1166893056
in use bytes = 348358880
max mmap regions = 55
max mmap bytes = 1919492096

將上述輸出存入臨時檔案 /tmp/fx.txt ,計算分配給 MySQL 記憶體和 MySQL 使用記憶體如下:

# awk '{if($1 == "system") total+=$NF; else if ($1 == "in") used+=$NF }END{print
total/1024/1024/1024,used/1024/1024/1024}' /tmp/fx.txt
28.4044 2.87976

分配給 MySQL 記憶體28.4G,MySQL 使用記憶體才2.8G,表明記憶體碎片化太嚴重了,使用 google 記憶體分配器 tcmalloc 重啟 MySQL 十幾天後,top 命令觀察 MySQL 佔用記憶體穩定在5G:

小結

jemalloc 和 tcmalloc 之類的記憶體分配器在一些場景,尤其是在多核 CPU 和高併發工作負載下能提供更高效的效能,例如我們熟知的 mongodb 使用 tcmalloc ,redis 使用 jemalloc 。

相關文章