[MDEV-26904] During replication, MariaDB takes a long time in "Freeing items" with high CPU usage Created: 2021-10-26  Updated: 2021-10-26

Status: Open
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.4.7, 10.6.4
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Masayoshi Hasunuma Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None
Environment:

CentOS 7.8 / CPU core x2 , memory 4GB


Attachments: File insert_rows.pl     File repl_log.mariadb.20211025.tsv     File repl_log.mysql.20211025.tsv     Text File show_variables_master.txt     Text File show_variables_slave.txt    

 Description   

While performing 2 million simple INSERTs to a MyISAM table, the slave takes longer and longer time in "Slave_SQL_Running_State" (shown with "SHOW SLAVE STATUS") being "Freeing items", and it keeps using more than 100% CPU time. "Seconds_Behind_Master" also keeps increasing.

(CPU core x2 / memory 4GB)

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
23924 mysql     20   0 1050384 181388  13384 S 125.9  4.5   7:03.56 /usr/sbin/mariadbd

After finishing INSERTs, CPU usage stays near 100% for a while.

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
23924 mysql     20   0 1115920 257156  13384 S 100.3  6.4  21:22.96 /usr/sbin/mariadbd

When "Exec_Master_Log_Pos" catches up with "Read_Master_Log_Pos", "Seconds_Behind_Master" quickly decreases to 0.

We did a test with the attached script "insert_rows.pl" which performs 2 million INSERTs. We tested MariaDB 10.6.4 as well as MySQL 8.0.26. The following attached TSV files are records of "Exec_Master_Log_Pos", "Seconds_Behind_Master", and "Slave_SQL_Running_State" from "SHOW SLAVE STATUS", taken once every one second while performing INSERTs:

  • repl_log.mariadb.20211025.tsv
  • repl_log.mysql.20211025.tsv

On MariaDB, the time the slave being in "Freeing items" gets longer over time after starting INSERTs, and "Seconds_Behind_Master" also increases. It keeps increasing even after finishing INSERTs.

On MySQL, the slave takes only a little time in "Freeing items", and "Seconds_Behind_Master" doesn't get too large. It also drops to 0 as soon as INSERTs finish.

Here is what the script shows on terminal:

--- MariaDB/10.6.4
 
$ ./insert_rows.pl 2000000
10000
20000
30000
  :
1980000
1990000
2000000
START:Mon Oct 25 15:41:00 2021
END:Mon Oct 25 15:45:44 2021
(elapsed: 283.665183 sec)
 
 
--- MySQL/8.0.26
 
$ ./insert_rows.pl 2000000
10000
20000
30000
  :
1980000
1990000
2000000
START:Mon Oct 25 15:41:00 2021
END:Mon Oct 25 15:46:54 2021
(elapsed: 354.114572 sec)


Generated at Thu Feb 08 09:48:50 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.