[MDEV-21814] Mariabackup some times fails on rocksdb check Created: 2020-02-25  Updated: 2020-03-26

Status: Open
Project: MariaDB Server
Component/s: mariabackup
Affects Version/s: 10.2.25
Fix Version/s: 10.2

Type: Bug Priority: Major
Reporter: Michaël de groot Assignee: Vladislav Lesin
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Hi,

Some times my periodic mariabackup (version 10.2.25 running to MariaDB 10.2.25 with Galera enabled) fails on locks (despite --no-lock is specified) while checking if rocksdb is enabled:

2020-02-19-02:07:02 --> Executing mariabackup command: /usr/bin/mariabackup --backup --target-dir /var/backups/bgbackup/full-2020-02-19_02-07-02 --no-timestamp --user=dbbackup --password=XXX --no-lock
 
....... Backing up InnoDB tables ......
 
[01] 2020-02-19 04:26:22         ...done
 
[00] 2020-02-19 04:26:22 Finished backing up non-InnoDB tables and files
 
[01] 2020-02-19 04:26:22 Compressing aria_log.00000001 to /var/backups/bgbackup/full-2020-02-19_02-07-02/aria_log.00000001.qp
 
[01] 2020-02-19 04:26:22         ...done
 
[01] 2020-02-19 04:26:22 Compressing aria_log_control to /var/backups/bgbackup/full-2020-02-19_02-07-02/aria_log_control.qp
 
[01] 2020-02-19 04:26:22         ...done
 
2020-02-19  4:26:22 140217386776320 [Note] InnoDB: Read redo log up to LSN=2016430925312
 
[00] 2020-02-19 04:26:23 >> log scanned up to (2016431568742)
 
[00] 2020-02-19 04:26:24 >> log scanned up to (2016432525414)
 
[00] 2020-02-19 04:26:25 >> log scanned up to (2016433424698)
 
[00] 2020-02-19 04:26:26 >> log scanned up to (2016434376645)
 
[00] 2020-02-19 04:26:27 >> log scanned up to (2016435220867)
 
[00] 2020-02-19 04:26:28 >> log scanned up to (2016436060398)
 
[00] 2020-02-19 04:26:29 >> log scanned up to (2016436936893)
 
[00] 2020-02-19 04:26:30 >> log scanned up to (2016437801648)
 
[00] 2020-02-19 04:26:31 >> log scanned up to (2016438687214)
 
[00] 2020-02-19 04:26:32 >> log scanned up to (2016439448120)
 
[00] 2020-02-19 04:26:33 >> log scanned up to (2016440114769)
 
[00] 2020-02-19 04:26:34 >> log scanned up to (2016441083733)
 
[00] 2020-02-19 04:26:35 >> log scanned up to (2016441908647)
 
[00] 2020-02-19 04:26:36 >> log scanned up to (2016442817106)
 
2020-02-19  4:26:37 140217386776320 [Note] InnoDB: Read redo log up to LSN=2016442882560
 
[00] 2020-02-19 04:26:37 >> log scanned up to (2016443705180)
 
[00] 2020-02-19 04:26:38 >> log scanned up to (2016444633260)
 
[00] 2020-02-19 04:26:39 >> log scanned up to (2016445679399)
 
[00] 2020-02-19 04:26:40 >> log scanned up to (2016446255243)
 
[00] 2020-02-19 04:26:42 >> log scanned up to (2016447056979)
 
[00] 2020-02-19 04:26:43 >> log scanned up to (2016447777444)
 
[00] 2020-02-19 04:26:44 >> log scanned up to (2016448668415)
 
[00] 2020-02-19 04:26:45 >> log scanned up to (2016449560136)
 
[00] 2020-02-19 04:26:46 >> log scanned up to (2016450447574)
 
[00] 2020-02-19 04:26:47 >> log scanned up to (2016451497729)
 
[00] 2020-02-19 04:26:48 >> log scanned up to (2016452361362)
 
[00] 2020-02-19 04:26:49 >> log scanned up to (2016453171085)
 
[00] 2020-02-19 04:26:50 >> log scanned up to (2016454266108)
 
[00] 2020-02-19 04:26:51 >> log scanned up to (2016455140036)
 
2020-02-19  4:26:52 140217386776320 [Note] InnoDB: Read redo log up to LSN=2016455205376
 
[00] 2020-02-19 04:26:52 >> log scanned up to (2016455882648)
 
[00] FATAL ERROR: 2020-02-19 04:26:52 failed to execute query SELECT COUNT(*) FROM information_schema.plugins WHERE plugin_name='rocksdb': Lock wait timeout exceeded; try restarting transaction
 
2020-02-19-04:26:52 --> Disabling WSREP desync.
 
2020-02-19-04:27:42 --> Full backup FAILED

I don't know if this is a bug in the server or Mariabackup, I am surprised that a information_schema query on the plugins table is locked by another thread.

Thanks,
Michaël

 Comments   
Comment by Marko Mäkelä [ 2020-02-25 ]

michaeldg, which version is this? 10.4 introduced backup locks.

Comment by Michaël de groot [ 2020-02-25 ]

The MariaDB version is 10.2.25:
michael@server:~$ mariabackup --version
mariabackup based on MariaDB server 10.2.25-MariaDB debian-linux-gnu (x86_64)
michael@server:~$ mysqld --version
mysqld Ver 10.2.25-MariaDB-10.2.25+maria~xenial-log for debian-linux-gnu on x86_64 (mariadb.org binary distribution)

Are backup locks relevant for this case? I specify --no-lock so it should not take any locks at all.

Comment by Michaël de groot [ 2020-02-25 ]

Oh, probably worth to explicitly mention as well that this backup runs on a Galera cluster node. We set wsrep_desync while running the backup.

Comment by Marko Mäkelä [ 2020-02-25 ]

Thanks for the clarification! I believe that --no-lock is unsafe when there could be concurrent DDL operations. It would still be helpful if you could provide a self-contained test case. Can you repeat this without Galera?

Comment by Michaël de groot [ 2020-02-25 ]

The application does not perform DDL operations. But if it were, should this block an information_schema query? I think that points to the issue being more server or galera related then mariabackup.

The issue occurred 3 times now (January 9th for the first time), and always on the same query as you can find in the log here.

I don't know how to repeat this as it doesn't always occur. I will post updates here once I get to know more.

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