[MDEV-23876]  event_scheduler acquires Backup lock and does not release upon completion Created: 2020-10-02  Updated: 2021-05-02  Resolved: 2021-04-06

Status: Closed
Project: MariaDB Server
Component/s: Backup, Events
Affects Version/s: 10.5.4
Fix Version/s: 10.5.9

Type: Bug Priority: Critical
Reporter: Muhammad Irfan Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Problem/Incident
Relates
relates to MDEV-24552 ALTER causes discrepancy in FK inform... Open

 Description   

We enable "read_only=1" part of shutdown process for MariaDB Server but it's being blocked by backup lock. 

mysql [localhost:10504] {msandbox} (test) > create table emp (id int, name varchar(50), hiredate date, primary key(id));
 
Query OK, 0 rows affected (0.015 sec)
 
mysql [localhost:10504] {msandbox} (test) > create table emp_view (id int, name varchar(50), hiredate date, primary key(id));
 
Query OK, 0 rows affected (0.007 sec)
 
mysql [localhost:10504] {msandbox} (test) > insert into emp values(1, 'Muhammad', CURDATE());
 
Query OK, 1 row affected (0.005 sec)
 
mysql [localhost:10504] {msandbox} (test) > 
mysql [localhost:10504] {msandbox} (test) > delimiter //
 
mysql [localhost:10504] {msandbox} (test) > create procedure update_emp_report()
 
    -> BEGIN
 
    ->   TRUNCATE TABLE `emp_view`;
 
    ->   INSERT INTO `emp_view` SELECT * FROM emp;
 
    -> END
 
    -> //
 
Query OK, 0 rows affected (0.003 sec)
 
mysql [localhost:10504] {msandbox} (test) > delimiter ;
 
mysql [localhost:10504] {msandbox} (test) > 
mysql [localhost:10504] {msandbox} (test) > CREATE EVENT `update_emp_report_every_2_minutes` ON SCHEDULE EVERY 2 MINUTE STARTS '2020-10-01 00:00:00' ON COMPLETION NOT PRESERVE ENABLE DO CALL update_emp_report();
 
Query OK, 0 rows affected, 1 warning (0.001 sec)
 
 
 
mysql [localhost:10504] {msandbox} (test) > show tables;
 
+----------------+
 
| Tables_in_test |
 
+----------------+
 
| emp            |
 
| emp_view       |
 
+----------------+
 
2 rows in set (0.000 sec)
 
mysql [localhost:10504] {msandbox} ((none)) > select * from  information_schema.metadata_lock_info\G
 
*************************** 1. row ***************************
 
    THREAD_ID: 4
 
    LOCK_MODE: MDL_BACKUP_SYS_DML
 
LOCK_DURATION: NULL
 
    LOCK_TYPE: Backup lock
 
 TABLE_SCHEMA: 
   TABLE_NAME: 
*************************** 2. row ***************************
 
    THREAD_ID: 4
 
    LOCK_MODE: MDL_SHARED_WRITE
 
LOCK_DURATION: NULL
 
    LOCK_TYPE: Table metadata lock
 
 TABLE_SCHEMA: mysql
 
   TABLE_NAME: event
 
2 rows in set (0.000 sec)
 
mysql [localhost:10504] {msandbox} ((none)) > SELECT * FROM performance_schema.metadata_locks\G
 
*************************** 1. row ***************************
 
          OBJECT_TYPE: TABLE
 
        OBJECT_SCHEMA: mysql
 
          OBJECT_NAME: event
 
OBJECT_INSTANCE_BEGIN: 139879098948320
 
            LOCK_TYPE: SHARED_WRITE
 
        LOCK_DURATION: TRANSACTION
 
          LOCK_STATUS: GRANTED
 
               SOURCE: 
      OWNER_THREAD_ID: 28
 
       OWNER_EVENT_ID: 1
 
*************************** 2. row ***************************
 
          OBJECT_TYPE: BACKUP
 
        OBJECT_SCHEMA: NULL
 
          OBJECT_NAME: NULL
 
OBJECT_INSTANCE_BEGIN: 139879098948400
 
            LOCK_TYPE: BACKUP_SYS_DML
 
        LOCK_DURATION: STATEMENT
 
          LOCK_STATUS: GRANTED
 
               SOURCE: 
      OWNER_THREAD_ID: 28
 
       OWNER_EVENT_ID: 1
 
*************************** 3. row ***************************
 
          OBJECT_TYPE: TABLE
 
        OBJECT_SCHEMA: performance_schema
 
          OBJECT_NAME: metadata_locks
 
OBJECT_INSTANCE_BEGIN: 139878900194512
 
            LOCK_TYPE: SHARED_READ
 
        LOCK_DURATION: TRANSACTION
 
          LOCK_STATUS: GRANTED
 
               SOURCE: 
      OWNER_THREAD_ID: 29
 
       OWNER_EVENT_ID: 1
 
3 rows in set (0.000 sec)
 
mysql [localhost:10504] {msandbox} ((none)) > SELECT OBJECT_TYPE, OBJECT_SCHEMA, OBJECT_NAME, LOCK_TYPE, LOCK_STATUS, THREAD_ID, PROCESSLIST_ID, PROCESSLIST_INFO FROM performance_schema.metadata_locks INNER JOIN performance_schema.threads ON THREAD_ID = OWNER_THREAD_ID WHERE PROCESSLIST_ID <> CONNECTION_ID()\G
 
*************************** 1. row ***************************
 
     OBJECT_TYPE: TABLE
 
   OBJECT_SCHEMA: mysql
 
     OBJECT_NAME: event
 
       LOCK_TYPE: SHARED_WRITE
 
     LOCK_STATUS: GRANTED
 
       THREAD_ID: 28
 
  PROCESSLIST_ID: 4
 
PROCESSLIST_INFO: NULL
 
*************************** 2. row ***************************
 
     OBJECT_TYPE: BACKUP
 
   OBJECT_SCHEMA: NULL
 
     OBJECT_NAME: NULL
 
       LOCK_TYPE: BACKUP_SYS_DML
 
     LOCK_STATUS: GRANTED
 
       THREAD_ID: 28
 
  PROCESSLIST_ID: 4
 
PROCESSLIST_INFO: NULL
 
2 rows in set (0.000 sec)
 
mysql [localhost:10504] {msandbox} ((none)) > SET GLOBAL read_only = ON;
 
<hanged>
 
mysql [localhost:10504] {msandbox} ((none)) > show full processlist\G
 
*************************** 1. row ***************************
 
      Id: 4
 
    User: event_scheduler
 
    Host: localhost
 
      db: NULL
 
 Command: Daemon
 
    Time: 3835
 
   State: Waiting for next activation
 
    Info: NULL
 
Progress: 0.000
 
*************************** 2. row ***************************
 
      Id: 37
 
    User: msandbox
 
    Host: localhost
 
      db: NULL
 
 Command: Query
 
    Time: 18
 
   State: Waiting for backup lock
 
    Info: SET GLOBAL read_only = ON
 
Progress: 0.000
 
*************************** 3. row ***************************
 
      Id: 39
 
    User: msandbox
 
    Host: localhost
 
      db: NULL
 
 Command: Query
 
    Time: 0
 
   State: starting
 
    Info: show full processlist
 
Progress: 0.000
 
3 rows in set (0.000 sec)

"Backup lock" was acquired during the event execution so it should be released once event execution completes.
I didn't notice backup lock issue with earlier version at least I tested on 10.3

 Comments   
Comment by Elena Stepanova [ 2020-10-16 ]

Below is an MTR-friendly version of the exactly the same test case as in the description, only without the STARTS clause, to speed up the first execution of the event. 

INSTALL SONAME 'metadata_lock_info';
 
SET GLOBAL event_scheduler= ON;
 
 
 
create table emp (id int, name varchar(50), hiredate date, primary key(id));
 
create table emp_view (id int, name varchar(50), hiredate date, primary key(id));
 
insert into emp values(1, 'Muhammad', CURDATE());
 
--delimiter //
 
create procedure update_emp_report()
 
BEGIN
 
TRUNCATE TABLE `emp_view`;
 
INSERT INTO `emp_view` SELECT * FROM emp;
 
END //
 
--delimiter ;
 
CREATE EVENT `update_emp_report_every_2_minutes` ON SCHEDULE EVERY 2 MINUTE ON COMPLETION NOT PRESERVE ENABLE DO CALL update_emp_report();
 
--sleep 1
 
show status like 'Executed_events';
 
select * from  information_schema.metadata_lock_info;

The result seems to be reliably reproducible for me on 10.5:

10.5 9028cc6b

 
show status like 'Executed_events';
 
Variable_name	Value
 
Executed_events	1
 
select * from  information_schema.metadata_lock_info;
 
THREAD_ID	LOCK_MODE	LOCK_DURATION	LOCK_TYPE	TABLE_SCHEMA	TABLE_NAME
 
5	MDL_BACKUP_SYS_DML	NULL	Backup lock		
5	MDL_SHARED_WRITE	NULL	Table metadata lock	mysql	event

It couldn't have happened on 10.3 MariaDB community server, as it doesn't have backup locks, but indeed, it's not reproducible on 10.4 either, only on 10.5.

Comment by Elena Stepanova [ 2021-04-06 ]

It was fixed in 10.5.9 in the scope of MDEV-24452 by the same commit.

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