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

BACKUP STAGE BLOCK_DDL hangs on flush sequence table

Details

    Description

      BACKUP STAGE BLOCK_DDL hangs with the following test case:

      --source include/have_innodb.inc
      --connect(con1,localhost,root,,)
      --connection default
       
      --let $i=10000
      CREATE SEQUENCE s START WITH 100 INCREMENT BY 10;
      ALTER TABLE s ENGINE=InnoDB;
       
       
      while($i) {
      SELECT NEXTVAL(s);
      SELECT NEXTVAL(s);
       
      --connection con1
      BACKUP STAGE START;
      BACKUP STAGE FLUSH;
      --connection default
      --send ALTER SEQUENCE IF EXISTS s INCREMENT = 9 MAXVALUE 4735816483156787200 MINVALUE 90;
      --connection con1
      BACKUP STAGE BLOCK_DDL;
      BACKUP STAGE BLOCK_COMMIT;
      BACKUP STAGE END;
      --connection default
      --reap
      --dec $i
      }
      

      The backtrace:

      Thread 28 (Thread 0x7fa86ddad700 (LWP 1521)):
      #0  0x00007fa8780d6f85 in futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7fa86ddaaec0, expected=0, futex_word=0x7fa814000f6c) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
      #1  __pthread_cond_wait_common (abstime=0x7fa86ddaaec0, mutex=0x7fa814000eb8, cond=0x7fa814000f40) at pthread_cond_wait.c:539
      #2  __pthread_cond_timedwait (cond=0x7fa814000f40, mutex=0x7fa814000eb8, abstime=0x7fa86ddaaec0) at pthread_cond_wait.c:667
      #3  0x000055f66a1dbb86 in safe_cond_timedwait (cond=0x7fa814000f40, mp=0x7fa814000e90, abstime=0x7fa86ddaaec0, 
          file=0x55f66a2e9f00 "./include/mysql/psi/mysql_thread.h", line=1215) at ./mysys/thr_mutex.c:546
      #4  0x000055f6698ad6e6 in inline_mysql_cond_timedwait (that=0x7fa814000f40, mutex=0x7fa814000e90, abstime=0x7fa86ddaaec0)
          at ./include/mysql/psi/mysql_thread.h:1215
      #5  0x000055f6698ae919 in MDL_wait::timed_wait (this=0x7fa814000e90, owner=0x7fa814000e40, abs_timeout=0x7fa86ddaaec0, set_status_on_timeout=false, 
          wait_state_name=0x55f66acfe1b0 <MDL_key::m_namespace_to_wait_state_name+48>) at ./sql/mdl.cc:1147
      #6  0x000055f6698b057a in MDL_context::acquire_lock (this=0x7fa814000e90, mdl_request=0x7fa86ddab010, lock_wait_timeout=86400) at ./sql/mdl.cc:2325
      #7  0x000055f6698b0a15 in MDL_context::acquire_locks (this=0x7fa814000e90, mdl_requests=0x7fa86ddaafe0, lock_wait_timeout=86400) at ./sql/mdl.cc:2447
      #8  0x000055f66995a603 in SEQUENCE::read_initial_values (this=0x7fa820166ef8, table=0x7fa8140511c0) at ./sql/sql_sequence.cc:460
      #9  0x000055f66a1a5900 in ha_sequence::open (this=0x7fa8140532b8, name=0x7fa8200d6210 "./test/s", mode=2, flags=8194) at ./sql/ha_sequence.cc:114
      #10 0x000055f669a66d8a in handler::ha_open (this=0x7fa8140532b8, table_arg=0x7fa8140511c0, name=0x7fa8200d6210 "./test/s", mode=2, test_if_locked=8194, mem_root=0x0, partitions_to_open=0x0)
          at ./sql/handler.cc:2688
      #11 0x000055f66984da1d in open_table_from_share (thd=0x7fa814000d70, share=0x7fa8200d5c88, alias=0x55f66abb16c0 <empty_clex_str>, db_stat=1, prgflag=0, ha_open_flags=8194, outparam=0x7fa8140511c0, 
          is_create_table=false, partitions_to_open=0x0) at ./sql/table.cc:3878
      #12 0x000055f6696925f3 in flush_tables (thd=0x7fa814000d70, flag=FLUSH_NON_TRANS_TABLES) at ./sql/sql_base.cc:574
      #13 0x000055f6699a18af in backup_block_ddl (thd=0x7fa814000d70) at ./sql/backup.cc:255
      #14 0x000055f6699a1462 in run_backup_stage (thd=0x7fa814000d70, stage=BACKUP_WAIT_FOR_FLUSH) at ./sql/backup.cc:113
      #15 0x000055f669734e5a in mysql_execute_command (thd=0x7fa814000d70) at ./sql/sql_parse.cc:5298
      #16 0x000055f66973ec79 in mysql_parse (thd=0x7fa814000d70, rawbuf=0x7fa814012098 "BACKUP STAGE BLOCK_DDL", length=22, parser_state=0x7fa86ddac180, is_com_multi=false, is_next_command=false)
          at ./sql/sql_parse.cc:8163
      #17 0x000055f66972a4dd in dispatch_command (command=COM_QUERY, thd=0x7fa814000d70, packet=0x7fa8140087b1 "BACKUP STAGE BLOCK_DDL", packet_length=22, is_com_multi=false, is_next_command=false)
          at ./sql/sql_parse.cc:1828
      #18 0x000055f669728d11 in do_command (thd=0x7fa814000d70) at ./sql/sql_parse.cc:1361
      #19 0x000055f6698a236d in do_handle_one_connection (connect=0x55f66cd51b90, put_in_cache=true) at ./sql/sql_connect.cc:1413
      #20 0x000055f6698a20b2 in handle_one_connection (arg=0x55f66cd51b90) at ./sql/sql_connect.cc:1309
      #21 0x00007fa8780d06db in start_thread (arg=0x7fa86ddad700) at pthread_create.c:463
      #22 0x00007fa8772b688f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
       
      Thread 27 (Thread 0x7fa86ddf8700 (LWP 1518)):
      #0  0x00007fa8780d5938 in futex_abstimed_wait (private=<optimized out>, abstime=0x0, expected=3, futex_word=0x7fa820166f64) at ../sysdeps/unix/sysv/linux/futex-internal.h:172
      #1  __pthread_rwlock_wrlock_full (abstime=0x0, rwlock=0x7fa820166f58) at pthread_rwlock_common.c:706
      #2  __GI___pthread_rwlock_wrlock (rwlock=0x7fa820166f58) at pthread_rwlock_wrlock.c:27
      #3  0x000055f6699591a7 in inline_mysql_rwlock_wrlock (that=0x7fa820166f58) at ./include/mysql/psi/mysql_thread.h:964
      #4  0x000055f66995a367 in SEQUENCE::write_lock (this=0x7fa820166ef8, table=0x7fa8200bb280) at ./sql/sql_sequence.cc:401
      #5  0x000055f66995a4d2 in SEQUENCE::read_initial_values (this=0x7fa820166ef8, table=0x7fa8200bb280) at ./sql/sql_sequence.cc:434
      #6  0x000055f66a1a5900 in ha_sequence::open (this=0x7fa820109f28, name=0x7fa8200d6210 "./test/s", mode=2, flags=18) at ./sql/ha_sequence.cc:114
      #7  0x000055f669a66d8a in handler::ha_open (this=0x7fa820109f28, table_arg=0x7fa8200bb280, name=0x7fa8200d6210 "./test/s", mode=2, test_if_locked=18, mem_root=0x0, partitions_to_open=0x0)
          at ./sql/handler.cc:2688
      #8  0x000055f66984da1d in open_table_from_share (thd=0x7fa820000d70, share=0x7fa8200d5c88, alias=0x7fa820013438, db_stat=33, prgflag=8, ha_open_flags=18, outparam=0x7fa8200bb280, is_create_table=false, 
          partitions_to_open=0x0) at ./sql/table.cc:3878
      #9  0x000055f669695485 in open_table (thd=0x7fa820000d70, table_list=0x7fa8200133f0, ot_ctx=0x7fa86ddf6150) at ./sql/sql_base.cc:2043
      #10 0x000055f66969891f in open_and_process_table (thd=0x7fa820000d70, tables=0x7fa8200133f0, counter=0x7fa86ddf6234, flags=0, prelocking_strategy=0x7fa86ddf62b8, has_prelocking_list=false, 
          ot_ctx=0x7fa86ddf6150) at ./sql/sql_base.cc:3802
      #11 0x000055f669699c99 in open_tables (thd=0x7fa820000d70, options=..., start=0x7fa86ddf6218, counter=0x7fa86ddf6234, sroutine_to_open_list=0x7fa820004ad0, flags=0, prelocking_strategy=0x7fa86ddf62b8)
          at ./sql/sql_base.cc:4301
      #12 0x000055f669691229 in open_tables (thd=0x7fa820000d70, options=..., tables=0x7fa86ddf6218, counter=0x7fa86ddf6234, flags=0, prelocking_strategy=0x7fa86ddf62b8)
          at ./sql/sql_base.h:260
      #13 0x000055f66969ba79 in open_and_lock_tables (thd=0x7fa820000d70, options=..., tables=0x7fa8200133f0, derived=false, flags=0, prelocking_strategy=0x7fa86ddf62b8)
          at ./sql/sql_base.cc:5185
      ---Type <return> to continue, or q <return> to quit---
      #14 0x000055f669658ca4 in open_and_lock_tables (thd=0x7fa820000d70, tables=0x7fa8200133f0, derived=false, flags=0) at ./sql/sql_base.h:513
      #15 0x000055f66995b7eb in Sql_cmd_alter_sequence::execute (this=0x7fa820013ac8, thd=0x7fa820000d70) at ./sql/sql_sequence.cc:894
      #16 0x000055f669739a6c in mysql_execute_command (thd=0x7fa820000d70) at ./sql/sql_parse.cc:6354
      #17 0x000055f66973ec79 in mysql_parse (thd=0x7fa820000d70, rawbuf=0x7fa820013248 "ALTER SEQUENCE IF EXISTS s INCREMENT = 9 MAXVALUE 4735816483156787200 MINVALUE 90", length=81, parser_state=0x7fa86ddf7180, 
          is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:8163
      #18 0x000055f66972a4dd in dispatch_command (command=COM_QUERY, thd=0x7fa820000d70, packet=0x7fa82010e6c1 "ALTER SEQUENCE IF EXISTS s INCREMENT = 9 MAXVALUE 4735816483156787200 MINVALUE 90;", packet_length=82, 
          is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:1828
      #19 0x000055f669728d11 in do_command (thd=0x7fa820000d70) at ./sql/sql_parse.cc:1361
      #20 0x000055f6698a236d in do_handle_one_connection (connect=0x55f66cd5f710, put_in_cache=true) at ./sql/sql_connect.cc:1413
      #21 0x000055f6698a20b2 in handle_one_connection (arg=0x55f66cd29910) at ./sql/sql_connect.cc:1309
      #22 0x00007fa8780d06db in start_thread (arg=0x7fa86ddf8700) at pthread_create.c:463
      #23 0x00007fa8772b688f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Attachments

        Activity

          I have run MDEV-19745 BACKUP STAGE BLOCK_DDL hangs on flush sequence table 4 times and no problems with 10.4 and 10.5

          The lock requested is MDL_SHARED_READ, MDL_EXPLICIT at sql_sequence.cc:460
          I can't see anything in Sql_cmd_alter_sequence::execute that could conflict with that lock.
          If you get this problem again, please provide a full back trace for all threads so that we can see where the ALTER SEQUENCE thread is stuck.

          monty Michael Widenius added a comment - I have run MDEV-19745 BACKUP STAGE BLOCK_DDL hangs on flush sequence table 4 times and no problems with 10.4 and 10.5 The lock requested is MDL_SHARED_READ, MDL_EXPLICIT at sql_sequence.cc:460 I can't see anything in Sql_cmd_alter_sequence::execute that could conflict with that lock. If you get this problem again, please provide a full back trace for all threads so that we can see where the ALTER SEQUENCE thread is stuck.

          It is reproducible readily for me with Vlad's test case.
          Two consequent full all thread stack traces from 10.5 a6946c55 are attached (from the same process, taken with a half of a minute interval or so): mdev19745_threads1 mdev19745_threads2

          elenst Elena Stepanova added a comment - It is reproducible readily for me with Vlad's test case. Two consequent full all thread stack traces from 10.5 a6946c55 are attached (from the same process, taken with a half of a minute interval or so): mdev19745_threads1 mdev19745_threads2

          Problem was that FLUSH TABLES where trying to read latest sequence state which conflicted with a running ALTER SEQUENCE. Removed the reading of the state, when opening a table for FLUSH, as it's not needed in this case.

          monty Michael Widenius added a comment - Problem was that FLUSH TABLES where trying to read latest sequence state which conflicted with a running ALTER SEQUENCE. Removed the reading of the state, when opening a table for FLUSH, as it's not needed in this case.

          Problem was that FLUSH TABLES where trying to read latest sequence state which conflicted with a running ALTER SEQUENCE. Removed the reading of the state, when opening a table for FLUSH,
          as it's not needed in this case.

          monty Michael Widenius added a comment - Problem was that FLUSH TABLES where trying to read latest sequence state which conflicted with a running ALTER SEQUENCE. Removed the reading of the state, when opening a table for FLUSH, as it's not needed in this case.

          People

            monty Michael Widenius
            vlad.lesin Vladislav Lesin
            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.