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

Server crash in backup_end or assertion failure `ticket->m_duration == MDL_EXPLICIT' upon BACKUP STAGE END after FLUSH TABLE with locks

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.4
    • Fix Version/s: 10.4
    • Component/s: Backup, Locking
    • Labels:
      None

      Description

      CREATE TABLE t1 (pk INT PRIMARY KEY, f INT);
      BACKUP STAGE START;
      FLUSH TABLE t1 FOR EXPORT;
      UNLOCK TABLES;
      BACKUP STAGE END;
       
      # Cleanup
      DROP TABLE t1;
      

      10.4 debug a8eb0c76b

      mysqld: /data/src/10.4/sql/mdl.cc:2851: void MDL_context::release_lock(MDL_ticket*): Assertion `ticket->m_duration == MDL_EXPLICIT' failed.
      181223 23:37:42 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007fb5fe103ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
      #8  0x00005611310d7d4e in MDL_context::release_lock (this=0x7fb5e8000c20, ticket=0x7fb5e80b4f10) at /data/src/10.4/sql/mdl.cc:2851
      #9  0x00005611311acedb in backup_end (thd=0x7fb5e8000b00) at /data/src/10.4/sql/backup.cc:308
      #10 0x00005611311ac894 in run_backup_stage (thd=0x7fb5e8000b00, stage=BACKUP_END) at /data/src/10.4/sql/backup.cc:119
      #11 0x0000561130f6a94b in mysql_execute_command (thd=0x7fb5e8000b00) at /data/src/10.4/sql/sql_parse.cc:5233
      #12 0x0000561130f738e4 in mysql_parse (thd=0x7fb5e8000b00, rawbuf=0x7fb5e8014f98 "BACKUP STAGE END", length=16, parser_state=0x7fb5f8295600, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
      #13 0x0000561130f60b0e in dispatch_command (command=COM_QUERY, thd=0x7fb5e8000b00, packet=0x7fb5e800b421 "BACKUP STAGE END", packet_length=16, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
      #14 0x0000561130f5f532 in do_command (thd=0x7fb5e8000b00) at /data/src/10.4/sql/sql_parse.cc:1396
      #15 0x00005611310cb6de in do_handle_one_connection (connect=0x5611335866b0) at /data/src/10.4/sql/sql_connect.cc:1402
      #16 0x00005611310cb462 in handle_one_connection (arg=0x5611335866b0) at /data/src/10.4/sql/sql_connect.cc:1308
      #17 0x000056113158a338 in pfs_spawn_thread (arg=0x5611334ca970) at /data/src/10.4/storage/perfschema/pfs.cc:1862
      #18 0x00007fb5ffbbf494 in start_thread (arg=0x7fb5f8296700) at pthread_create.c:333
      #19 0x00007fb5fe1c093f in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      10.4 non-debug a8eb0c76b

      #5  <signal handler called>
      #6  0x0000000000000055 in ?? ()
      #7  0x000055bd2db3724f in backup_end (thd=0x7f71b00009a8) at /data/src/10.4/sql/backup.cc:308
      #8  0x000055bd2db372d8 in run_backup_stage (thd=0x7f71b00009a8, stage=BACKUP_END) at /data/src/10.4/sql/backup.cc:119
      #9  0x000055bd2d9d1399 in mysql_execute_command (thd=0x7f71b00009a8) at /data/src/10.4/sql/sql_parse.cc:5233
      #10 0x000055bd2d9d79a1 in mysql_parse (thd=0x7f71b00009a8, rawbuf=<optimized out>, length=16, parser_state=0x7f71cc31f640, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.4/sql/sql_parse.cc:8104
      #11 0x000055bd2d9da315 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f71b00009a8, packet=packet@entry=0x7f71b0009559 "BACKUP STAGE END", packet_length=packet_length@entry=16, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.4/sql/sql_parse.cc:1851
      #12 0x000055bd2d9daca0 in do_command (thd=0x7f71b00009a8) at /data/src/10.4/sql/sql_parse.cc:1396
      #13 0x000055bd2daacd54 in do_handle_one_connection (connect=connect@entry=0x55bd311490c8) at /data/src/10.4/sql/sql_connect.cc:1402
      #14 0x000055bd2daacef4 in handle_one_connection (arg=arg@entry=0x55bd311490c8) at /data/src/10.4/sql/sql_connect.cc:1308
      #15 0x000055bd2dda35a4 in pfs_spawn_thread (arg=0x55bd31149328) at /data/src/10.4/storage/perfschema/pfs.cc:1862
      #16 0x00007f71d337a494 in start_thread (arg=0x7f71cc320700) at pthread_create.c:333
      #17 0x00007f71d197b93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      10.4 7b33a6a1 ASAN

      ==30879==ERROR: AddressSanitizer: heap-use-after-free on address 0x6060000059ec at pc 0x557fdac7557d bp 0x7fcf01608730 sp 0x7fcf01608728
      READ of size 4 at 0x6060000059ec thread T5
          #0 0x557fdac7557c in MDL_context::release_lock(MDL_ticket*) /data/src/10.4/sql/mdl.cc:2835
          #1 0x557fdae7837c in backup_end(THD*) /data/src/10.4/sql/backup.cc:308
          #2 0x557fdae775e0 in run_backup_stage(THD*, backup_stages) /data/src/10.4/sql/backup.cc:119
          #3 0x557fda8d6ee4 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:5336
          #4 0x557fda8e9dda in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8205
          #5 0x557fda8c1ce5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1829
          #6 0x557fda8beb36 in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1358
          #7 0x557fdac528a5 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1399
          #8 0x557fdac5229e in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1302
          #9 0x557fdb819be2 in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
          #10 0x7fcf0c9b7493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
          #11 0x7fcf0ad9d93e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
       
      0x6060000059ec is located 44 bytes inside of 64-byte region [0x6060000059c0,0x606000005a00)
      freed by thread T5 here:
          #0 0x7fcf0cc22477 in operator delete(void*) (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x55477)
          #1 0x557fdac7a5d9 in MDL_ticket::~MDL_ticket() /data/src/10.4/sql/mdl.h:667
          #2 0x557fdac6f5b4 in MDL_ticket::destroy(MDL_ticket*) /data/src/10.4/sql/mdl.cc:1014
          #3 0x557fdac754aa in MDL_context::release_lock(enum_mdl_duration, MDL_ticket*) /data/src/10.4/sql/mdl.cc:2820
          #4 0x557fdac7578d in MDL_context::release_locks_stored_before(enum_mdl_duration, MDL_ticket*) /data/src/10.4/sql/mdl.cc:2867
          #5 0x557fdac76542 in MDL_context::release_transactional_locks() /data/src/10.4/sql/mdl.cc:3040
          #6 0x557fda8d6adf in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:5275
          #7 0x557fda8e9dda in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8205
          #8 0x557fda8c1ce5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1829
          #9 0x557fda8beb36 in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1358
          #10 0x557fdac528a5 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1399
          #11 0x557fdac5229e in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1302
          #12 0x557fdb819be2 in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
          #13 0x7fcf0c9b7493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
       
      previously allocated by thread T5 here:
          #0 0x7fcf0cc2223f in operator new(unsigned long, std::nothrow_t const&) (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5523f)
          #1 0x557fdac6f51c in MDL_ticket::create(MDL_context*, enum_mdl_type, enum_mdl_duration) /data/src/10.4/sql/mdl.cc:1008
          #2 0x557fdac7259a in MDL_context::try_acquire_lock_impl(MDL_request*, MDL_ticket**) /data/src/10.4/sql/mdl.cc:2084
          #3 0x557fdac731b1 in MDL_context::acquire_lock(MDL_request*, double) /data/src/10.4/sql/mdl.cc:2247
          #4 0x557fdae77a57 in backup_start /data/src/10.4/sql/backup.cc:165
          #5 0x557fdae77564 in run_backup_stage(THD*, backup_stages) /data/src/10.4/sql/backup.cc:104
          #6 0x557fda8d6ee4 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:5336
          #7 0x557fda8e9dda in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8205
          #8 0x557fda8c1ce5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1829
          #9 0x557fda8beb36 in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1358
          #10 0x557fdac528a5 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1399
          #11 0x557fdac5229e in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1302
          #12 0x557fdb819be2 in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
          #13 0x7fcf0c9b7493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
       
      Thread T5 created by T0 here:
          #0 0x7fcf0cbf0bba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
          #1 0x557fdb81a1aa in spawn_thread_v1 /data/src/10.4/storage/perfschema/pfs.cc:1912
          #2 0x557fda609846 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
          #7 0x557fda61e973 in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:5876
          #8 0x557fda6076cf in main /data/src/10.4/sql/main.cc:25
          #9 0x7fcf0acd52b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
       
      SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.4/sql/mdl.cc:2835 MDL_context::release_lock(MDL_ticket*)
      Shadow bytes around the buggy address:
        0x0c0c7fff8ae0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c0c7fff8af0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c0c7fff8b00: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c0c7fff8b10: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c0c7fff8b20: fa fa fa fa fa fa fa fa fa fa fa fa fd fd fd fd
      =>0x0c0c7fff8b30: fd fd fd fd fa fa fa fa fd fd fd fd fd[fd]fd fd
        0x0c0c7fff8b40: fa fa fa fa fd fd fd fd fd fd fd fd fa fa fa fa
        0x0c0c7fff8b50: fd fd fd fd fd fd fd fd fa fa fa fa fd fd fd fd
        0x0c0c7fff8b60: fd fd fd fd fa fa fa fa fd fd fd fd fd fd fd fd
        0x0c0c7fff8b70: fa fa fa fa fd fd fd fd fd fd fd fd fa fa fa fa
        0x0c0c7fff8b80: fd fd fd fd fd fd fd fd fa fa fa fa fd fd fd fd
      Shadow byte legend (one shadow byte represents 8 application bytes):
        Addressable:           00
        Partially addressable: 01 02 03 04 05 06 07 
        Heap left redzone:       fa
        Heap right redzone:      fb
        Freed heap region:       fd
        Stack left redzone:      f1
        Stack mid redzone:       f2
        Stack right redzone:     f3
        Stack partial redzone:   f4
        Stack after return:      f5
        Stack use after scope:   f8
        Global redzone:          f9
        Global init order:       f6
        Poisoned by user:        f7
        Contiguous container OOB:fc
        ASan internal:           fe
      ==30879==ABORTING
      

      Another test case, with FTWRL instead of FOR EXPORT:

      CREATE TABLE t1 (a INT);
      CREATE TABLE t2 (b INT);
      BACKUP STAGE START;
      FLUSH TABLES t1 WITH READ LOCK;
      --error ER_BACKUP_LOCK_IS_ACTIVE
      LOCK TABLE t2 WRITE;
      BACKUP STAGE END;
       
      # Cleanup
      UNLOCK TABLES;
      DROP TABLE t1, t2;
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                monty Michael Widenius
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated: