XtraBackup全備工作流程解讀與總結

背景

出于對XtraBackup工作原理好奇，做了下面的日志解讀

備份輸出日志解讀

[root@node1 09:23:35 /root]
#time innobackupex --defaults-file=/data/mysql/mysql3306/my3306.cnf -S /tmp/mysql3306.sock -uroot -plmlm /data/backup/
180525 09:24:24 innobackupex: Starting the backup operation
#開始備份操作
#為什么使用innobackupex，因為5.7及以前版本，mysql表是myisam引擎表，innobackupex可以備份所有引擎表
IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".
#重要提示：請檢查備份運行是否成功完成。
#在成功的備份運行結束時，innobackupex會打印“completed OK!”，也就是完成狀態是OK。
180525 09:24:24  version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;port=3306;mysql_socket=/tmp/mysql3306.sock' as 'root'  (using password: YES).
#版本檢查：使用DSN連接到MySQL服務器，DSN是數據源名稱，也就是連接數據庫需要的參數。
180525 09:24:24  version_check Connected to MySQL server
180525 09:24:24  version_check Executing a version check against the server...
#對服務器執行版本檢查
180525 09:24:24  version_check Done.
180525 09:24:24 Connecting to MySQL server host: localhost, user: root, password: set, port: 3306, socket: /tmp/mysql3306.sock
Using server version 5.7.22-log
#連接到MySQL服務器，使用的參數是：host=localhost,user=root,password=使用命令行輸入的，但不打印進日志；
port=3306,socket=/tmp/mysql3306.sock,使用的版本是5.7.22
innobackupex version 2.4.11 based on MySQL server 5.7.19 Linux (x86_64) (revision id: b4e0db5)
#innobackupex版本是2.4.11，是基于64位Linux的5.7.19版本的MySQL服務器
xtrabackup: uses posix_fadvise().
#xtrabckup：使用posix_fadvise()函數，這是程序的函數入口？
xtrabackup: cd to /data/mysql/mysql3306/data
#xtrabckup：cd到/data/mysql/mysql3306/data目錄下
xtrabackup: open files limit requested 65535, set to 65535
#xtrabckup：打開文件請求限制65535，設置為65535
xtrabackup: using the following InnoDB configuration:
#xtrabckup：使用以下InnoDB配置信息
xtrabackup:   innodb_data_home_dir = .
#設置innodb數據的存放目錄為當前目錄
xtrabackup:   innodb_data_file_path = ibdata1:100M:autoextend
#設置innodb共享表空間文件的個數和初始分配大小值，autoextend是自動擴展
xtrabackup:   innodb_log_group_home_dir = ./
#設置innodb日志文件的存放目錄為當前目錄（.和./是等效的）
xtrabackup:   innodb_log_files_in_group = 3
#設置innodb日志文件的個數為3
xtrabackup:   innodb_log_file_size = 104857600
#設置innodb日志文件的大小為100M
xtrabackup: using O_DIRECT
#使用無緩存的輸入、輸出
InnoDB: Number of pools: 1
#備份的線程是1個，還是線程池？不太明白
180525 09:24:24 >> log scanned up to (2643241)
#從2643241字節開始掃描日志
xtrabackup: Generating a list of tablespaces
#生成表空間列表
InnoDB: Allocated tablespace ID 2 for mysql/plugin, old maximum was 0
#為mysql/插件分配的表空間ID 2，舊的最大值為0
180525 09:24:25 [01] Copying ./ibdata1 to /data/backup/2018-05-25_09-24-24/ibdata1
180525 09:24:25 [01]        ...done
#首先完成ibdata1的拷貝，這是存放innodb引擎表的元數據信息
180525 09:24:25 [01] Copying ./mysql/plugin.ibd to /data/backup/2018-05-25_09-24-24/mysql/plugin.ibd
180525 09:24:25 [01]        ...done
#接著完成一堆ibd文件的拷貝，也就是innodb引擎表的數據和索引
180525 09:24:25 [01] Copying ./mysql/servers.ibd to /data/backup/2018-05-25_09-24-24/mysql/servers.ibd
180525 09:24:25 [01]        ...done
.....省略部分輸出......
180525 09:24:25 [01] Copying ./db1/tb1.ibd to /data/backup/2018-05-25_09-24-24/db1/tb1.ibd
180525 09:24:25 [01]        ...done
180525 09:24:25 >> log scanned up to (2643241)
#日志掃描到2643241
180525 09:24:26 Executing FLUSH NO_WRITE_TO_BINLOG TABLES...
#執行刷新表的語句，作用是關閉所有打開的表，但是不記錄到二進制日志里面
180525 09:24:26 Executing FLUSH TABLES WITH READ LOCK...
#執行FTWRL操作，對整個實例施加只讀鎖，只能讀，不能寫
#實際他做的是關閉所有表，使用全局讀鎖來鎖定所有數據庫的所有表。
180525 09:24:26 Starting to backup non-InnoDB tables and files
#開始備份非innodb引擎表和文件，這里主要是為了備份mysql庫，sys庫和performance_schema庫，因為該庫下的表都是myisam引擎表
#Performance Schema 收集數據庫服務器性能參數，并且表的存儲引擎均為PERFORMANCE_SCHEMA
180525 09:24:26 [01] Copying ./mysql/db.opt to /data/backup/2018-05-25_09-24-24/mysql/db.opt
180525 09:24:26 [01]        ...done
.....省略部分輸出......
180525 09:24:26 [01] Copying ./performance_schema/session_status.frm to /data/backup/2018-05-25_09-24-24/performance_schema/session_status.frm
180525 09:24:26 [01]        ...done
180525 09:24:26 Finished backing up non-InnoDB tables and files
#完成非innodb引擎表和文件的備份
180525 09:24:26 [00] Writing /data/backup/2018-05-25_09-24-24/xtrabackup_binlog_info
#往xtrabackup_binlog_info寫入信息，也就是GTID執行過的值和binlog的位點信息
180525 09:24:26 [00]        ...done
180525 09:24:26 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
#執行FEL，但不記錄到二進制日志
#為已安裝的存儲引擎關閉和重新打開任何可刷新的日志。這是因為，InnoDB會把日志刷新到磁盤。
xtrabackup: The latest check point (for incremental): '2643232'
#有關自增的最后一個檢查點是2643232
xtrabackup: Stopping log copying thread.
#停止日志拷貝線程
.180525 09:24:26 >> log scanned up to (2643241)
#日志掃描到2643241字節
180525 09:24:26 Executing UNLOCK TABLES
#執行UNLOCK TABLES，也就是是否全局讀鎖
180525 09:24:26 All tables unlocked
#所有的表解鎖
180525 09:24:26 [00] Copying ib_buffer_pool to /data/backup/2018-05-25_09-24-24/ib_buffer_pool
180525 09:24:26 [00]        ...done
#拷貝內存中的數據到相應的備份文件中
180525 09:24:26 Backup created in directory '/data/backup/2018-05-25_09-24-24/'
#備份創建在/data/backup/2018-05-25_09-24-24/目錄里面
MySQL binlog position: filename 'mysql-bin.000012', position '194', GTID of the last change '81c310cb-5428-11e8-8c27-080027801684:1-21'
#打印出備份結束位點信息和執行過的GTID信息
180525 09:24:26 [00] Writing /data/backup/2018-05-25_09-24-24/backup-my.cnf
180525 09:24:26 [00]        ...done
#開始寫backup-my.cnf文件
180525 09:24:26 [00] Writing /data/backup/2018-05-25_09-24-24/xtrabackup_info
#開始寫xtrabackup_info文件
180525 09:24:26 [00]        ...done
xtrabackup: Transaction log of lsn (2643232) to (2643241) was copied.
#lsn編號從2643232到2643241的事務日志已經拷貝完成
180525 09:24:26 completed OK!

real    0m2.122s
user    0m0.177s
sys     0m0.261s

general log解讀

2018-05-26T06:31:22.661529Z         3 Connect   root@localhost on  using Socket
2018-05-26T06:31:22.662086Z         3 Query     SET SESSION wait_timeout=2147483
2018-05-26T06:31:22.662627Z         3 Query     SELECT CONCAT(@@hostname, @@port)
2018-05-26T06:31:22.666879Z         3 Quit
2018-05-26T06:31:22.667426Z         4 Connect   root@localhost on  using Socket
2018-05-26T06:31:22.667619Z         4 Query     SET SESSION wait_timeout=2147483
2018-05-26T06:31:22.667913Z         4 Query     SHOW VARIABLES
#查看MySQL服務器的環境變量狀態
2018-05-26T06:31:22.670727Z         4 Query     SHOW ENGINE INNODB STATUS
#查看InnoDB引擎狀態信息
2018-05-26T06:31:22.673329Z         4 Query     SELECT PLUGIN_NAME, PLUGIN_LIBRARY FROM information_schema.plugins WHERE PLUGIN_STATUS = 'ACTIVE' AND PLUGIN_TYPE = 'KEYRING'
#查看活躍的類型是KEYRING的插件
2018-05-26T06:31:22.674371Z         4 Query     SELECT
  CONCAT(table_schema, '/', table_name), engine
FROM information_schema.tables
WHERE engine NOT IN (
  'MyISAM', 'InnoDB', 'CSV', 'MRG_MYISAM'
)
AND table_schema NOT IN (
  'performance_schema', 'information_schema',  'mysql'
)
2018-05-26T06:31:23.984461Z         4 Query     SET SESSION lock_wait_timeout=31536000
2018-05-26T06:31:23.985374Z         4 Query     FLUSH NO_WRITE_TO_BINLOG TABLES
2018-05-26T06:31:23.989832Z         4 Query     FLUSH TABLES WITH READ LOCK
2018-05-26T06:31:24.392888Z         4 Query     SHOW MASTER STATUS
#獲取當前數據庫的位置
2018-05-26T06:31:24.393268Z         4 Query     SHOW VARIABLES
2018-05-26T06:31:24.396572Z         4 Query     FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS
#把日志刷到磁盤
2018-05-26T06:31:24.603445Z         4 Query     UNLOCK TABLES
2018-05-26T06:31:24.623980Z         4 Query     SELECT UUID()
2018-05-26T06:31:24.625019Z         4 Query     SELECT VERSION()
2018-05-26T06:31:24.835667Z         4 Quit

總結

第一階段：檢查與連接的準備階段
執行備份命令之后，備份開始，XtraBackup工具嘗試去連接MySQL服務器，連接成功之后，執行MySQL版本檢查，版本檢查完畢。使用給定的用戶、密碼、端口、socket文件連接使用5.7.22版本的MySQL服務器。

第二階段：持續拷貝redo log
這部分內容并沒有在備份的輸出日志里體現，推測通過開啟general log可以看到，也不一定，也許要通過源碼才能看到。
修正：我的測試備份環境是一個靜止的數據庫，在備份時，既沒有發生寫操作，也沒有發生讀操作。所以沒有看到一直在做"輸出看到大量log scanned up to (xxx)，對應就是持續掃描redo log"

第三階段：拷貝ibdata1和ibd文件
xtrabackup進程開始執行一系列工作
1、調用系統函數posix_fadvise()，該函數是用來清理緩存的，不太理解此處使用的意圖？了解的童鞋給我科普下，謝謝。
2、進入到/data/mysql/mysql3306/data目錄下面
3、把打開文件請求限制調整為65535
4、使用以下InnoDB配置：
innodb_data_home_dir = .
#innodb數據存放在當前目錄
innodb_data_file_path = ibdata1:100M:autoextend
#innodb共享表空間文件為1個，初始大小為100M，類型為自動擴展
innodb_log_group_home_dir = ./
#innodb日志文件存放在當前目錄
innodb_log_files_in_group = 3
#innodb日志文件個數為3個
innodb_log_file_size = 104857600
#innodb日志文件大小為100M
5、使用O_DIRECT標志，目的為繞過緩沖區高速緩存，直接把數據傳遞到文件或設備，實際就是無需緩存來拷貝數據
6、默認使用單線程進行備份
7、日志掃描到2643241字節的位置
8、形成一個表表空間的列表
9、為mysql/plugin分配表空間為2，舊的最大值是0
10、把ibdata1文件拷貝到備份目錄下面，直到完成
11、把ibd文件拷貝到備份目錄下面，直到所有的ibd文件拷貝完成

第四階段：備份非事務表的準備階段
innobackupex進程開始執行一系列工作
1、掃描日志文件到2643241，這是已經寫入redo的LSN
2、執行FLUSH TABLES，關閉所有打開的表，使用NO_WRITE_TO_BINLOG選項，也就是該語句不會被記錄到binlog里面
3、執行FTWRL，使用全局讀鎖來鎖定整個實例

第五階段：備份非事務表
開始拷貝非innodb引擎表和文件，包括所有的.frm文件等，直到所有的都拷貝完成
修正：
.frm文件：保存了每個表的元數據，包括表結構的定義等；
.ibd文件：InnoDB引擎開啟了獨立表空間(my.ini中配置innodb_file_per_table = 1)產生的存放該表的數據和索引的文件。

第六階段：整個備份完成后的后續工作
1、開始寫xtrabackup_binlog_info文件，此處推測，獲取執行過的GTID值和位點信息的語句在general log里面有記錄
2、執行引擎的日志刷新，也就是把日志刷新到磁盤
3、最后的檢查點是2643232字節的位置，也就是數據持久化到的LSN
4、停止拷貝線程
5、掃描日志文件到2643241
6、執行UNLOCK TABLES，釋放全局讀鎖
7、開始拷貝ib_buffer_pool，直到拷貝完成，這是一堆數字，不知道做什么用處，了解的童鞋給我科普下，謝謝。
修正：拷貝緩沖池里的數據，以備恢復后，可以快速加載和預熱訪問量最高的數據。
8、打印出備份結束的位點和執行過的GTID值
9、寫backup-my.cnf文件
10、寫xtrabckup_info
11、LSN從2643232到2643241的事務日志拷貝完成
12、打印備份成功的標志，completed OK!