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

InnoDB: Failing assertion: (block)->index || (block)->n_pointers == 0

Details

    Description

      Problem found during RQG testing.
       Version: '10.4.7-MariaDB-debug-log'  socket: '/dev/shm/vardir/1564417709/8/1/mysql.sock'  port: 19440  Source distribution
       2019-07-29 18:29:01 0x7f55a004c700  InnoDB: Assertion failure in file /work/10.4/storage/innobase/btr/btr0sea.cc line 1824
       InnoDB: Failing assertion: (block)->index || (block)->n_pointers == 0
      ...
      Query (0x7fc228011190): INSERT INTO t3 (col1,col2) VALUES ( 2241, 2241 ) /* E_R Thread3 QNO 7611 CON_ID 18 */
      Connection ID (thread ID): 18
      Status: NOT_KILLED
       
      In case I start the server with
           innodb_adaptive_hash_index=off
      than the test passes.
      

      Attachments

        1. simp_MDEV-20203.cfg
          37 kB
        2. Seven.yy
          1 kB
        3. 000000.log
          74 kB

        Issue Links

          Activity

            The bug was observed again on
            origin/10.6 b0d38448a176dc990554c7dd5b184c3ebe64be8b 2021-08-19T16:35:44+05:30
             
            RQG
            ====
            --------------------------------------
            git clone https://github.com/mleich1/rqg --branch experimental RQG
             
            perl rqg.pl \
            --grammar=conf/engines/many_indexes.yy \
            --gendata=conf/engines/many_indexes.zz \
            --reporters=RestartConsistencyRR \                     #    Experimental derivate of RestartConsistency, but RestartConsistency replays too
            --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
            --mysqld=--loose-idle_write_transaction_timeout=0 \
            --mysqld=--loose-idle_transaction_timeout=0 \
            --mysqld=--loose-idle_readonly_transaction_timeout=0 \
            --mysqld=--connect_timeout=60 \
            --mysqld=--interactive_timeout=28800 \
            --mysqld=--slave_net_timeout=60 \
            --mysqld=--net_read_timeout=30 \
            --mysqld=--net_write_timeout=60 \
            --mysqld=--loose-table_lock_wait_timeout=50 \
            --mysqld=--wait_timeout=28800 \
            --mysqld=--lock-wait-timeout=86400 \
            --mysqld=--innodb-lock-wait-timeout=50 \
            --no-mask \
            --queries=10000000 \
            --seed=random \
            --reporters=Backtrace \
            --reporters=ErrorLog \
            --reporters=Deadlock1 \
            --validators=None \
            --mysqld=--log_output=none \
            --mysqld=--log_bin_trust_function_creators=1 \
            --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
            --engine=InnoDB \
            --restart_timeout=240 \
            --mysqld=--plugin-load-add=file_key_management.so \
            --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
            --duration=150 \
            --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
            --mysqld=--innodb_stats_persistent=on \
            --mysqld=--innodb_adaptive_hash_index=on \
            --mysqld=--log-bin \
            --mysqld=--sync-binlog=1 \
            --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
            --mysqld=--loose-max-statement-time=30 \
            --threads=9 \
            --mysqld=--innodb_use_native_aio=1 \
            --mysqld=--innodb_undo_tablespaces=3 \
            --mysqld=--innodb_undo_log_truncate=ON \
            --mysqld=--innodb_page_size=16K \
            --mysqld=--innodb-buffer-pool-size=8M \
            --no_mask \
            --workdir=<local settings>
            --vardir=<local settings>
            --mtr-build-thread=<local settings>
            --basedir1=<local settings>
            --script_debug=_nix_
             
            The test above replays MDEV-26450 far way more often.
            

            mleich Matthias Leich added a comment - The bug was observed again on origin/10.6 b0d38448a176dc990554c7dd5b184c3ebe64be8b 2021-08-19T16:35:44+05:30   RQG ==== -------------------------------------- git clone https://github.com/mleich1/rqg --branch experimental RQG   perl rqg.pl \ --grammar=conf/engines/many_indexes.yy \ --gendata=conf/engines/many_indexes.zz \ --reporters=RestartConsistencyRR \ # Experimental derivate of RestartConsistency, but RestartConsistency replays too --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \ --mysqld=--loose-idle_write_transaction_timeout=0 \ --mysqld=--loose-idle_transaction_timeout=0 \ --mysqld=--loose-idle_readonly_transaction_timeout=0 \ --mysqld=--connect_timeout=60 \ --mysqld=--interactive_timeout=28800 \ --mysqld=--slave_net_timeout=60 \ --mysqld=--net_read_timeout=30 \ --mysqld=--net_write_timeout=60 \ --mysqld=--loose-table_lock_wait_timeout=50 \ --mysqld=--wait_timeout=28800 \ --mysqld=--lock-wait-timeout=86400 \ --mysqld=--innodb-lock-wait-timeout=50 \ --no-mask \ --queries=10000000 \ --seed=random \ --reporters=Backtrace \ --reporters=ErrorLog \ --reporters=Deadlock1 \ --validators=None \ --mysqld=--log_output=none \ --mysqld=--log_bin_trust_function_creators=1 \ --mysqld=--loose-debug_assert_on_not_freed_memory=0 \ --engine=InnoDB \ --restart_timeout=240 \ --mysqld=--plugin-load-add=file_key_management.so \ --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \ --duration=150 \ --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \ --mysqld=--innodb_stats_persistent=on \ --mysqld=--innodb_adaptive_hash_index=on \ --mysqld=--log-bin \ --mysqld=--sync-binlog=1 \ --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \ --mysqld=--loose-max-statement-time=30 \ --threads=9 \ --mysqld=--innodb_use_native_aio=1 \ --mysqld=--innodb_undo_tablespaces=3 \ --mysqld=--innodb_undo_log_truncate=ON \ --mysqld=--innodb_page_size=16K \ --mysqld=--innodb-buffer-pool-size=8M \ --no_mask \ --workdir=<local settings> --vardir=<local settings> --mtr-build-thread=<local settings> --basedir1=<local settings> --script_debug=_nix_   The test above replays MDEV-26450 far way more often.

            Sorry, I was too slow. While the trace is still there, the executable has been lost or moved:

            marko@pluto:~$ rr replay /data/results/1641558610/MDEV-20203/run/user/1001/1641558610/202/1/rr/latest-trace
            [FATAL /home/roc/rr/rr/src/TraceStream.cc:1146:read_mapped_region() errno: ENOENT] Failed to stat /data/Server_bin/preview-10.8-MDEV-14425-innodbC_asan/bin/mariadbd: replay is impossible
            

            marko Marko Mäkelä added a comment - Sorry, I was too slow. While the trace is still there, the executable has been lost or moved: marko@pluto:~$ rr replay /data/results/1641558610/MDEV-20203/run/user/1001/1641558610/202/1/rr/latest-trace [FATAL /home/roc/rr/rr/src/TraceStream.cc:1146:read_mapped_region() errno: ENOENT] Failed to stat /data/Server_bin/preview-10.8-MDEV-14425-innodbC_asan/bin/mariadbd: replay is impossible

            origin/bb-10.10-MDEV-11026 2acc2601910d5292f1ea46e06e5affeb56dc8010 2022-06-10T14:05:00+03:00
            pluto:/data/results/1655120660/MDEV-20203$ _RR_TRACE_DIR=./1/rr/ rr replay
            2022-06-13 13:53:51 0x7f440a0fb700  InnoDB: Assertion failure in file /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc line 699
            InnoDB: Failing assertion: (block)->index || (block)->n_pointers == 0
             
            (rr) bt
            #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
            #1  0x00007f442b7f6859 in __GI_abort () at abort.c:79
            #2  0x00005654610a901d in ut_dbg_assertion_failed (expr=0x5654622d7380 "(block)->index || (block)->n_pointers == 0", file=0x5654622d6720 "/data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc", line=699)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/ut/ut0dbg.cc:60
            #3  0x000056546114509c in btr_search_update_hash_ref (info=0x61a00006f9a0, block=0x7f441ee97790, cursor=0x6230001a2868) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:699
            #4  0x000056546114ae08 in btr_search_info_update_slow (info=0x61a00006f9a0, cursor=0x6230001a2868) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:1695
            #5  0x00005654611012b3 in btr_search_info_update (index=0x616000a8b508, cursor=0x6230001a2868) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0sea.inl:83
            #6  0x000056546110e6a6 in btr_cur_search_to_nth_level_func (index=0x616000a8b508, level=0, tuple=0x6230001a2e20, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x6230001a2868, ahi_latch=0x0, mtr=0x7f440a0f7b10, autoinc=0)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0cur.cc:2413
            #7  0x0000565460fa1836 in btr_pcur_open_with_no_init_func (index=0x616000a8b508, tuple=0x6230001a2e20, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x6230001a2868, ahi_latch=0x0, mtr=0x7f440a0f7b10)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0pcur.inl:390
            #8  0x0000565460fb3aae in Row_sel_get_clust_rec_for_mysql::operator() (this=0x7f440a0f70f0, prebuilt=0x6230001a2588, sec_index=0x616000a92108, rec=0x7f441eeb8b2c "", thr=0x6230001a3028, out_rec=0x7f440a0f6ff0, 
                offsets=0x7f440a0f7050, offset_heap=0x7f440a0f7030, vrow=0x0, mtr=0x7f440a0f7b10) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/row/row0sel.cc:3352
            #9  0x0000565460fc1467 in row_search_mvcc (buf=0x6260001dd122 "", mode=PAGE_CUR_G, prebuilt=0x6230001a2588, match_mode=0, direction=1) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/row/row0sel.cc:5466
            #10 0x0000565460bafd31 in ha_innobase::general_fetch (this=0x61d0008ca0b8, buf=0x6260001dd122 "", direction=1, match_mode=0) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/handler/ha_innodb.cc:9243
            #11 0x0000565460bb0326 in ha_innobase::index_next (this=0x61d0008ca0b8, buf=0x6260001dd122 "") at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/handler/ha_innodb.cc:9298
            #12 0x0000565460307239 in handler::ha_index_next (this=0x61d0008ca0b8, buf=0x6260001dd122 "") at /data/Server/bb-10.10-MDEV-11026A/sql/handler.cc:3522
            #13 0x0000565460ab8d9c in ha_partition::handle_ordered_next (this=0x61d0008c96b8, buf=0x626000165138 "", is_next_same=false) at /data/Server/bb-10.10-MDEV-11026A/sql/ha_partition.cc:8302
            #14 0x0000565460aa8774 in ha_partition::index_next (this=0x61d0008c96b8, buf=0x626000165138 "") at /data/Server/bb-10.10-MDEV-11026A/sql/ha_partition.cc:6135
            #15 0x0000565460307239 in handler::ha_index_next (this=0x61d0008c96b8, buf=0x626000165138 "") at /data/Server/bb-10.10-MDEV-11026A/sql/handler.cc:3522
            #16 0x000056545fc2a2f6 in join_read_next (info=0x629000e99f00) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:22329
            #17 0x000056545f7f4b00 in READ_RECORD::read_record (this=0x629000e99f00) at /data/Server/bb-10.10-MDEV-11026A/sql/records.h:81
            #18 0x000056545fc23476 in sub_select (join=0x629000e98b38, join_tab=0x629000e99e38, end_of_records=false) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:21297
            #19 0x000056545fc21afd in do_select (join=0x629000e98b38, procedure=0x0) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:20823
            #20 0x000056545fbb2837 in JOIN::exec_inner (this=0x629000e98b38) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:4787
            #21 0x000056545fbb0080 in JOIN::exec (this=0x629000e98b38) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:4565
            #22 0x000056545fbb3c9e in mysql_select (thd=0x62b00021b218, tables=0x629000e97af8, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x629000e98b08, 
                unit=0x62b00021f438, select_lex=0x629000e97390) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:5045
            #23 0x000056545fb88b21 in handle_select (thd=0x62b00021b218, lex=0x62b00021f360, result=0x629000e98b08, setup_tables_done_option=0) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:579
            #24 0x000056545facabb8 in execute_sqlcom_select (thd=0x62b00021b218, all_tables=0x629000e97af8) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:6260
            #25 0x000056545fab9832 in mysql_execute_command (thd=0x62b00021b218, is_called_from_prepared_stmt=false) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:3944
            #26 0x000056545fad4c44 in mysql_parse (thd=0x62b00021b218, rawbuf=0x629000e97238 "SELECT `col_varchar_255_ucs2_key` FROM `table100_innodb_key_pk_parts_2_int_autoinc` /* E_R Thread3 QNO 13 CON_ID 21 */", length=118, 
                parser_state=0x7f440a0f9b10) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:8036
            #27 0x000056545faace0c in dispatch_command (command=COM_QUERY, thd=0x62b00021b218, packet=0x629000e8d219 "", packet_length=119, blocking=true) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:1894
            #28 0x000056545faaa253 in do_command (thd=0x62b00021b218, blocking=true) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:1407
            #29 0x000056545feee367 in do_handle_one_connection (connect=0x608000003138, put_in_cache=true) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_connect.cc:1418
            #30 0x000056545feedbf3 in handle_one_connection (arg=0x608000003138) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_connect.cc:1312
            #31 0x00007f442bd20609 in start_thread (arg=<optimized out>) at pthread_create.c:477
            #32 0x00007f442b8f3293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
            (rr) quit
             
            origin/bb-10.8-MDEV-27716 81ab5d74e5f2bdbb5b7f495c74113a9bbb63376f 2022-02-04T11:02:12+02:00
            pluto:/data/results/1643977579/MDEV-20203/dev/shm/rqg/1643977579/256/1/rr
            2022-02-04 15:29:36 0x7f178ed43700  InnoDB: Assertion failure in file /data/Server/bb-10.8-MDEV-27716A/storage/innobase/btr/btr0sea.cc line 699
            InnoDB: Failing assertion: (block)->index || (block)->n_pointers == 0
            

            mleich Matthias Leich added a comment - origin/bb-10.10-MDEV-11026 2acc2601910d5292f1ea46e06e5affeb56dc8010 2022-06-10T14:05:00+03:00 pluto:/data/results/1655120660/MDEV-20203$ _RR_TRACE_DIR=./1/rr/ rr replay 2022-06-13 13:53:51 0x7f440a0fb700 InnoDB: Assertion failure in file /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc line 699 InnoDB: Failing assertion: (block)->index || (block)->n_pointers == 0   (rr) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00007f442b7f6859 in __GI_abort () at abort.c:79 #2 0x00005654610a901d in ut_dbg_assertion_failed (expr=0x5654622d7380 "(block)->index || (block)->n_pointers == 0", file=0x5654622d6720 "/data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc", line=699) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/ut/ut0dbg.cc:60 #3 0x000056546114509c in btr_search_update_hash_ref (info=0x61a00006f9a0, block=0x7f441ee97790, cursor=0x6230001a2868) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:699 #4 0x000056546114ae08 in btr_search_info_update_slow (info=0x61a00006f9a0, cursor=0x6230001a2868) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:1695 #5 0x00005654611012b3 in btr_search_info_update (index=0x616000a8b508, cursor=0x6230001a2868) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0sea.inl:83 #6 0x000056546110e6a6 in btr_cur_search_to_nth_level_func (index=0x616000a8b508, level=0, tuple=0x6230001a2e20, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x6230001a2868, ahi_latch=0x0, mtr=0x7f440a0f7b10, autoinc=0) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0cur.cc:2413 #7 0x0000565460fa1836 in btr_pcur_open_with_no_init_func (index=0x616000a8b508, tuple=0x6230001a2e20, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x6230001a2868, ahi_latch=0x0, mtr=0x7f440a0f7b10) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0pcur.inl:390 #8 0x0000565460fb3aae in Row_sel_get_clust_rec_for_mysql::operator() (this=0x7f440a0f70f0, prebuilt=0x6230001a2588, sec_index=0x616000a92108, rec=0x7f441eeb8b2c "", thr=0x6230001a3028, out_rec=0x7f440a0f6ff0, offsets=0x7f440a0f7050, offset_heap=0x7f440a0f7030, vrow=0x0, mtr=0x7f440a0f7b10) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/row/row0sel.cc:3352 #9 0x0000565460fc1467 in row_search_mvcc (buf=0x6260001dd122 "", mode=PAGE_CUR_G, prebuilt=0x6230001a2588, match_mode=0, direction=1) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/row/row0sel.cc:5466 #10 0x0000565460bafd31 in ha_innobase::general_fetch (this=0x61d0008ca0b8, buf=0x6260001dd122 "", direction=1, match_mode=0) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/handler/ha_innodb.cc:9243 #11 0x0000565460bb0326 in ha_innobase::index_next (this=0x61d0008ca0b8, buf=0x6260001dd122 "") at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/handler/ha_innodb.cc:9298 #12 0x0000565460307239 in handler::ha_index_next (this=0x61d0008ca0b8, buf=0x6260001dd122 "") at /data/Server/bb-10.10-MDEV-11026A/sql/handler.cc:3522 #13 0x0000565460ab8d9c in ha_partition::handle_ordered_next (this=0x61d0008c96b8, buf=0x626000165138 "", is_next_same=false) at /data/Server/bb-10.10-MDEV-11026A/sql/ha_partition.cc:8302 #14 0x0000565460aa8774 in ha_partition::index_next (this=0x61d0008c96b8, buf=0x626000165138 "") at /data/Server/bb-10.10-MDEV-11026A/sql/ha_partition.cc:6135 #15 0x0000565460307239 in handler::ha_index_next (this=0x61d0008c96b8, buf=0x626000165138 "") at /data/Server/bb-10.10-MDEV-11026A/sql/handler.cc:3522 #16 0x000056545fc2a2f6 in join_read_next (info=0x629000e99f00) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:22329 #17 0x000056545f7f4b00 in READ_RECORD::read_record (this=0x629000e99f00) at /data/Server/bb-10.10-MDEV-11026A/sql/records.h:81 #18 0x000056545fc23476 in sub_select (join=0x629000e98b38, join_tab=0x629000e99e38, end_of_records=false) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:21297 #19 0x000056545fc21afd in do_select (join=0x629000e98b38, procedure=0x0) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:20823 #20 0x000056545fbb2837 in JOIN::exec_inner (this=0x629000e98b38) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:4787 #21 0x000056545fbb0080 in JOIN::exec (this=0x629000e98b38) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:4565 #22 0x000056545fbb3c9e in mysql_select (thd=0x62b00021b218, tables=0x629000e97af8, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x629000e98b08, unit=0x62b00021f438, select_lex=0x629000e97390) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:5045 #23 0x000056545fb88b21 in handle_select (thd=0x62b00021b218, lex=0x62b00021f360, result=0x629000e98b08, setup_tables_done_option=0) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_select.cc:579 #24 0x000056545facabb8 in execute_sqlcom_select (thd=0x62b00021b218, all_tables=0x629000e97af8) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:6260 #25 0x000056545fab9832 in mysql_execute_command (thd=0x62b00021b218, is_called_from_prepared_stmt=false) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:3944 #26 0x000056545fad4c44 in mysql_parse (thd=0x62b00021b218, rawbuf=0x629000e97238 "SELECT `col_varchar_255_ucs2_key` FROM `table100_innodb_key_pk_parts_2_int_autoinc` /* E_R Thread3 QNO 13 CON_ID 21 */", length=118, parser_state=0x7f440a0f9b10) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:8036 #27 0x000056545faace0c in dispatch_command (command=COM_QUERY, thd=0x62b00021b218, packet=0x629000e8d219 "", packet_length=119, blocking=true) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:1894 #28 0x000056545faaa253 in do_command (thd=0x62b00021b218, blocking=true) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_parse.cc:1407 #29 0x000056545feee367 in do_handle_one_connection (connect=0x608000003138, put_in_cache=true) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_connect.cc:1418 #30 0x000056545feedbf3 in handle_one_connection (arg=0x608000003138) at /data/Server/bb-10.10-MDEV-11026A/sql/sql_connect.cc:1312 #31 0x00007f442bd20609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #32 0x00007f442b8f3293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 (rr) quit   origin/bb-10.8-MDEV-27716 81ab5d74e5f2bdbb5b7f495c74113a9bbb63376f 2022-02-04T11:02:12+02:00 pluto:/data/results/1643977579/MDEV-20203/dev/shm/rqg/1643977579/256/1/rr 2022-02-04 15:29:36 0x7f178ed43700 InnoDB: Assertion failure in file /data/Server/bb-10.8-MDEV-27716A/storage/innobase/btr/btr0sea.cc line 699 InnoDB: Failing assertion: (block)->index || (block)->n_pointers == 0

            There is a race condition around the assertion. Right after the time the crashing thread was reading block->index, another thread had created an adaptive hash index for the block.

            bb-10.10-MDEV-11026 2acc2601910d5292f1ea46e06e5affeb56dc8010

            #0  0x000056546114a7ad in btr_search_build_page_hash_index (
                index=0x616000a8b508, block=0x7f441ee97790, ahi_latch=0x615000003b40, 
                n_fields=1, n_bytes=0, left_side=false)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:1642
            #1  0x000056546114af27 in btr_search_info_update_slow (info=0x61a00006f9a0, 
                cursor=0x7f440d0e4c70)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:1702
            #2  0x00005654611012b3 in btr_search_info_update (index=0x616000a8b508, 
                cursor=0x7f440d0e4c70)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0sea.inl:83
            #3  0x000056546110e6a6 in btr_cur_search_to_nth_level_func (
                index=0x616000a8b508, level=0, tuple=0x6130001ddcc8, mode=PAGE_CUR_LE, 
                latch_mode=1, cursor=0x7f440d0e4c70, ahi_latch=0x0, mtr=0x7f440d0e4e60, 
                autoinc=0)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0cur.cc:2413
            #4  0x0000565460bf47cd in btr_pcur_open_low (index=0x616000a8b508, level=0, 
                tuple=0x6130001ddcc8, mode=PAGE_CUR_LE, latch_mode=1, 
                cursor=0x7f440d0e4c70, autoinc=0, mtr=0x7f440d0e4e60)
                at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0pcur.inl:346
            

            In other words, this particular failure looks like a failure of a bogus debug assertion and not a real error. There are other occurrences of assert_block_ahi_valid() that look equally racey (not protected by the AHI partition latch). One is located right at the start of btr_search_drop_page_hash_index() and even documented as being buggy:

            void btr_search_drop_page_hash_index(buf_block_t* block)
            {
            	ulint			n_fields;
            	ulint			n_bytes;
            	const rec_t*		rec;
            	mem_heap_t*		heap;
            	rec_offs*		offsets;
             
            retry:
            	/* This debug check uses a dirty read that could theoretically cause
            	false positives while buf_pool.clear_hash_index() is executing. */
            	assert_block_ahi_valid(block);
            

            I think that these bogus assertions would best be fixed (or removed) as part of MDEV-27700.

            marko Marko Mäkelä added a comment - There is a race condition around the assertion. Right after the time the crashing thread was reading block->index , another thread had created an adaptive hash index for the block. bb-10.10-MDEV-11026 2acc2601910d5292f1ea46e06e5affeb56dc8010 #0 0x000056546114a7ad in btr_search_build_page_hash_index ( index=0x616000a8b508, block=0x7f441ee97790, ahi_latch=0x615000003b40, n_fields=1, n_bytes=0, left_side=false) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:1642 #1 0x000056546114af27 in btr_search_info_update_slow (info=0x61a00006f9a0, cursor=0x7f440d0e4c70) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0sea.cc:1702 #2 0x00005654611012b3 in btr_search_info_update (index=0x616000a8b508, cursor=0x7f440d0e4c70) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0sea.inl:83 #3 0x000056546110e6a6 in btr_cur_search_to_nth_level_func ( index=0x616000a8b508, level=0, tuple=0x6130001ddcc8, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x7f440d0e4c70, ahi_latch=0x0, mtr=0x7f440d0e4e60, autoinc=0) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/btr/btr0cur.cc:2413 #4 0x0000565460bf47cd in btr_pcur_open_low (index=0x616000a8b508, level=0, tuple=0x6130001ddcc8, mode=PAGE_CUR_LE, latch_mode=1, cursor=0x7f440d0e4c70, autoinc=0, mtr=0x7f440d0e4e60) at /data/Server/bb-10.10-MDEV-11026A/storage/innobase/include/btr0pcur.inl:346 In other words, this particular failure looks like a failure of a bogus debug assertion and not a real error. There are other occurrences of assert_block_ahi_valid() that look equally racey (not protected by the AHI partition latch). One is located right at the start of btr_search_drop_page_hash_index() and even documented as being buggy: void btr_search_drop_page_hash_index(buf_block_t* block) { ulint n_fields; ulint n_bytes; const rec_t* rec; mem_heap_t* heap; rec_offs* offsets;   retry: /* This debug check uses a dirty read that could theoretically cause false positives while buf_pool.clear_hash_index() is executing. */ assert_block_ahi_valid(block); I think that these bogus assertions would best be fixed (or removed) as part of MDEV-27700 .

            We still have a possibly bogus assert_block_ahi_valid(block) at the start of the function btr_search_update_hash_ref(). The function btr_search_drop_page_hash_index() has been cleaned up.

            marko Marko Mäkelä added a comment - We still have a possibly bogus assert_block_ahi_valid(block) at the start of the function btr_search_update_hash_ref() . The function btr_search_drop_page_hash_index() has been cleaned up.

            People

              thiru Thirunarayanan Balathandayuthapani
              mleich Matthias Leich
              Votes:
              1 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.