In our last post, we talked about how to check the storage engine of a table in MySQL. Toaday, let's see how to obtain the start and end time of mysql binlogs.
When restoring a MySQL database to a specific point in time, we need to use a combination of a MySQL full backup, optional incremental backups, and MySQL binary logs (binlogs) to replay changes up to the desired time. In a production environment, multiple binlog files may be generated over a given period. MySQL does not store the start and end time of binlog files, so to restore to a specific time point, we must know which binlog files to replay. Therefore, it’s necessary to determine the start and end times of the binlog files. Here are some methods to achieve this:
Method 1: Obtaining Binlog Start and End Time from the xtrabackup_info File
When restoring a full or incremental backup with Xtrabackup, an xtrabackup_info file is generated, as shown below:
$ more xtrabackup_info uuid = 3bd8a0f7-ea2f-11ed-9896-00505697b437 name = tool_name = xtrabackup tool_command = --defaults-file=/data/conf/my.cnf --login-path=**** --backup --target-dir=/db_backup/mysql_backup/db_backup/backup_cycle_2023_04_30/full_backup_2023_05_04_11_53_25 tool_version = 8.0.31-24 ibbackup_version = 8.0.31-24 server_version = 8.0.31 start_time = 2023-05-04 11:53:26 end_time = 2023-05-04 11:53:30 lock_time = 0 binlog_pos = filename 'mysql_binlog.000042', position '289', GTID of the last change 'd01ecb4f-c944-11ed-9896-00505697b437:1-111:100 0108-1953894,d01edb91-c944-11ed-9896-00505697b437:1-5,f8ef839e-c942-11ed-9bd2-00505697b437:1-13' innodb_from_lsn = 0 innodb_to_lsn = 824007891 partial = N incremental = N format = file compressed = N encrypted = N
As shown, you can see a line with binlog_pos information. The binlog filename is mysql_binlog.000042, with a starting position of 289. This indicates that we can start applying MySQL binlogs from this file.
mysqlbinlog --start-position="289" ./mysql_binlog.000042 > restore.sql
However, this method is limited and can only passively retrieve the binlog filename and start position needed for replay. This is for reference only.
Method 2: Parsing Binlog Start and End Time with mysqlbinlog
For example, we want to know when mysql_binlog.000042 was created and finished. MySQL binary logs contain this information, as shown below:
$ mysqlbinlog mysql_binlog.000042 | head -10 # The proper term is pseudo_replica_mode, but we use this compatibility alias # to make the statement usable on server versions 8.0.24 and older. /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #230504 11:53:30 server id 1 end_log_pos 126 Start: binlog v 4, server v 8.0.31 created 230504 11:53:30 BINLOG ' OixTZA8BAAAAegAAAH4AAAAAAAQAOC4wLjMxAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEwANAAgAAAAABAAEAAAAYgAEGggAAAAICAgCAAAACgoKKioAEjQA
We can retrieve the start time of the MySQL binlog by looking for the Start: binlog line, as follows:
$ mysqlbinlog mysql_binlog.000042 |grep "Start: binlog"
#230504 11:53:30 server id 1 end_log_pos 126 Start: binlog v 4, server v 8.0.31 created 230504 11:53:30
$ mysqlbinlog mysql_binlog.000042 |grep "Start: binlog" | awk -F "server id" '{print $1}'
#230504 11:53:30
In this example, the creation time of mysql_binlog.000042 is 230504 11:53:30. The year is abbreviated, so 230504 represents 2023-05-04.
To obtain the binlog’s end time, you need to consider whether the binlog ended normally in a cycle or due to an instance shutdown, as these scenarios provide different information.
STOP_EVENT A STOP_EVENT has not payload or post-header ROTATE_EVENT The rotate event is added to the binlog as last event to tell the reader what binlog to request next.
As shown:
$ mysqlbinlog mysql_binlog.000042 | tail -10 # at 533 #230504 12:13:35 server id 3 end_log_pos 560 Xid = 50948183 COMMIT/*!*/; # at 560 #230504 12:14:03 server id 1 end_log_pos 606 Rotate to mysql_binlog.000043 pos: 4 SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/; DELIMITER ; # End of log file /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
$ mysqlbinlog mysql_binlog.000042 |grep Rotate
#230504 12:14:03 server id 1 end_log_pos 606 Rotate to mysql_binlog.000043 pos: 4
$ mysqlbinlog mysql_binlog.000042 |grep Rotate | awk -F "server id" '{print $1}'
#230504 12:14:03
If MySQL shuts down, the corresponding binlog format appears as follows:
$ mysqlbinlog mysql_binlog.000045 | tail -10 # at 126 #230504 17:02:23 server id 10 end_log_pos 157 CRC32 0x2d378ba5 Previous-GTIDs # [empty] # at 157 #230504 17:08:11 server id 10 end_log_pos 180 CRC32 0xb6b08f2c Stop SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/; DELIMITER ; # End of log file /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
$ mysqlbinlog mysql_binlog.000045 | grep Stop | awk -F "server id" '{print $1}'
Method 3: Using the stat Command to Check Creation Time
On Linux, you can use the stat command to view the creation time of the file, as shown below:
$ stat mysql_binlog.000042 File: mysql_binlog.000042 Size: 606 Blocks: 8 IO Block: 4096 regular file Device: fd08h/64776d Inode: 100663444 Links: 1 Access: (0640/-rw-r-----) Uid: ( 801/ mysql) Gid: ( 800/ mysql) Access: 2023-05-04 13:36:54.872910222 +0800 Modify: 2023-05-04 12:14:18.712310369 +0800 Change: 2023-05-04 12:14:18.712310369 +0800 Birth: 2023-05-04 11:53:30.640989646 +0800
From the Birth field, we see that mysql_binlog.000042 was created on 2023-05-04 at 11:53:30. However, this method does not provide the binlog’s end time. Since MySQL binlog files are numbered sequentially, you can use the start time of the next binlog file to approximate the end time of the previous binlog file.
$ stat mysql_binlog.000043 File: mysql_binlog.000043 Size: 335 Blocks: 8 IO Block: 4096 regular file Device: fd08h/64776d Inode: 100663430 Links: 1 Access: (0640/-rw-r-----) Uid: ( 801/ mysql) Gid: ( 800/ mysql) Access: 2023-05-04 13:36:58.524978710 +0800 Modify: 2023-05-04 16:55:07.161545830 +0800 Change: 2023-05-04 16:55:07.161545830 +0800 Birth: 2023-05-04 12:14:18.713310387 +0800
