關於熱點資料匯出與載入的影響,多的是你不知道的事

沃趣科技發表於2017-06-22

導  讀

想必資料庫的同行們都知道,熱點資料匯出匯入的動作,使得資料庫重啟之後,不需要再耗費大量的時間來預熱,使得因為熱點資料的原因導致資料庫效能波動的時間大大減少,那麼執行熱點資料的匯出與匯入操作時究竟對資料庫的效能有沒有影響呢?如果你的伺服器擁有超大記憶體,而且設定了一個對應記憶體一定比例的超大buffer pool,是否在糾結需不需要設定熱點資料在重啟時自動匯出匯入呢?下面一起看演示過程,答案就在其中。


背  景

  • sysbench造數200個500W資料量的表,佔用磁碟空間275G

  • 伺服器配置 
    CPU:72 vcpus 
    記憶體:256G 
    磁碟:1.5T SSD RAID10

  • 資料庫版本:5.6.34

  • 資料庫引數:innodb_buffer_pool_size=160G

  • 測試目的:測試在innodb_buffer_pool_size設定的buffer poo size佔滿時,匯出匯入ib_buffer_pool檔案需要多長時間


手動執行匯出ib_buffer_pool

  • sysbench 32執行緒oltp持續加壓

  • 先檢視一下buffer pool中當前有多少的資料量,是否達到或接近160G buffer大小,如果資料量已接近160G,則繼續往下(注:Innodb_buffer_pool_pages_data為當前buffer pool中包含資料的頁數)


[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:11:51]>show status like '%Innodb_buffer_pool_pages_data%';

+-------------------------------+----------+

| Variable_name                 | Value    |

+-------------------------------+----------+

| Innodb_buffer_pool_pages_data | 10319938 |

+-------------------------------+----------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:12:02]>select 10319938*16/1024/1024;

+-----------------------+

| 10319938*16/1024/1024 |

+-----------------------+

|          157.46975708 |

+-----------------------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:12:17]>


  • 為了對比後續有熱點資料和沒有熱點資料匯入匯出的差別,先執行一次不匯出匯入熱點資料的資料庫重啟,並記錄關閉和啟動mysqld的時間,先在innodb_buffer_pool_dump_at_shutdown=off的情況下,關閉MySQL,看看關閉時間需要多久。


# 設定 innodb_buffer_pool_dump_at_shutdown=off;

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 15:37:26]>set global innodb_buffer_pool_dump_at_shutdown=off;

Query OK, 0 rows affected (0.00 sec)

# 執行關閉mysqld,並記錄time命令列印的執行時間

$time mysqladmin --defaults-file=/home/mysql/conf/my1.cnf -uroot -p'password' -hlocalhost -P3306 shutdown

170428 18:34:16 mysqld_safe mysqld from pid file /home/mysql/data/mysqldata1/sock/mysql.pid ended

[1]+  Done      

......

real    1m4.020s

user    43m35.121s

sys 11m36.453s

# 執行啟動mysqld,啟動mysqld之前,先在my.cnf中配置引數innodb_buffer_pool_load_at_startup=OFF,再啟動,看看需要多長時間,由於是掛後臺,無法使用time命令檢視,可以透過錯誤日誌中的輸出來大致判斷啟動時間需要多長

$time mysqld_safe --defaults-file=/home/mysql/conf/my1.cnf --user=mysql &

$cat /data2/mysqldata1/log/error.log

......

170428 17:18:09 mysqld_safe Starting mysqld daemon with databases from /home/mysql/data/mysqldata1/mydata

2017-04-28 17:18:09 0 [Warning] Using unique option prefix collation instead of collation-server is deprecated and will be removed in a future release. Please use the full name instead.

......

2017-04-28 17:18:28 16701 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000228' at position 58975338, \

relay log '/home/mysql/data/mysqldata1/relaylog/mysql-relay-bin.000462' position: 4

2017-04-28 17:18:28 16701 [Note] Event Scheduler: Loaded 0 events

2017-04-28 17:18:28 16701 [Note] /usr/local/mysql/bin/mysqld: ready for connections.

Version: '5.6.34-log'  socket: '/home/mysql/data/mysqldata1/sock/mysql.sock'  port: 3306  MySQL Community Server (GPL)  

  • 從以上錯誤日誌的輸出資訊中可以看到,Starting mysqld 到列印socket地址時間的日誌時間判斷,在沒有載入ib_buffer_pool時的啟動時間為20S,且memlock引數未使用的情況下

  • 現在,重新使用sysbench持續32執行緒oltp加壓,以使得熱點資料儘量佔滿buffer pool

  • 然後登入資料庫執行set global innodb_buffer_pool_dump_now=on;語句(注意:在執行這個步驟之前,你需要確保Innodb_buffer_pool_pages_data引數中的頁數接近佔用全部的buffer pool size,否則後續的測試沒有意義)


# 設定innodb_buffer_pool_dump_now=on,表示立即匯出熱點資料頁到ib_buffer_pool檔案中

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 16:58:00]>set global innodb_buffer_pool_dump_now=on;

Query OK, 0 rows affected (0.00 sec)

# 使用Innodb_buffer_pool_dump_status狀態變數檢視一下dump完成時間(如果沒有顯示dump completed 則需要繼續等待並持續檢視這個變數,直到顯示dump completed 為止)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:00:15]>show status like 'Innodb_buffer_pool_dump_status';

+--------------------------------+--------------------------------------------------+

| Variable_name                  | Value                                            |

+--------------------------------+--------------------------------------------------+

| Innodb_buffer_pool_dump_status | Buffer pool(s) dump completed at 170428 16:58:42 |

+--------------------------------+--------------------------------------------------+

1 row in set (0.00 sec)


  • 現在,檢視與MySQL ibdata1檔案相同目錄下的ib_buffer_pool檔案。


$ ls -lh /data2/mysqldata1/innodb_ts/

total 2.1G

-rw-rw---- 1 mysql mysql  95M Apr 28 16:58 ib_buffer_pool

-rw-rw---- 1 mysql mysql 2.0G Apr 28 16:58 ibdata1

# 使用stat命令檢視這個檔案的秒級別access和Modify時間,在這個場景下,我們可以認為access代表了檔案建立時間(檔案控制程式碼開啟時間),Modify代表了檔案最後變更的時間(資料寫入完成時間)

#stat /data2/mysqldata1/innodb_ts/ib_buffer_pool

......

Access: 2017-04-28 16:58:39.078935848 +0800

Modify: 2017-04-28 16:58:42.568889476 +0800

Change: 2017-04-28 16:58:42.568889476 +0800


  • 計算前面幾個步驟獲取的時間:透過資料庫中的show status like 'Innodb_buffer_pool_dump_status';查詢結果,完成時間是16:58:42,透過stat命令查詢到這個檔案最後修改時間是16:58:42,時間一致,檔案access時間與Modify時間相差3秒,表示ib_buffer_pool檔案在檔案系統層3秒就完成了dump操作(從資料庫層到檔案系統層的寫入),而對於資料庫層,執行set global innodb_buffer_pool_dump_now=on;時是立即返回,說明該語句對於資料庫語句執行來說,沒有阻塞操作。


自動執行匯出ib_buffer_pool

  • sysbench 32執行緒oltp持續加壓

  • 登入MySQL資料庫中使用修改變數:set global innodb_buffer_pool_dump_at_shutdown=on;   修改innodb_buffer_pool_dump_at_shutdown=on之後,mysqld在關閉時會自動匯出熱點資料頁到ib_buffer_pool檔案中


[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:12:17]>set global innodb_buffer_pool_dump_at_shutdown=on;

Query OK, 0 rows affected (0.00 sec)


  • 注意:innodb_fast_shutdown的值不能為2,否則將無法執行匯出(經原始碼分析,在該引數設定為2時,不會進入dump函式執行ib_buffer_pool的匯出),如果為2請先修改為1即可:set global innodb_fast_shutdown=1;


[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:14:20]>show variables like 'innodb_fast_shutdown';

+----------------------+-------+

| Variable_name        | Value |

+----------------------+-------+

| innodb_fast_shutdown | 2     |

+----------------------+-------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:14:31]>set global innodb_fast_shutdown=1;

Query OK, 0 rows affected (0.00 sec)


在shell命令列中停止MySQL,留意停止時間需要多長。


$time mysqladmin --defaults-file=/home/mysql/conf/my1.cnf -uroot -p'password' -hlocalhost -P3306 shutdown

......

real    1m18.036s

user    0m0.005s

sys 0m0.004s

  • 檢視錯誤日誌,可以發現Dump ib_buffer_pool檔案中的相關日誌輸出,開始時間到結束時間對比,耗時為4S。


2017-04-28 17:16:21 7ed606745700 InnoDB: Dumping buffer pool(s) to /home/mysql/data/mysqldata1/innodb_ts/ib_buffer_pool

2017-04-28 17:16:25 7ed606745700 InnoDB: Buffer pool(s) dump completed at 170428 17:16:25


  • 使用stat命令檢視ib_buffer_pool檔案的建立,修改時間,這裡也可以看到,access和modify時間相差是4S,說明buffer pool在4S內完成了dump。


#ls -lh /data2/mysqldata1/innodb_ts/ib_buffer_pool

-rw-rw---- 1 mysql mysql 95M Apr 28 17:16 /data2/mysqldata1/innodb_ts/ib_buffer_pool

[root@master /root]

#stat /data2/mysqldata1/innodb_ts/ib_buffer_pool

......

Access: 2017-04-28 17:16:21.938770942 +0800

Modify: 2017-04-28 17:16:25.291726062 +0800

Change: 2017-04-28 17:16:25.291726062 +0800


手動執行匯入ib_buffer_pool

  • 在shell命令列中啟動MySQL(注意這裡配置檔案中配置引數innodb_buffer_pool_load_at_startup設定為OFF,讓mysqld啟動時並不自動載入ib_buffer_pool檔案)


170428 17:18:09 mysqld_safe Starting mysqld daemon with databases from /home/mysql/data/mysqldata1/mydata

2017-04-28 17:18:09 0 [Warning] Using unique option prefix collation instead of collation-server is deprecated and will be removed in a future release. Please use the full name instead.

......

2017-04-28 17:18:28 16701 [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.

2017-04-28 17:18:28 16701 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000228' at position 58975338,\

relay log '/home/mysql/data/mysqldata1/relaylog/mysql-relay-bin.000462' position: 4

2017-04-28 17:18:28 16701 [Note] Event Scheduler: Loaded 0 events

2017-04-28 17:18:28 16701 [Note] /usr/local/mysql/bin/mysqld: ready for connections.

Version: '5.6.34-log'  socket: '/home/mysql/data/mysqldata1/sock/mysql.sock'  port: 3306  MySQL Community Server (GPL)


  • 從上面的錯誤日誌資訊中可以看到,從Starting mysqld 到列印socket地址時間的日誌時間判斷,在沒有載入ib_buffer_pool時的啟動時間為20S,且memlock引數未使用的情況下。現在,登入資料庫手動load ib_buffer_pool檔案。


# 執行load ib_buffer_pool檔案

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:24:53]>set global innodb_buffer_pool_load_now=ON;

Query OK, 0 rows affected (0.00 sec)

# 檢視load 完成時間,如果沒有檢視到load completed,則持續檢視Innodb_buffer_pool_load_status狀態變數

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:14:21]>show status like '%Innodb_buffer_pool_load_status';

+--------------------------------+--------------------------------------------------+

| Variable_name                  | Value                                            |

+--------------------------------+--------------------------------------------------+

| Innodb_buffer_pool_load_status | Buffer pool(s) load completed at 170428 18:10:32 |

+--------------------------------+--------------------------------------------------+

1 row in set (0.00 sec)

# load ib_buffer_pool期間載入期間,可以使用iostat命令檢視data磁碟載情況,如下

avg-cpu:  %user   %nice %system %iowait  %steal   %idle

          0.06    0.00    0.15    1.15    0.00   98.64

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util

sda               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

sdb               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

sdc               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

sdd               0.00     0.00 4410.00    0.00 141120.00     0.00    32.00     0.86    0.19   0.19  85.70

dm-0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

dm-1              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

dm-2              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

dm-3              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

md127             0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

sde               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

sdf               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00


  • 檢視錯誤日誌中的Dump開始時間 
    2017-04-28 17:29:42 7fd07fff9700 InnoDB: Loading buffer pool(s) from /home/mysql/data/mysqldata1/innodb_ts/ib_buffer_pool

  • 從上面一系列結果來看,日誌中開始執行load的時間為17:29:42,而show status檢視到的load ib_buffer_pool檔案完成時間是18:10:32,耗時近40分鐘,load期間磁碟讀負載較高。但並不會阻塞對資料庫的讀寫操作


自動執行匯入ib_buffer_pool

  • 本節中由於使用相同環境,"手動執行匯入ib_buffer_pool"的演示步驟中已經執行過手動load ib_buffer_pool檔案,這裡需要先關閉mysqld並使用關閉時自動匯入熱點資料頁引數innodb_buffer_pool_dump_at_shutdown=on,以及innodb_fast_shutdown=1

  • 先設定set global innodb_buffer_pool_dump_at_shutdown=on;設定set global innodb_fast_shutdown=1;


[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:46:50]>set global innodb_buffer_pool_dump_at_shutdown=on;

Query OK, 0 rows affected (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:46:58]>set global innodb_fast_shutdown=1;

Query OK, 0 rows affected (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:47:03]>


  • 然後停止MySQL


$ mysqladmin --defaults-file=/home/mysql/conf/my1.cnf -uroot -p'password' -hlocalhost -P3306 shutdown

  • 把innodb_buffer_pool_load_at_startup=ON引數加到配置檔案中


cat /home/mysql/conf/my1.cnf

......

innodb_buffer_pool_load_at_startup=ON


  • 啟動MySQL


$ mysqld_safe --defaults-file=/home/mysql/conf/my1.cnf --user=mysql &

  • 檢視錯誤日誌中,開始Load的日誌輸出如下(並沒有看到Load ib_buffer_pool完成的日誌)


2017-04-28 18:49:55 7fa0dfb83700 InnoDB: Loading buffer pool(s) from /home/mysql/data/mysqldata1/innodb_ts/ib_buffer_pool

  • 登入資料庫中查詢Load狀態(可以看到總共10319883個頁,才匯入119681個頁,才1%……),沒有發現 load completed 字串。


[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:50:22]>show status like '%Innodb_buffer_pool_load_status';

+--------------------------------+------------------------------+

| Variable_name                  | Value                        |

+--------------------------------+------------------------------+

| Innodb_buffer_pool_load_status | Loaded 119681/10319883 pages |

+--------------------------------+------------------------------+

1 row in set (0.00 sec)


  • 在ib_buffer_pool檔案執行載入過程中,可以嘗試著訪問一下資料庫(可以正常訪問,說明在Load ib_buffer_pool時並不會阻塞資料庫訪問,Load操作是在後臺執行的)


[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:51:52]>select * from sbtest1 order by id desc limit 1;

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| id      | k       | c                                                                                                                       | pad                                                         |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| 9999999 | 2507960 | 25744810828-37032637642-87919764377-76779868555-49415634722-86176448317-10050757951-88422706101-49861857465-53325889077 | 55855883347-94289537806-43993911203-91112041707-01357150366 |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:52:02]>update sbtest1 set k=k+1 where id=9999999;

Query OK, 1 row affected (0.00 sec)

Rows matched: 1  Changed: 1  Warnings: 0

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:54:05]>select * from sbtest1 order by id desc limit 1;

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| id      | k       | c                                                                                                                       | pad                                                         |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| 9999999 | 2507961 | 25744810828-37032637642-87919764377-76779868555-49415634722-86176448317-10050757951-88422706101-49861857465-53325889077 | 55855883347-94289537806-43993911203-91112041707-01357150366 |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

1 row in set (0.00 sec)

  • 這個時候,要做的就是繼續等待,直到錯誤日誌中列印Load完成的日誌,或者Innodb_buffer_pool_load_status狀態變數檢視到 load completed 字串。


# 檢視錯誤日誌

$ cat /data2/mysqldata1/log/error.log

......

2017-04-28 19:30:32 7fa0dfb83700 InnoDB: Buffer pool(s) load completed at 170428 19:30:32

# 資料庫中的狀態查詢到Load完成

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 19:46:10]>show status like '%Innodb_buffer_pool_load_status';

+--------------------------------+--------------------------------------------------+

| Variable_name                  | Value                                            |

+--------------------------------+--------------------------------------------------+

| Innodb_buffer_pool_load_status | Buffer pool(s) load completed at 170428 19:30:32 |

+--------------------------------+--------------------------------------------------+

1 row in set (0.00 sec)


  • 從上面的結果中可以看到,Load開始時間是18:49:55,結束時間是19:30:32,耗時近40分鐘,與手動Load ib_buffer_pool檔案耗時相當。


總  結

從以上測試結果可以看到,ib_buffer_pool的Dump時間160G左右的資料量,1000W左右的資料頁,只需要幾秒時間,在Load的時候,需要大約40分鐘,但是在Load ib_buffer_pool檔案的時候並不會阻塞對資料庫的訪問,所以理論上在MySQL的起停中開啟ib_buffer_pool的自動Dump和Load對資料庫前臺的操作影響極小,建議在配置檔案中設定如下引數以實現該功能。


innodb_buffer_pool_dump_at_shutdown=ON

innodb_buffer_pool_load_at_startup=ON

innodb_fast_shutdown=1


  • 補 充

  • 在MySQL 5.6.x版本中innodb_buffer_pool_dump_at_shutdown和innodb_buffer_pool_load_at_startup引數預設關閉,從MySQL 5.7.7及其之後的版本預設開啟,在MySQL起停的時候自動Dump 和Load ib_buffer_pool檔案,但需要注意innodb_fast_shutdown引數不能設定為2,否則就算引數innodb_buffer_pool_dump_at_shutdown開啟,在關閉MySQL時也不會自動Dump ib_buffer_pool檔案,可能導致在MySQL啟動時報ib_buffer_pool檔案不存在的錯誤(如果你手工執行了set global innodb_buffer_pool_dump_now=ON就會立即Dump出ib_buffer_pool檔案)。

  • 雖然在Load ib_buffer_pool檔案時不會阻塞前臺的操作,而是在後臺執行,但是從測試結果中可以看到,Load操作會佔用大量磁碟的讀IO,所以對於MySQL的起停操作,需要避開業務高峰期進行。

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/28218939/viewspace-2141146/,如需轉載,請註明出處,否則將追究法律責任。

相關文章