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

ASAN use-after-poison in page_cur_insert_rec_low

    XMLWordPrintable

    Details

      Description

      The failure currently happens for me every time, but it was a bit sporadic (although frequent) with non-final versions of the test case, so please run with --repeat=N if it doesn't fail right away.

      --source include/have_innodb.inc
       
      CREATE TABLE t1 (id INT AUTO_INCREMENT, a YEAR, UNIQUE(id), KEY(id,a)) ENGINE=InnoDB;
      INSERT INTO t1 VALUES (1,NULL),(2,NULL);
      UPDATE IGNORE t1 SET a = '';
       
      # Cleanup
      DROP TABLE t1;
      

      10.5 ASAN 607960c7

      ==12352==ERROR: AddressSanitizer: use-after-poison on address 0x6190000d7613 at pc 0x55a8b41509fe bp 0x7fc5a510a2d0 sp 0x7fc5a510a2c8
      READ of size 1 at 0x6190000d7613 thread T13
          #0 0x55a8b41509fd in page_cur_insert_rec_low(page_cur_t const*, dict_index_t*, unsigned char const*, unsigned short*, mtr_t*) /data/src/10.5/storage/innobase/page/page0cur.cc:1567
          #1 0x55a8b442e55e in page_cur_tuple_insert /data/src/10.5/storage/innobase/include/page0cur.ic:285
          #2 0x55a8b44442fc in btr_cur_optimistic_insert(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /data/src/10.5/storage/innobase/btr/btr0cur.cc:3537
          #3 0x55a8b4218ad0 in row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*) /data/src/10.5/storage/innobase/row/row0ins.cc:3115
          #4 0x55a8b4219a27 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /data/src/10.5/storage/innobase/row/row0ins.cc:3316
          #5 0x55a8b42fb636 in row_upd_sec_index_entry /data/src/10.5/storage/innobase/row/row0upd.cc:2224
          #6 0x55a8b42fba4f in row_upd_sec_step /data/src/10.5/storage/innobase/row/row0upd.cc:2251
          #7 0x55a8b4300a14 in row_upd /data/src/10.5/storage/innobase/row/row0upd.cc:3031
          #8 0x55a8b4301400 in row_upd_step(que_thr_t*) /data/src/10.5/storage/innobase/row/row0upd.cc:3146
          #9 0x55a8b425cd74 in row_update_for_mysql(row_prebuilt_t*) /data/src/10.5/storage/innobase/row/row0mysql.cc:1889
          #10 0x55a8b3f6917d in ha_innobase::update_row(unsigned char const*, unsigned char const*) /data/src/10.5/storage/innobase/handler/ha_innodb.cc:8573
          #11 0x55a8b360add1 in handler::ha_update_row(unsigned char const*, unsigned char const*) /data/src/10.5/sql/handler.cc:6702
          #12 0x55a8b3141d57 in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /data/src/10.5/sql/sql_update.cc:1054
          #13 0x55a8b2eada86 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:4360
          #14 0x55a8b2ec4cd1 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:7918
          #15 0x55a8b2e9ee89 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1845
          #16 0x55a8b2e9be42 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1364
          #17 0x55a8b324d6b4 in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1422
          #18 0x55a8b324d0aa in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1319
          #19 0x55a8b3e835c9 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:1869
          #20 0x7fc5b54df4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
          #21 0x7fc5b3613d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
       
      0x6190000d7613 is located 147 bytes inside of 1152-byte region [0x6190000d7580,0x6190000d7a00)
      allocated by thread T13 here:
          #0 0x7fc5b57b6d28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
          #1 0x55a8b41263cb in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned int, unsigned long) /data/src/10.5/storage/innobase/mem/mem0mem.cc:277
          #2 0x55a8b420384d in mem_heap_create_func /data/src/10.5/storage/innobase/include/mem0mem.ic:375
          #3 0x55a8b42198dc in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /data/src/10.5/storage/innobase/row/row0ins.cc:3295
          #4 0x55a8b42fb636 in row_upd_sec_index_entry /data/src/10.5/storage/innobase/row/row0upd.cc:2224
          #5 0x55a8b42fba4f in row_upd_sec_step /data/src/10.5/storage/innobase/row/row0upd.cc:2251
          #6 0x55a8b4300a14 in row_upd /data/src/10.5/storage/innobase/row/row0upd.cc:3031
          #7 0x55a8b4301400 in row_upd_step(que_thr_t*) /data/src/10.5/storage/innobase/row/row0upd.cc:3146
          #8 0x55a8b425cd74 in row_update_for_mysql(row_prebuilt_t*) /data/src/10.5/storage/innobase/row/row0mysql.cc:1889
          #9 0x55a8b3f6917d in ha_innobase::update_row(unsigned char const*, unsigned char const*) /data/src/10.5/storage/innobase/handler/ha_innodb.cc:8573
          #10 0x55a8b360add1 in handler::ha_update_row(unsigned char const*, unsigned char const*) /data/src/10.5/sql/handler.cc:6702
          #11 0x55a8b3141d57 in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /data/src/10.5/sql/sql_update.cc:1054
          #12 0x55a8b2eada86 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:4360
          #13 0x55a8b2ec4cd1 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:7918
          #14 0x55a8b2e9ee89 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1845
          #15 0x55a8b2e9be42 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1364
          #16 0x55a8b324d6b4 in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1422
          #17 0x55a8b324d0aa in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1319
          #18 0x55a8b3e835c9 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:1869
          #19 0x7fc5b54df4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
       
      Thread T13 created by T0 here:
          #0 0x7fc5b5725f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
          #1 0x55a8b3e839b6 in spawn_thread_v1 /data/src/10.5/storage/perfschema/pfs.cc:1919
          #2 0x55a8b2be8b28 in inline_mysql_thread_create /data/src/10.5/include/mysql/psi/mysql_thread.h:1275
          #3 0x55a8b2bfc79f in create_thread_to_handle_connection(CONNECT*) /data/src/10.5/sql/mysqld.cc:6065
          #4 0x55a8b2bfcd14 in create_new_thread(CONNECT*) /data/src/10.5/sql/mysqld.cc:6124
          #5 0x55a8b2bfced1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.5/sql/mysqld.cc:6189
          #6 0x55a8b2bfd8b4 in handle_connections_sockets() /data/src/10.5/sql/mysqld.cc:6316
          #7 0x55a8b2bfbffb in mysqld_main(int, char**) /data/src/10.5/sql/mysqld.cc:5728
          #8 0x55a8b2be6a0f in main /data/src/10.5/sql/main.cc:25
          #9 0x7fc5b354b2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
       
      SUMMARY: AddressSanitizer: use-after-poison /data/src/10.5/storage/innobase/page/page0cur.cc:1567 in page_cur_insert_rec_low(page_cur_t const*, dict_index_t*, unsigned char const*, unsigned short*, mtr_t*)
      Shadow bytes around the buggy address:
        0x0c3280012e70: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012e80: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012e90: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012ea0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c3280012eb0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
      =>0x0c3280012ec0: f7 00[03]f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012ed0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012ee0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012ef0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012f00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c3280012f10: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
      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
      ==12352==ABORTING
      200301 19:57:55 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.5.2-MariaDB-debug-log
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=1
      max_threads=153
      thread_count=2
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63657 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x62b000069270
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x7fc5a510f9a0 thread_stack 0x5fc00
      /usr/lib/x86_64-linux-gnu/libasan.so.3(backtrace+0x41)[0x7fc5b5742681]
      /data/bld/10.5-asan/bin/mysqld(my_print_stacktrace+0xb5)[0x55a8b487855f]
      /data/bld/10.5-asan/bin/mysqld(handle_fatal_signal+0x873)[0x55a8b35d7295]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x110e0)[0x7fc5b54e90e0]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcf)[0x7fc5b355dfff]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fc5b355f42a]
      /usr/lib/x86_64-linux-gnu/libasan.so.3(+0xdb329)[0x7fc5b57d0329]
      /usr/lib/x86_64-linux-gnu/libasan.so.3(+0xd09ab)[0x7fc5b57c59ab]
      /usr/lib/x86_64-linux-gnu/libasan.so.3(+0xcab57)[0x7fc5b57bfb57]
      /usr/lib/x86_64-linux-gnu/libasan.so.3(__asan_report_load1+0x28)[0x7fc5b57c01e8]
      /data/bld/10.5-asan/bin/mysqld(+0x26fc9fe)[0x55a8b41509fe]
      /data/bld/10.5-asan/bin/mysqld(+0x29da55f)[0x55a8b442e55f]
      /data/bld/10.5-asan/bin/mysqld(+0x29f02fd)[0x55a8b44442fd]
      /data/bld/10.5-asan/bin/mysqld(+0x27c4ad1)[0x55a8b4218ad1]
      /data/bld/10.5-asan/bin/mysqld(+0x27c5a28)[0x55a8b4219a28]
      /data/bld/10.5-asan/bin/mysqld(+0x28a7637)[0x55a8b42fb637]
      /data/bld/10.5-asan/bin/mysqld(+0x28a7a50)[0x55a8b42fba50]
      /data/bld/10.5-asan/bin/mysqld(+0x28aca15)[0x55a8b4300a15]
      /data/bld/10.5-asan/bin/mysqld(+0x28ad401)[0x55a8b4301401]
      /data/bld/10.5-asan/bin/mysqld(+0x2808d75)[0x55a8b425cd75]
      /data/bld/10.5-asan/bin/mysqld(+0x251517e)[0x55a8b3f6917e]
      /data/bld/10.5-asan/bin/mysqld(_ZN7handler13ha_update_rowEPKhS1_+0x89a)[0x55a8b360add2]
      /data/bld/10.5-asan/bin/mysqld(_Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_orderybPySA_+0x4833)[0x55a8b3141d58]
      /data/bld/10.5-asan/bin/mysqld(_Z21mysql_execute_commandP3THD+0x6be3)[0x55a8b2eada87]
      /data/bld/10.5-asan/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x6b4)[0x55a8b2ec4cd2]
      /data/bld/10.5-asan/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x2053)[0x55a8b2e9ee8a]
      /data/bld/10.5-asan/bin/mysqld(_Z10do_commandP3THD+0x10f5)[0x55a8b2e9be43]
      /data/bld/10.5-asan/bin/mysqld(_Z24do_handle_one_connectionP7CONNECTb+0x430)[0x55a8b324d6b5]
      /data/bld/10.5-asan/bin/mysqld(handle_one_connection+0x80)[0x55a8b324d0ab]
      /data/bld/10.5-asan/bin/mysqld(+0x242f5ca)[0x55a8b3e835ca]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x74a4)[0x7fc5b54df4a4]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fc5b3613d0f]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x62b00007e290): UPDATE IGNORE t1 SET a = ''
      Connection ID (thread ID): 4
      Status: NOT_KILLED
      

      The failure appeared in 10.5 tree with this commit:

      commit 138cbec5f2300bd5b401e83802642c1806264992
      Author: Marko Mäkelä <marko.makela@mariadb.com>
      Date:   Thu Feb 27 17:19:44 2020 +0200
       
          MDEV-21724: Optimize page_cur_insert_low() redo logging
      

      See also MDEV-21779.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: