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

Server hang or ASAN heap-use-after-free in maria_write upon INSERT after failed ALTER under lock

    XMLWordPrintable

    Details

      Description

      CREATE TABLE t1 (a INT) ENGINE=Aria;
      CREATE VIEW v1 AS SELECT * FROM t1;
      LOCK TABLE t1 WRITE, v1 READ;
       
      --error ER_ALTER_OPERATION_NOT_SUPPORTED_REASON
      ALTER TABLE t1 CHANGE COLUMN a b INT, ALGORITHM=COPY, LOCK=NONE;
      INSERT INTO t1 VALUES (1);
       
      # Cleanup
      UNLOCK TABLES;
      DROP VIEW v1;
      DROP TABLE t1;
      

      10.3 ASAN d531b4ee

      ==9167==ERROR: AddressSanitizer: heap-use-after-free on address 0x61100000c8f0 at pc 0x55d180d7e98d bp 0x7f2d079a3e50 sp 0x7f2d079a3e48
      READ of size 4 at 0x61100000c8f0 thread T5
          #0 0x55d180d7e98c in maria_write /data/src/10.3/storage/maria/ma_write.c:286
          #1 0x55d180c3ed7f in ha_maria::write_row(unsigned char*) /data/src/10.3/storage/maria/ha_maria.cc:1211
          #2 0x55d17ff2201f in handler::ha_write_row(unsigned char*) /data/src/10.3/sql/handler.cc:6447
          #3 0x55d17f773c05 in write_record(THD*, TABLE*, st_copy_info*) /data/src/10.3/sql/sql_insert.cc:2034
          #4 0x55d17f76c9ab in mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool) /data/src/10.3/sql/sql_insert.cc:1072
          #5 0x55d17f807974 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4455
          #6 0x55d17f81de4a in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7818
          #7 0x55d17f7f8b9e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1856
          #8 0x55d17f7f5a7d in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1401
          #9 0x55d17fb6ba08 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
          #10 0x55d17fb6b3cf in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
          #11 0x55d180fd6629 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
          #12 0x7f2d137f84a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
          #13 0x7f2d1192cd0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
       
      0x61100000c8f0 is located 176 bytes inside of 252-byte region [0x61100000c840,0x61100000c93c)
      freed by thread T5 here:
          #0 0x7f2d13acfa10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
          #1 0x55d1811072d0 in free_memory /data/src/10.3/mysys/safemalloc.c:279
          #2 0x55d1811069b9 in sf_free /data/src/10.3/mysys/safemalloc.c:197
          #3 0x55d1810d8b4b in my_free /data/src/10.3/mysys/my_malloc.c:223
          #4 0x55d180c15f8c in _ma_remove_table_from_trnman /data/src/10.3/storage/maria/ma_state.c:594
          #5 0x55d180cfcd26 in maria_extra /data/src/10.3/storage/maria/ma_extra.c:410
          #6 0x55d180c4a2e2 in ha_maria::extra(ha_extra_function) /data/src/10.3/storage/maria/ha_maria.cc:2547
          #7 0x55d17f6acbbe in Locked_tables_list::reopen_tables(THD*, bool) /data/src/10.3/sql/sql_base.cc:2497
          #8 0x55d17f812ffd in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6061
          #9 0x55d17f81de4a in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7818
          #10 0x55d17f7f8b9e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1856
          #11 0x55d17f7f5a7d in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1401
          #12 0x55d17fb6ba08 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
          #13 0x55d17fb6b3cf in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
          #14 0x55d180fd6629 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
          #15 0x7f2d137f84a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
       
      previously allocated by thread T5 here:
          #0 0x7f2d13acfd28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
          #1 0x55d1811063d1 in sf_malloc /data/src/10.3/mysys/safemalloc.c:118
          #2 0x55d1810d825a in my_malloc /data/src/10.3/mysys/my_malloc.c:101
          #3 0x55d180c128fd in _ma_setup_live_state /data/src/10.3/storage/maria/ma_state.c:81
          #4 0x55d180c4c3b9 in ha_maria::implicit_commit(THD*, bool) /data/src/10.3/storage/maria/ha_maria.cc:2893
          #5 0x55d17fefbe0c in ha_commit_trans(THD*, bool) /data/src/10.3/sql/handler.cc:1387
          #6 0x55d17fb9a200 in trans_commit_implicit(THD*) /data/src/10.3/sql/transaction.cc:361
          #7 0x55d17f803730 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:3669
          #8 0x55d17f81de4a in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7818
          #9 0x55d17f7f8b9e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1856
          #10 0x55d17f7f5a7d in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1401
          #11 0x55d17fb6ba08 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
          #12 0x55d17fb6b3cf in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
          #13 0x55d180fd6629 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
          #14 0x7f2d137f84a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
       
      Thread T5 created by T0 here:
          #0 0x7f2d13a3ef59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
          #1 0x55d180fd6a65 in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1912
          #2 0x55d17f562e80 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1268
          #3 0x55d17f57818c in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6600
          #4 0x55d17f57886f in create_new_thread /data/src/10.3/sql/mysqld.cc:6670
          #5 0x55d17f579887 in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6945
          #6 0x55d17f57765c in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6222
          #7 0x55d17f56159f in main /data/src/10.3/sql/main.cc:25
          #8 0x7f2d118642e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
       
      SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.3/storage/maria/ma_write.c:286 in maria_write
      Shadow bytes around the buggy address:
        0x0c227fff98c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
        0x0c227fff98d0: 04 fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c227fff98e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c227fff98f0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c227fff9900: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
      =>0x0c227fff9910: fd fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd
        0x0c227fff9920: fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa
        0x0c227fff9930: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c227fff9940: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c227fff9950: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
        0x0c227fff9960: fd fd fd fd fd fd fd fd fd fd fd fd 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
        Container overflow:      fc
        Array cookie:            ac
        Intra object redzone:    bb
        ASan internal:           fe
        Left alloca redzone:     ca
        Right alloca redzone:    cb
      

      Reproducible with 10.2, 10.3.
      Couldn't reproduce with 10.1, 10.4.
      No visible effect on a non-ASAN build; however, the variation below makes the server hang on non-debug builds as well:

      CREATE TABLE t1 (a INT) ENGINE=Aria;
      LOCK TABLE t1 WRITE, t1 t1a READ;
       
      SET lock_wait_timeout= 1;
       
      --error ER_ALTER_OPERATION_NOT_SUPPORTED_REASON
      ALTER TABLE t1 CHANGE COLUMN a b INT, ALGORITHM=COPY, LOCK=NONE;
      INSERT INTO t1 VALUES (1);
       
      # Cleanup
      UNLOCK TABLES;
      DROP TABLE t1;
      

      Stack trace from the running (hanging) server:

      10.3 debug d531b4ee

      #0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
      #1  0x000055d922966014 in safe_cond_timedwait (cond=0x7fcda80008c8, mp=0x7fcda8097710, abstime=0x7fcdb94579f0, file=0x55d922da6590 "/data/src/10.3/include/mysql/psi/mysql_thread.h", line=1204) at /data/src/10.3/mysys/thr_mutex.c:546
      #2  0x000055d922962512 in inline_mysql_cond_timedwait (that=0x7fcda80008c8, mutex=0x7fcda8097710, abstime=0x7fcdb94579f0, src_file=0x55d922da65c0 "/data/src/10.3/mysys/thr_lock.c", src_line=576) at /data/src/10.3/include/mysql/psi/mysql_thread.h:1204
      #3  0x000055d922962c0b in wait_for_lock (wait=0x7fcda80977e0, data=0x7fcda807e818, in_wait_list=0 '\000', lock_wait_timeout=31536000) at /data/src/10.3/mysys/thr_lock.c:576
      #4  0x000055d922963764 in thr_lock (data=0x7fcda807e818, owner=0x7fcda8002600, lock_wait_timeout=31536000) at /data/src/10.3/mysys/thr_lock.c:1014
      #5  0x000055d922964053 in thr_multi_lock (data=0x7fcda804a5a8, count=1, owner=0x7fcda8002600, lock_wait_timeout=31536000) at /data/src/10.3/mysys/thr_lock.c:1295
      #6  0x000055d922220677 in mysql_lock_tables (thd=0x7fcda8000af0, sql_lock=0x7fcda804a580, flags=18539) at /data/src/10.3/sql/lock.cc:347
      #7  0x000055d922220479 in mysql_lock_tables (thd=0x7fcda8000af0, tables=0x7fcda8045018, count=1, flags=18539) at /data/src/10.3/sql/lock.cc:299
      #8  0x000055d921d3a468 in Locked_tables_list::reopen_tables (this=0x7fcda8004800, thd=0x7fcda8000af0, need_reopen=true) at /data/src/10.3/sql/sql_base.cc:2538
      #9  0x000055d921dd8897 in mysql_execute_command (thd=0x7fcda8000af0) at /data/src/10.3/sql/sql_parse.cc:6061
      #10 0x000055d921dddb73 in mysql_parse (thd=0x7fcda8000af0, rawbuf=0x7fcda8012818 "ALTER TABLE t1 CHANGE COLUMN a b INT, ALGORITHM=COPY, LOCK=NONE", length=63, parser_state=0x7fcdb94585e0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7818
      #11 0x000055d921dca6e7 in dispatch_command (command=COM_QUERY, thd=0x7fcda8000af0, packet=0x7fcda8008c71 "ALTER TABLE t1 CHANGE COLUMN a b INT, ALGORITHM=COPY, LOCK=NONE", packet_length=63, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1856
      #12 0x000055d921dc902f in do_command (thd=0x7fcda8000af0) at /data/src/10.3/sql/sql_parse.cc:1401
      #13 0x000055d921f4098e in do_handle_one_connection (connect=0x55d924eedc90) at /data/src/10.3/sql/sql_connect.cc:1403
      #14 0x000055d921f406f0 in handle_one_connection (arg=0x55d924eedc90) at /data/src/10.3/sql/sql_connect.cc:1308
      #15 0x000055d9228eff52 in pfs_spawn_thread (arg=0x55d924f08d40) at /data/src/10.3/storage/perfschema/pfs.cc:1862
      #16 0x00007fcdc11e24a4 in start_thread (arg=0x7fcdb9459700) at pthread_create.c:456
      #17 0x00007fcdbf316d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

        Attachments

          Activity

            People

            Assignee:
            vlad.lesin Vladislav Lesin
            Reporter:
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated: