Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-23876

event_scheduler acquires Backup lock and does not release upon completion

Details

    • Bug
    • Status: Closed (View Workflow)
    • Critical
    • Resolution: Fixed
    • 10.5.4
    • 10.5.9
    • Backup, Events
    • None

    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

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-24552 ALTER causes discrepancy in FK information between server and engine, unexpected ER_CANNOT_ADD_FOREIGN

          • Major - Major loss of function.
          • Open

          Activity

            Ascending order - Click to sort in descending order
            elenst Elena Stepanova added a comment - - edited

            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.

            elenst Elena Stepanova added a comment - - edited 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.
            elenst Elena Stepanova added a comment -

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

            elenst Elena Stepanova added a comment - It was fixed in 10.5.9 in the scope of MDEV-24452 by the same commit.

            People

              monty Michael Widenius
              muhammad.irfan Muhammad Irfan
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.