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

Server crash in binlog_online_alter_end_trans

    XMLWordPrintable

Details

    Description

      The test case is non-deterministic, run with --repeat=N. It usually fails for me within a few attempts, but it can vary with different machines and builds.

      --source include/have_innodb.inc
       
      CREATE TABLE t (pk int auto_increment primary key) ENGINE=InnoDB;
      INSERT INTO t () VALUES (),(),(),(),(),(),(),(),(),(),(),(),(),(),(),();
      --send
        ALTER TABLE t NOWAIT FORCE, ALGORITHM=COPY;
       
      --connect (con1,localhost,root,,test)
      START TRANSACTION;
      INSERT INTO t () VALUES (),(),(),(),(),(),(),(),(),(),(),(),(),(),(),();
       
      --connection default
      --error 0,ER_LOCK_WAIT_TIMEOUT
      --reap
       
      BACKUP STAGE START;
      BACKUP STAGE BLOCK_COMMIT;
      BACKUP STAGE END;
       
      --connection con1
      COMMIT;
       
      # Cleanup
      DROP TABLE t;
      --disconnect con1
      

      preview-10.10-MDEV-16329-online-alter d7a7d167

      #1  0x000056095a846c20 in my_write_core (sig=11) at /data/src/preview-10.10-MDEV-16329-online-alter/mysys/stacktrace.c:424
      No locals.
      #2  0x0000560959fb4e86 in handle_fatal_signal (sig=11) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/signal_handler.cc:345
              curr_time = 1655163559
              tm = {tm_sec = 19, tm_min = 39, tm_hour = 2, tm_mday = 14, tm_mon = 5, tm_year = 122, tm_wday = 2, tm_yday = 164, tm_isdst = 1, tm_gmtoff = 10800, tm_zone = 0x56095c1f9160 "EEST"}
              thd = 0x7f75c4000db8
              print_invalid_query_pointer = false
      #3  <signal handler called>
      No locals.
      #4  0x000056095a103a03 in inline_mysql_mutex_lock (that=0x8f8f8f8f8f8f8f97, src_file=0x56095aba4998 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/log.cc", src_line=7608) at /data/src/preview-10.10-MDEV-16329-online-alter/include/mysql/psi/mysql_thread.h:745
      No locals.
      #5  0x000056095a11af47 in binlog_online_alter_end_trans (thd=0x7f75c4000db8, all=true, commit=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/log.cc:7608
              binlog = 0x8f8f8f8f8f8f8f8f
              do_commit = true
              cache = @0x7f75c4013ce0: {<ilist_node<void>> = {next = 0x7f75c4007a80, prev = 0x7f75c4007a80}, cache_log = {pos_in_file = 0, end_of_file = 18446744073709547520, read_pos = 0x7f75c401ea68 "\247\312\247b\027\001", read_end = 0x56095a8333a1 <multi_alloc_root+395> "H\211\205\370\376\377\377H\203\275\370\376\377\377", buffer = 0x7f75c401ea68 "\247\312\247b\027\001", request_pos = 0x7f75c401ea68 "\247\312\247b\027\001", write_buffer = 0x7f75c401ea68 "\247\312\247b\027\001", append_read_pos = 0x560959b35b7d <server_mpvio_read_packet(MYSQL_PLUGIN_VIO*, uchar**)+777> "H\211\205\240\375\377\377H\203\275\240\375\377\377\377\017\224\300\017\266\300\205\300\017\225\300\017\266\300H\205\300t$\351-\002", write_pos = 0x7f75c401ead5 '\245' <repeats 200 times>..., write_end = 0x7f75c4026a68 "h4z\025", append_buffer_lock = {m_mutex = {global = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, file = 0x0, name = 0x0, line = 0, count = 0, create_flags = 0, active_flags = 0, id = 0, thread = 0, locked_mutex = 0x0, used_mutex = 0x0, prev = 0x0, next = 0x0}, m_psi = 0x0}, share = 0x0, read_function = 0x56095a81dc7d <_my_b_cache_read>, write_function = 0x56095a81f872 <_my_b_cache_write>, type = WRITE_CACHE, disk_writes = 0, file_name = 0x0, dir = 0x56095c2aa4d8 "/mnt8t/bld/10.10-online-alter-debug/mysql-test/var/tmp/mysqld.1", prefix = "ML", file = -1, next_file_user = 0x0, seek_not_done = 0, error = 0, buffer_length = 32768, read_length = 32768, myflags = 528, alloced_buffer = 32768}, share = 0x7f75c0102210, sv_list = 0x0, m_pending = 0x0, status = 2, before_stmt_pos = 109, incident = false, saved_max_binlog_cache_size = 18446744073709547520, ptr_binlog_cache_use = 0x56095b5788a0 <binlog_cache_use>, ptr_binlog_cache_disk_use = 0x56095b5788a8 <binlog_cache_disk_use>}
              __for_range = @0x7f75c4007a80: {sentinel_ = {next = 0x7f75c4013ce0, prev = 0x7f75c4013ce0}}
              __for_begin = {node_ = 0x7f75c4013ce0}
              __for_end = {node_ = 0x7f75c4007a80}
              _db_stack_frame_ = {func = 0x56095aba5a6a "binlog_commit", file = 0x56095aba4998 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/log.cc", level = 2147483658, line = -1, prev = 0x7f75e82572a0}
              error = 0
              is_ending_transaction = true
              __PRETTY_FUNCTION__ = "int binlog_online_alter_end_trans(THD*, bool, bool)"
      #6  0x000056095a10ad08 in binlog_commit (thd=0x7f75c4000db8, all=true, ro_1pc=false) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/log.cc:2271
              error = 0
              org_stage = {m_key = 0, m_name = 0x7f75c4000db8 "(K\"[\tV", m_flags = -400198960}
              _db_stack_frame_ = {func = 0x56095ab70bff "commit_one_phase_2", file = 0x56095ab6fd90 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc", level = 2147483657, line = -1, prev = 0x7f75e8257330}
              is_ending_transaction = true
              cache_mngr = 0x560959d26517 <THD::is_current_stmt_binlog_disabled() const+49>
              __PRETTY_FUNCTION__ = "int binlog_commit(THD*, bool, bool)"
      #7  0x0000560959fbbc93 in commit_one_phase_2 (thd=0x7f75c4000db8, all=true, trans=0x7f75c4004770, is_real_trans=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc:2059
              err = 22025
              error = 0
              count = 0
              ha_info = 0x7f75c40037e8
              ha_info_next = 0x7f75c400ae88
              _db_stack_frame_ = {func = 0x56095ab70beb "ha_commit_one_phase", file = 0x56095ab6fd90 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc", level = 2147483656, line = -1, prev = 0x7f75e8257390}
      #8  0x0000560959fbbac1 in ha_commit_one_phase (thd=0x7f75c4000db8, all=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc:2021
              trans = 0x7f75c4004770
              is_real_trans = true
              res = 0
              _db_stack_frame_ = {func = 0x56095ab704cb "ha_commit_trans", file = 0x56095ab6fd90 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc", level = 2147483655, line = -1, prev = 0x7f75e8257440}
      #9  0x0000560959fbac02 in ha_commit_trans (thd=0x7f75c4000db8, all=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc:1815
              error = 0
              cookie = 1574
              trans = 0x7f75c4004770
              is_real_trans = true
              ha_info = 0x7f75c40037e8
              need_prepare_ordered = false
              need_commit_ordered = false
              xid = 15402188421350010368
              run_wsrep_hooks = false
              _db_stack_frame_ = {func = 0x56095a9dc686 "trans_commit", file = 0x56095a9dc4d8 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/transaction.cc", level = 2147483654, line = -1, prev = 0x7f75e8257d60}
              __PRETTY_FUNCTION__ = "int ha_commit_trans(THD*, bool)"
              rw_ha_count = 1
              rw_trans = true
              mdl_backup = {type = 13, duration = MDL_EXPLICIT, next_in_list = 0x7f75e8257a10, prev_in_list = 0x7f75e82574a0, ticket = 0x7f75c401e5b0, key = {m_length = 3, m_db_name_length = 0, m_hash_value = 65537, m_ptr = "\000\000\000\304u\177\000\000\340\f\000\304u\177\000\000\270\f\000\304\001\000\000\000\340v%\350u\177\000\000S;\207Z\tV\000\000\340\f\000\304u\177\000\000@w%\350u\177\000\000\t\000\000\000u\177\000\000\340\f\000\304u\177\000\000\t\000\000\000u\177\000\000Pw%\350u\177\000\000\t\000\000\000_\f\000\000\340\f\000\304u\177\000\000\340\202\317Z\tV\000\000\270\r\000\304u\177\000\000@u%\350u\177\000\000\210\256\000\304u\177\000\000;\202\317Z\tV\000\000\300e\317Z\tV\000\000\v\000\000\200;\006\000\000pu%\350u\177\000\000\200\366\071\360u\177\000\000\000\256\063\322\303\220\277\325\240u%\350u\177\000\000\177\326SZ\tV\000\000"...}, m_src_file = 0x56095ab6fd90 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/handler.cc", m_src_line = 1719}
      #10 0x0000560959de5c76 in trans_commit (thd=0x7f75c4000db8) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/transaction.cc:266
              res = 32629
              _db_stack_frame_ = {func = 0x56095a97fb88 "mysql_execute_command", file = 0x56095a97ee28 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc", level = 2147483653, line = -1, prev = 0x7f75e8257f20}
              __PRETTY_FUNCTION__ = "bool trans_commit(THD*)"
      #11 0x0000560959bffa9c in mysql_execute_command (thd=0x7f75c4000db8, is_called_from_prepared_stmt=false) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc:5624
              tx_chain = false
              tx_release = false
              commit_failed = false
              res = 0
              up_result = 0
              lex = 0x7f75c4005100
              select_lex = 0x7f75c40059d8
              first_table = 0x0
              all_tables = 0x0
              unit = 0x7f75c40051d8
              have_table_map_for_update = false
              rpl_filter = 0x7f75e82580d0
              _db_stack_frame_ = {func = 0x56095a980f1f "mysql_parse", file = 0x56095a97ee28 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc", level = 2147483652, line = -1, prev = 0x7f75e8258380}
              __PRETTY_FUNCTION__ = "int mysql_execute_command(THD*, bool)"
              ots = {ctx = 0x7f75c4004d98, traceable = false}
              orig_binlog_format = BINLOG_FORMAT_MIXED
              orig_current_stmt_binlog_format = BINLOG_FORMAT_STMT
      #12 0x0000560959c070ad in mysql_parse (thd=0x7f75c4000db8, rawbuf=0x7f75c4013ff0 "COMMIT", length=6, parser_state=0x7f75e8258500) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc:8036
              found_semicolon = 0x0
              error = 32629
              lex = 0x7f75c4005100
              err = false
              _db_stack_frame_ = {func = 0x56095a97f3c9 "dispatch_command", file = 0x56095a97ee28 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc", level = 2147483651, line = -1, prev = 0x7f75e82584e0}
              __PRETTY_FUNCTION__ = "void mysql_parse(THD*, char*, uint, Parser_state*)"
      #13 0x0000560959bf3661 in dispatch_command (command=COM_QUERY, thd=0x7f75c4000db8, packet=0x7f75c400b9f9 "COMMIT", packet_length=6, blocking=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc:1894
              packet_end = 0x7f75c4013ff6 ""
              parser_state = {m_lip = {lookahead_token = -1, lookahead_yylval = 0x0, m_thd = 0x7f75c4000db8, m_ptr = 0x7f75c4013ff7 "\004", m_tok_start = 0x7f75c4013ff7 "\004", m_tok_end = 0x7f75c4013ff7 "\004", m_end_of_query = 0x7f75c4013ff6 "", m_tok_start_prev = 0x7f75c4013ff6 "", m_buf = 0x7f75c4013ff0 "COMMIT", m_buf_length = 6, m_echo = true, m_echo_saved = false, m_cpp_buf = 0x7f75c4014050 "COMMIT", m_cpp_ptr = 0x7f75c4014056 "", m_cpp_tok_start = 0x7f75c4014056 "", m_cpp_tok_start_prev = 0x7f75c4014056 "", m_cpp_tok_end = 0x7f75c4014056 "", m_body_utf8 = 0x0, m_body_utf8_ptr = 0x0, m_cpp_utf8_processed_ptr = 0x0, next_state = MY_LEX_END, found_semicolon = 0x0, ignore_space = false, stmt_prepare_mode = false, multi_statements = true, yylineno = 1, m_digest = 0x0, in_comment = NO_COMMENT, in_comment_saved = (PRESERVE_COMMENT | unknown: 0x7f74), m_cpp_text_start = 0x7f75c401409c '\217' <repeats 200 times>..., m_cpp_text_end = 0x7f75c401409d '\217' <repeats 200 times>..., m_underscore_cs = 0x0}, m_yacc = {yacc_yyss = 0x0, yacc_yyvs = 0x0, m_set_signal_info = {m_item = {0x0 <repeats 13 times>}}, m_lock_type = TL_READ_DEFAULT, m_mdl_type = MDL_SHARED_READ}, m_digest_psi = 0x7f75c4004b28}
              net = 0x7f75c40010f0
              error = false
              do_end_of_statement = true
              _db_stack_frame_ = {func = 0x56095a97f04d "do_command", file = 0x56095a97ee28 "/data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc", level = 2147483650, line = -1, prev = 0x7f75e8258dc0}
              drop_more_results = false
              __PRETTY_FUNCTION__ = "dispatch_command_return dispatch_command(enum_server_command, THD*, char*, uint, bool)"
              __FUNCTION__ = "dispatch_command"
              res = <optimized out>
      #14 0x0000560959bf205c in do_command (thd=0x7f75c4000db8, blocking=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_parse.cc:1407
              return_value = DISPATCH_COMMAND_SUCCESS
              packet = 0x7f75c400b9f8 "\003COMMIT"
              packet_length = 7
              net = 0x7f75c40010f0
              command = COM_QUERY
              _db_stack_frame_ = {func = 0x56095adeedc1 "?func", file = 0x56095adeedc7 "?file", level = 2147483649, line = -1, prev = 0x0}
              __PRETTY_FUNCTION__ = "dispatch_command_return do_command(THD*, bool)"
              __FUNCTION__ = "do_command"
      #15 0x0000560959dca29c in do_handle_one_connection (connect=0x56095ca45fb8, put_in_cache=true) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_connect.cc:1418
              create_user = true
              thr_create_utime = 1585671254320
              thd = 0x7f75c4000db8
              __PRETTY_FUNCTION__ = "void do_handle_one_connection(CONNECT*, bool)"
      #16 0x0000560959dc9f3b in handle_one_connection (arg=0x56095ca45fb8) at /data/src/preview-10.10-MDEV-16329-online-alter/sql/sql_connect.cc:1312
              connect = 0x56095ca45fb8
      #17 0x000056095a2c74be in pfs_spawn_thread (arg=0x56095ca46098) at /data/src/preview-10.10-MDEV-16329-online-alter/storage/perfschema/pfs.cc:2201
              typed_arg = 0x56095ca46098
              user_arg = 0x56095ca45fb8
              user_start_routine = 0x560959dc9ee0 <handle_one_connection(void*)>
              pfs = 0x7f75f565b180
              klass = 0x56095c1db580
      #18 0x00007f75f6227ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
              ret = <optimized out>
              pd = <optimized out>
              unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140144382678784, 3180009120030882440, 140733683640094, 140733683640095, 140144382676864, 311296, -3257658094184727928, -3257715278973535608}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
              not_first_call = 0
      #19 0x00007f75f5e26def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Attachments

        Issue Links

          Activity

            People

              serg Sergei Golubchik
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              2 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.