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

mysqld: storage/innobase/include/ut0rnd.ic:142: ulint ut_fold_string(const char*): Assertion `str' failed.

Details

    Description

      Assert hit during RQG testing on
      		 
      10.3 4cdb72f2372b27e1fbbc573812240c1e29128c8f 2019-10-10
      		 
      innodb-evict-tables-on-commit-debug was set to 1.
      		 
      The setting of innodb_adaptive_hash_index has no impact.
      		 
      In case I do not set innodb-evict-tables-on-commit-debug to 1 than the assert will not show up.
      		 
       
      		 
      Version: '10.3.19-MariaDB-debug-log'  socket: ... 
      # 2019-10-11T01:20:48 [50100] | mysqld: /work/10.3/storage/innobase/include/ut0rnd.ic:142: ulint ut_fold_string(const char*): Assertion `str' failed.
      		 
       
      		 
      # 2019-10-11T01:20:48 [50100] | Thread pointer: 0x7fdbf0000a98
      		 
      # 2019-10-11T01:20:48 [50100] | Attempting backtrace. You can use the following information to find out
      		 
      # 2019-10-11T01:20:48 [50100] | where mysqld died. If you see no messages after this, something went
      		 
      # 2019-10-11T01:20:48 [50100] | terribly wrong...
      		 
      # 2019-10-11T01:20:48 [50100] | stack_bottom = 0x7fdc903fbec0 thread_stack 0x49000
      		 
      # 2019-10-11T01:20:48 [50100] | /work/10.3/bld_debug/sql/mysqld(my_print_stacktrace+0x40)[0x561b0139cf52]
      		 
      # 2019-10-11T01:20:48 [50100] | mysys/stacktrace.c:269(my_print_stacktrace)[0x561b00ad23f5]
      		 
      # 2019-10-11T01:20:48 [50100] | /lib/x86_64-linux-gnu/libpthread.so.0(+0x11670)[0x7fdc9463a670]
      		 
      # 2019-10-11T01:20:48 [50100] | linux/raise.c:58(__GI_raise)[0x7fdc939ef77f]
      		 
      # 2019-10-11T01:20:48 [50100] | stdlib/abort.c:91(__GI_abort)[0x7fdc939f137a]
      		 
      # 2019-10-11T01:20:48 [50100] | assert/assert.c:92(__assert_fail_base)[0x7fdc939e7b47]
      		 
      # 2019-10-11T01:20:48 [50100] | /lib/x86_64-linux-gnu/libc.so.6(+0x2dbf2)[0x7fdc939e7bf2]
      		 
      # 2019-10-11T01:20:48 [50100] | /work/10.3/bld_debug/sql/mysqld(+0xf72862)[0x561b01058862]
      		 
      # 2019-10-11T01:20:48 [50100] | include/ut0rnd.ic:144(ut_fold_string(char const*))[0x561b01064fa9]
      		 
      # 2019-10-11T01:20:48 [50100] | dict/dict0dict.cc:1999(dict_table_remove_from_cache_low(dict_table_t*, unsigned long))[0x561b00f78db7]
      		 
      # 2019-10-11T01:20:48 [50100] | trx/trx0trx.cc:1306(trx_update_mod_tables_timestamp(trx_t*))[0x561b00f7953d]
      		 
      # 2019-10-11T01:20:48 [50100] | trx/trx0trx.cc:1389(trx_commit_in_memory(trx_t*, mtr_t const*))[0x561b00f7a9a3]
      		 
      # 2019-10-11T01:20:48 [50100] | trx/trx0trx.cc:1586(trx_commit_low(trx_t*, mtr_t*))[0x561b00f7aa5b]
      		 
      # 2019-10-11T01:20:48 [50100] | trx/trx0trx.cc:1596(trx_commit(trx_t*))[0x561b00f7af0a]
      		 
      # 2019-10-11T01:20:48 [50100] | trx/trx0trx.cc:1747(trx_commit_for_mysql(trx_t*))[0x561b00cfb182]
      		 
      # 2019-10-11T01:20:48 [50100] | handler/ha_innodb.cc:4408(innobase_commit_low(trx_t*))[0x561b00cfb57a]
      		 
      # 2019-10-11T01:20:48 [50100] | handler/ha_innodb.cc:4522(innobase_commit_ordered_2(trx_t*, THD*))[0x561b00cfbbab]
      		 
      # 2019-10-11T01:20:48 [50100] | handler/ha_innodb.cc:4646(innobase_commit(handlerton*, THD*, bool))[0x561b00ad6b0b]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/handler.cc:1641(commit_one_phase_2(THD*, bool, THD_TRANS*, bool))[0x561b00ad6a07]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/handler.cc:1621(ha_commit_one_phase(THD*, bool))[0x561b00ad60c4]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/handler.cc:1483(ha_commit_trans(THD*, bool))[0x561b009415a9]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/transaction.cc:292(trans_commit(THD*))[0x561b007c368a]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/sql_parse.cc:5519(mysql_execute_command(THD*))[0x561b007caad1]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/sql_parse.cc:7829(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x561b007b770b]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/sql_parse.cc:1857(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x561b007b6053]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/sql_parse.cc:1400(do_command(THD*))[0x561b0092cd64]
      		 
      # 2019-10-11T01:20:48 [50100] | sql/sql_connect.cc:1403(do_handle_one_connection(CONNECT*))[0x561b0092cac6]
      		 
      # 2019-10-11T01:20:48 [50100] | nptl/pthread_create.c:456(start_thread)[0x7fdc946306da]
      		 
      # 2019-10-11T01:20:48 [50100] | x86_64/clone.S:107(clone)[0x7fdc93ac2d7f]
      		 
       
      		 
      # 2019-10-11T01:20:48 [50100] | Query (0x7fdbf0010890): COMMIT /* E_R Thread2 QNO 327 CON_ID 18 */
      		 
      # 2019-10-11T01:20:48 [50100] | Connection ID (thread ID): 18
      		 
      # 2019-10-11T01:20:48 [50100] | Status: NOT_KILLED
      		 
       
      		 
      I will add more information and some simplified replay test soon.

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-24811 Assertion `find(table)' failed in dict_sys_t::remove upon concurrent COMMIT with innodb_evict_tables_on_commit_debug

          • Major - Major loss of function.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            mleich Matthias Leich added a comment - 

            simp_ut_fold_string.yy is my simplified RQG grammar.
            		 
            There are only 3 concurrent sessions required.

            mleich Matthias Leich added a comment - simp_ut_fold_string.yy is my simplified RQG grammar. There are only 3 concurrent sessions required.
            marko Marko Mäkelä added a comment -

            mleich, I think that this could be a sign of bigger trouble, even when that debug variable is not set.
            Can you please try the following patch?

            diff --git a/storage/innobase/trx/trx0trx.cc b/storage/innobase/trx/trx0trx.cc
            		 
            index 2c672dd24fa..155ae9e9dd5 100644
            		 
            --- a/storage/innobase/trx/trx0trx.cc
            		 
            +++ b/storage/innobase/trx/trx0trx.cc
            		 
            @@ -1285,6 +1285,7 @@ trx_update_mod_tables_timestamp(
            		 
             		protecting it with a latch here would be too performance
            		 
             		intrusive. */
            		 
             		dict_table_t* table = it->first;
            		 
            +		ut_a(table->name.m_name);
            		 
             		table->update_time = now;
            		 
             #ifdef UNIV_DEBUG
            		 
             		if (preserve_tables || table->get_ref_count()) {

            Does it fail when the debug parameter is not set? The patch should be valid for both release and debug builds.

            marko Marko Mäkelä added a comment - mleich , I think that this could be a sign of bigger trouble, even when that debug variable is not set. Can you please try the following patch? diff --git a/storage/innobase/trx/trx0trx.cc b/storage/innobase/trx/trx0trx.cc index 2c672dd24fa..155ae9e9dd5 100644 --- a/storage/innobase/trx/trx0trx.cc +++ b/storage/innobase/trx/trx0trx.cc @@ -1285,6 +1285,7 @@ trx_update_mod_tables_timestamp( protecting it with a latch here would be too performance intrusive. */ dict_table_t* table = it->first; + ut_a(table->name.m_name); table->update_time = now; #ifdef UNIV_DEBUG if (preserve_tables || table->get_ref_count()) { Does it fail when the debug parameter is not set? The patch should be valid for both release and debug builds.
            marko Marko Mäkelä added a comment -

            It seems that a hack related to adding or dropping GENERATED columns (persistent or virtual) in ha_innobase::commit_inplace_alter_table() could conflict with DML transaction commit:

            	/* MDEV-17468: Avoid this at least when ctx->is_instant().
            		 
            	Currently dict_load_column_low() is the only place where
            		 
            	num_base for virtual columns is assigned to nonzero. */
            		 
            	if (ctx0->num_to_drop_vcol || ctx0->num_to_add_vcol) {
            		 
            		DBUG_ASSERT(ctx0->old_table->get_ref_count() == 1);
            		 
             
            		 
            		trx_commit_for_mysql(m_prebuilt->trx);
            		 
            #ifdef BTR_CUR_HASH_ADAPT
            		 
            		if (btr_search_enabled) {
            		 
            			btr_search_disable(false);
            		 
            			btr_search_enable();
            		 
            		}
            		 
            #endif /* BTR_CUR_HASH_ADAPT */
            		 
             
            		 
            		char	tb_name[FN_REFLEN];
            		 
            		ut_strcpy(tb_name, m_prebuilt->table->name.m_name);
            		 
             
            		 
            		tb_name[strlen(m_prebuilt->table->name.m_name)] = 0;
            		 
             
            		 
            		dict_table_close(m_prebuilt->table, true, false);
            		 
            		if (ctx0->is_instant()) {
            		 
            			for (unsigned i = ctx0->old_n_v_cols; i--; ) {
            		 
            				ctx0->old_v_cols[i].~dict_v_col_t();
            		 
            			}
            		 
            			const_cast<unsigned&>(ctx0->old_n_v_cols) = 0;
            		 
            		}
            		 
            		dict_sys.remove(m_prebuilt->table);
            		 
            		m_prebuilt->table = dict_table_open_on_name(
            		 
            			tb_name, TRUE, TRUE, DICT_ERR_IGNORE_NONE);

            I do not know the exact mechanism for the failure, but I would for now suggest to avoid setting innodb_evict_tables_on_commit_debug while executing DML transactions concurrently with ALTER TABLE that add or drop GENERATED columns.

            marko Marko Mäkelä added a comment - It seems that a hack related to adding or dropping GENERATED columns (persistent or virtual) in ha_innobase::commit_inplace_alter_table() could conflict with DML transaction commit: /* MDEV-17468: Avoid this at least when ctx->is_instant(). Currently dict_load_column_low() is the only place where num_base for virtual columns is assigned to nonzero. */ if (ctx0->num_to_drop_vcol || ctx0->num_to_add_vcol) { DBUG_ASSERT(ctx0->old_table->get_ref_count() == 1);   trx_commit_for_mysql(m_prebuilt->trx); #ifdef BTR_CUR_HASH_ADAPT if (btr_search_enabled) { btr_search_disable( false ); btr_search_enable(); } #endif /* BTR_CUR_HASH_ADAPT */   char tb_name[FN_REFLEN]; ut_strcpy(tb_name, m_prebuilt->table->name.m_name);   tb_name[ strlen (m_prebuilt->table->name.m_name)] = 0;   dict_table_close(m_prebuilt->table, true , false ); if (ctx0->is_instant()) { for (unsigned i = ctx0->old_n_v_cols; i--; ) { ctx0->old_v_cols[i].~dict_v_col_t(); } const_cast <unsigned&>(ctx0->old_n_v_cols) = 0; } dict_sys. remove (m_prebuilt->table); m_prebuilt->table = dict_table_open_on_name( tb_name, TRUE, TRUE, DICT_ERR_IGNORE_NONE); I do not know the exact mechanism for the failure, but I would for now suggest to avoid setting innodb_evict_tables_on_commit_debug while executing DML transactions concurrently with ALTER TABLE that add or drop GENERATED columns.
            marko Marko Mäkelä added a comment -

            It could be that the innodb_evict_tables_on_commit_debug=ON simply suffers from a race condition when another thread is evicting the table at the same time.

            marko Marko Mäkelä added a comment - It could be that the innodb_evict_tables_on_commit_debug=ON simply suffers from a race condition when another thread is evicting the table at the same time.
            marko Marko Mäkelä added a comment -

            This should be fixed in MDEV-24811.

            marko Marko Mäkelä added a comment - This should be fixed in MDEV-24811 .
            mleich Matthias Leich added a comment - 

            No replay of that problem with
            		 
            - ~ 4900 RQG tests with the RQG grammar simp_ut_fold_string.yy
            		 
            - origin/10.3 86c1bf118a48dd0bab80346f6d65c112ab2e486d 2022-03-07T16:42:05+03:00
            		 
               10.3.35
            		 
            Therefore I close the bug.

            mleich Matthias Leich added a comment - No replay of that problem with - ~ 4900 RQG tests with the RQG grammar simp_ut_fold_string.yy - origin/10.3 86c1bf118a48dd0bab80346f6d65c112ab2e486d 2022-03-07T16:42:05+03:00 10.3.35 Therefore I close the bug.

            People

              mleich Matthias Leich
              mleich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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