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

Assertion `(fil_page_get_type(page) == 17855 || fil_page_get_type(page) == 17854)' failed in rec_get_trx_id

    XMLWordPrintable

    Details

    • Sprint:
      10.2.12

      Description

      10.2 0c4d11e8199f4c7a with the injection below

      mysqld: /data/src/10.2-bug/storage/innobase/rem/rem0rec.cc:2183: trx_id_t rec_get_trx_id(const rec_t*, const dict_index_t*): Assertion `(fil_page_get_type(page) == 17855 || fil_page_get_type(page) == 17854)' failed.
      171116 17:54:16 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007f046b4c1ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
      #8  0x0000563d6fa15548 in rec_get_trx_id (rec=0x7f0414010c7e "\200", index=0x7f041012fc88) at /data/src/10.2-bug/storage/innobase/rem/rem0rec.cc:2183
      #9  0x0000563d6fa846bd in row_sel_sec_rec_is_for_clust_rec (sec_rec=0x7f046510407d "\200", sec_index=0x7f0410039ca8, clust_rec=0x7f0414010c7e "\200", clust_index=0x7f041012fc88, thr=0x7f041401e9a0) at /data/src/10.2-bug/storage/innobase/row/row0sel.cc:188
      #10 0x0000563d6fa8b1bf in row_sel_get_clust_rec_for_mysql (prebuilt=0x7f041401e288, sec_index=0x7f0410039ca8, rec=0x7f046510407d "\200", thr=0x7f041401e9a0, out_rec=0x7f04640e1aa8, offsets=0x7f04640e1ac8, offset_heap=0x7f04640e1ac0, vrow=0x0, mtr=0x7f04640e25c0) at /data/src/10.2-bug/storage/innobase/row/row0sel.cc:3522
      #11 0x0000563d6fa8f023 in row_search_mvcc (buf=0x7f041401de28 "\377", mode=PAGE_CUR_G, prebuilt=0x7f041401e288, match_mode=0, direction=0) at /data/src/10.2-bug/storage/innobase/row/row0sel.cc:5242
      #12 0x0000563d6f91c233 in ha_innobase::index_read (this=0x7f041401c6d8, buf=0x7f041401de28 "\377", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at /data/src/10.2-bug/storage/innobase/handler/ha_innodb.cc:9823
      #13 0x0000563d6f91d5d6 in ha_innobase::index_first (this=0x7f041401c6d8, buf=0x7f041401de28 "\377") at /data/src/10.2-bug/storage/innobase/handler/ha_innodb.cc:10261
      #14 0x0000563d6f60a63b in handler::ha_index_first (this=0x7f041401c6d8, buf=0x7f041401de28 "\377") at /data/src/10.2-bug/sql/handler.cc:2717
      #15 0x0000563d6f77460f in rr_index_first (info=0x7f0414013c30) at /data/src/10.2-bug/sql/records.cc:401
      #16 0x0000563d6f4058e2 in join_init_read_record (tab=0x7f0414013b68) at /data/src/10.2-bug/sql/sql_select.cc:19560
      #17 0x0000563d6f5217fe in JOIN_TAB_SCAN::open (this=0x7f0414014988) at /data/src/10.2-bug/sql/sql_join_cache.cc:3339
      #18 0x0000563d6f51fd0c in JOIN_CACHE::join_matching_records (this=0x7f0414014858, skip_last=false) at /data/src/10.2-bug/sql/sql_join_cache.cc:2250
      #19 0x0000563d6f51f890 in JOIN_CACHE::join_records (this=0x7f0414014858, skip_last=false) at /data/src/10.2-bug/sql/sql_join_cache.cc:2087
      #20 0x0000563d6f40330a in sub_select_cache (join=0x7f0414012150, join_tab=0x7f0414013b68, end_of_records=true) at /data/src/10.2-bug/sql/sql_select.cc:18417
      #21 0x0000563d6f40351c in sub_select (join=0x7f0414012150, join_tab=0x7f04140137b8, end_of_records=true) at /data/src/10.2-bug/sql/sql_select.cc:18589
      #22 0x0000563d6f402d32 in do_select (join=0x7f0414012150, procedure=0x0) at /data/src/10.2-bug/sql/sql_select.cc:18184
      #23 0x0000563d6f3dd3e3 in JOIN::exec_inner (this=0x7f0414012150) at /data/src/10.2-bug/sql/sql_select.cc:3514
      #24 0x0000563d6f3dc892 in JOIN::exec (this=0x7f0414012150) at /data/src/10.2-bug/sql/sql_select.cc:3309
      #25 0x0000563d6f3dda5b in mysql_select (thd=0x7f0414000b00, tables=0x7f04140113d0, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f0414012130, unit=0x7f04140046a0, select_lex=0x7f0414004dd8) at /data/src/10.2-bug/sql/sql_select.cc:3709
      #26 0x0000563d6f3d22bc in handle_select (thd=0x7f0414000b00, lex=0x7f04140045d8, result=0x7f0414012130, setup_tables_done_option=0) at /data/src/10.2-bug/sql/sql_select.cc:373
      #27 0x0000563d6f39e0fc in execute_sqlcom_select (thd=0x7f0414000b00, all_tables=0x7f04140113d0) at /data/src/10.2-bug/sql/sql_parse.cc:6428
      #28 0x0000563d6f394159 in mysql_execute_command (thd=0x7f0414000b00) at /data/src/10.2-bug/sql/sql_parse.cc:3462
      #29 0x0000563d6f3a1abe in mysql_parse (thd=0x7f0414000b00, rawbuf=0x7f0414011088 "SELECT a1.f1, a1.f2 FROM t1 AS a1, t1 AS a2", length=43, parser_state=0x7f04640e4200, is_com_multi=false, is_next_command=false) at /data/src/10.2-bug/sql/sql_parse.cc:7869
      #30 0x0000563d6f38fa4a in dispatch_command (command=COM_QUERY, thd=0x7f0414000b00, packet=0x7f04140088a1 "", packet_length=43, is_com_multi=false, is_next_command=false) at /data/src/10.2-bug/sql/sql_parse.cc:1805
      #31 0x0000563d6f38e3a8 in do_command (thd=0x7f0414000b00) at /data/src/10.2-bug/sql/sql_parse.cc:1360
      #32 0x0000563d6f4db98d in do_handle_one_connection (connect=0x563d73106c40) at /data/src/10.2-bug/sql/sql_connect.cc:1354
      #33 0x0000563d6f4db71a in handle_one_connection (arg=0x563d73106c40) at /data/src/10.2-bug/sql/sql_connect.cc:1260
      #34 0x0000563d6f8f8e1a in pfs_spawn_thread (arg=0x563d731a8ad0) at /data/src/10.2-bug/storage/perfschema/pfs.cc:1863
      #35 0x00007f046d198494 in start_thread (arg=0x7f04640e5700) at pthread_create.c:333
      #36 0x00007f046b57e93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      The problem happens in concurrent tests on a normal server (without the sleep below), but very rarely. With the delay, for me it's reproducible reliably enough, although probably not 100%. I suppose it might require different sleep times on other machines.

      diff --git a/storage/innobase/rem/rem0rec.cc b/storage/innobase/rem/rem0rec.cc
      index 37bf6e6..08cf8b8 100644
      --- a/storage/innobase/rem/rem0rec.cc
      +++ b/storage/innobase/rem/rem0rec.cc
      @@ -2179,6 +2179,7 @@ rec_get_trx_id(
              ulint* offsets = offsets_;
       
              ut_ad(trx_id_col <= MAX_REF_PARTS);
      +       my_sleep(200000);
              ut_ad(fil_page_index_page_check(page));
              ut_ad(mach_read_from_8(page + PAGE_HEADER + PAGE_INDEX_ID)
                    == index->id);
      

      Run with --mysqld=--innodb_locks_unsafe_for_binlog and, if it's not reproducible right away, with --repeat=N.

      --source include/have_innodb.inc
       
      CREATE TABLE t1 (f1 INT NOT NULL AUTO_INCREMENT PRIMARY KEY, f2 INT) ENGINE=InnoDB;
      INSERT IGNORE INTO t1 VALUES (5,9),(NULL,3),(NULL,0),(4,105),(197,66),(0,0);
      ALTER TABLE t1 ADD KEY (f1);
       
      --connect (con1,localhost,root,,test)
       
      --connection default
      --send
        INSERT IGNORE INTO t1 SELECT f1, f2 FROM t1 ORDER BY f1, f2 LIMIT 4;
       
      --connection con1
      DELETE FROM t1 ORDER BY f1, f2 LIMIT 1;
      SELECT a1.f1, a1.f2 FROM t1 AS a1, t1 AS a2;
      --disconnect con1
       
      --connection default
      --reap
       
      # Cleanup
      DROP TABLE t1;
      

      Reproducible on 10.2 and 10.3. I've never encountered it on 10.1 so far.

      10.2 0c4d11e8199f4 ASAN

      =================================================================
      ==23938==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x613000124018 at pc 0x55b828cf4a44 bp 0x7f860123dd40 sp 0x7f860123dd38
      READ of size 1 at 0x613000124018 thread T28
          #0 0x55b828cf4a43 in mach_read_from_2 /data/src/10.2-asan/storage/innobase/include/mach0data.ic:84
          #1 0x55b828d5c961 in fil_page_get_type(unsigned char const*) /data/src/10.2-asan/storage/innobase/include/fil0fil.h:1322
          #2 0x55b828f014d7 in rec_get_trx_id(unsigned char const*, dict_index_t const*) /data/src/10.2-asan/storage/innobase/rem/rem0rec.cc:2183
          #3 0x55b828fd352d in row_sel_sec_rec_is_for_clust_rec /data/src/10.2-asan/storage/innobase/row/row0sel.cc:188
          #4 0x55b828fe0492 in row_sel_get_clust_rec_for_mysql /data/src/10.2-asan/storage/innobase/row/row0sel.cc:3522
          #5 0x55b828fe72b2 in row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long) /data/src/10.2-asan/storage/innobase/row/row0sel.cc:5242
          #6 0x55b828d22b63 in ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function) /data/src/10.2-asan/storage/innobase/handler/ha_innodb.cc:9823
          #7 0x55b828d26136 in ha_innobase::index_first(unsigned char*) /data/src/10.2-asan/storage/innobase/handler/ha_innodb.cc:10261
          #8 0x55b82858807f in handler::ha_index_first(unsigned char*) /data/src/10.2-asan/sql/handler.cc:2717
          #9 0x55b8288fe18c in rr_index_first /data/src/10.2-asan/sql/records.cc:401
          #10 0x55b8280b7b5a in join_init_read_record(st_join_table*) /data/src/10.2-asan/sql/sql_select.cc:19560
          #11 0x55b8283586a5 in JOIN_TAB_SCAN::open() /data/src/10.2-asan/sql/sql_join_cache.cc:3339
          #12 0x55b82835389c in JOIN_CACHE::join_matching_records(bool) /data/src/10.2-asan/sql/sql_join_cache.cc:2250
          #13 0x55b828352922 in JOIN_CACHE::join_records(bool) /data/src/10.2-asan/sql/sql_join_cache.cc:2087
          #14 0x55b8280b041c in sub_select_cache(JOIN*, st_join_table*, bool) /data/src/10.2-asan/sql/sql_select.cc:18417
          #15 0x55b8280b092a in sub_select(JOIN*, st_join_table*, bool) /data/src/10.2-asan/sql/sql_select.cc:18589
          #16 0x55b8280af449 in do_select /data/src/10.2-asan/sql/sql_select.cc:18184
          #17 0x55b82804f912 in JOIN::exec_inner() /data/src/10.2-asan/sql/sql_select.cc:3514
          #18 0x55b82804d5a9 in JOIN::exec() /data/src/10.2-asan/sql/sql_select.cc:3309
          #19 0x55b82805098f in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /data/src/10.2-asan/sql/sql_select.cc:3709
          #20 0x55b828030a3c in handle_select(THD*, LEX*, select_result*, unsigned long) /data/src/10.2-asan/sql/sql_select.cc:373
          #21 0x55b827fb42dc in execute_sqlcom_select /data/src/10.2-asan/sql/sql_parse.cc:6428
          #22 0x55b827fa1167 in mysql_execute_command(THD*) /data/src/10.2-asan/sql/sql_parse.cc:3462
          #23 0x55b827fbc7d1 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2-asan/sql/sql_parse.cc:7869
          #24 0x55b827f97cee in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2-asan/sql/sql_parse.cc:1805
          #25 0x55b827f94d8d in do_command(THD*) /data/src/10.2-asan/sql/sql_parse.cc:1360
          #26 0x55b8282cc7a7 in do_handle_one_connection(CONNECT*) /data/src/10.2-asan/sql/sql_connect.cc:1354
          #27 0x55b8282cc1bc in handle_one_connection /data/src/10.2-asan/sql/sql_connect.cc:1260
          #28 0x55b828cd21f9 in pfs_spawn_thread /data/src/10.2-asan/storage/perfschema/pfs.cc:1863
          #29 0x7f861d702493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
          #30 0x7f861bae893e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
       
      AddressSanitizer can not describe address in more detail (wild memory access suspected).
      SUMMARY: AddressSanitizer: heap-buffer-overflow /data/src/10.2-asan/storage/innobase/include/mach0data.ic:84 mach_read_from_2
      Shadow bytes around the buggy address:
        0x0c268001c7b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c7c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c7d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c7e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c7f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
      =>0x0c268001c800: fa fa fa[fa]fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c810: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c820: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c830: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c840: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c268001c850: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
      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
      Thread T28 created by T0 here:
          #0 0x7f861d93bbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
          #1 0x55b828cd27c1 in spawn_thread_v1 /data/src/10.2-asan/storage/perfschema/pfs.cc:1913
          #2 0x55b827d9773f in inline_mysql_thread_create /data/src/10.2-asan/include/mysql/psi/mysql_thread.h:1239
          #3 0x55b827dac56b in create_thread_to_handle_connection(CONNECT*) /data/src/10.2-asan/sql/mysqld.cc:6445
          #4 0x55b827dacc70 in create_new_thread /data/src/10.2-asan/sql/mysqld.cc:6515
          #5 0x55b827dadc81 in handle_connections_sockets() /data/src/10.2-asan/sql/mysqld.cc:6790
          #6 0x55b827dabab8 in mysqld_main(int, char**) /data/src/10.2-asan/sql/mysqld.cc:6064
          #7 0x55b827d95c6f in main /data/src/10.2-asan/sql/main.cc:25
          #8 0x7f861ba202b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
       
      ==23938==ABORTING
      

        Attachments

          Activity

            People

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

              Dates

              Created:
              Updated:
              Resolved: