Sample Header Ad - 728x90

When does xtrabackup take lock exactly and why there's slave lag after backup starts?

0 votes
0 answers
35 views
MySQL Version -- MySQL Community Server 5.7.44 Percona xtrabackup Version 2.4.29 (x86_64) I want to understand when does xtrabackup exactly take the FLUSH TABLES WITH READ LOCK. Following is the simplified command I use for full backup. /usr/bin/xtrabackup --defaults-file=/etc/my.cnf --backup --slave-info --login-path=bkp_user --tmpdir=/pfg_prod/tmp --parallel=4 --use-memory=1024M 2> bkp.log --stream=xbstream | /usr/bin/lz4 stdin /bkp_dir/date.lz4 I use this same command on all my slave servers for daily backups. When I check the xtrabackup logs, I notice that it does not immediately take FTWRL but the slave lag begins to grow. Log for the 9th 250309 11:13:18 Executing FLUSH TABLES WITH READ LOCK... 250309 11:13:32 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS... 250309 11:13:32 Executing UNLOCK TABLES Log for the 10th 250310 11:13:55 Executing FLUSH TABLES WITH READ LOCK... 250310 11:14:05 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS... 250310 11:14:05 Executing UNLOCK TABLES Log for the 15th 250315 11:21:17 Executing FLUSH TABLES WITH READ LOCK... 250315 11:21:18 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS... 250315 11:21:18 Executing UNLOCK TABLES ***The backup starts at 08:00 AM every morning.*** Thus, if it starts the backup at 08:00 AM and executes the FTWRL at around after 11:00 AM, I want to understand why there's slave lag immediately after the backup starts and the lag continues till the backup is over. ***I want to understand when does xtrabackup exactly take the FLUSH TABLES WITH READ LOCK if not at the start of the backup? and why there's slave lag as soon as the backup starts, because if the FTWRL is taken after approximately 3 hours, I think there shouldn't be lag before that, I am not sure though. The slave lag is only during the backup window.*** I had been assuming so far that FTWRL is taken when the backup starts, hence the doubt. root@localhost 09:45:21 [(none)] show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: master_ip Master_User: repl Master_Port: 3306 Connect_Retry: 60 Master_Log_File: binlog.000982 Read_Master_Log_Pos: 30958 Relay_Log_File: relay.000430 Relay_Log_Pos: 1058083259 Relay_Master_Log_File: binlog.000981 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 10580 Relay_Log_Space: 1383 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 5872 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 103454371 Master_UUID: UUID Master_Info_File: mysql.slave_master_info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: System lock Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: GTID-SET Executed_Gtid_Set: GTID-SETS Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: 1 row in set (0.25 sec) +-------+-------------------+---------------------+-------------------+-------------+--------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +-------+-------------------+---------------------+-------------------+-------------+--------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+ | | 13 | system user | | NULL | Connect | 255661 | Waiting for master to send event | NULL | | 14 | system user | | NULL | Connect | 0 | Waiting for dependent transaction to commit | NULL | | 15 | system user | | NULL | Connect | 5931 | System lock | NULL | | 16 | system user | | NULL | Connect | 5931 | Waiting for an event from Coordinator | NULL | | 12664 | bkp_user | localhost | NULL | Sleep | 6377 | | NULL | | | 12989 | root | localhost | NULL | Query | 0 | starting | show processlist | | 12990 | prome | 127.0.0.1:43240 | NULL | Query | 0 | Opening tables | SELECT table_schema, table_name, column_name, auto_increment, pow(2, case data_type when ' | +-------+-------------------+---------------------+-------------------+-------------+--------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+
Asked by Avinash Pawar (216 rep)
Mar 16, 2025, 09:37 AM
Last activity: Mar 17, 2025, 02:24 AM