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

TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed

Details

    Description

      10.2 1ca8637ae35061

      		 
      mysqld: /data/src/10.2/storage/innobase/include/trx0trx.h:1423: static bool TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed.
      		 
      170321 19:54:53 [ERROR] mysqld got signal 6 ;


      # 2017-03-21T19:55:03 [23375] #7  0x00007f1af3371312 in __GI___assert_fail (assertion=0x7f1af67ef450 "srv_read_only_mode || trx->in_depth > 0", file=0x7f1af67ef418 "/data/src/10.2/storage/innobase/include/trx0trx.h", line=1423, function=0x7f1af67fde60 <TrxInInnoDB::is_aborted(trx_t const*)::__PRETTY_FUNCTION__> "static bool TrxInInnoDB::is_aborted(const trx_t*)") at assert.c:101
      		 
      # 2017-03-21T19:55:03 [23375] #8  0x00007f1af61e7259 in TrxInInnoDB::is_aborted (trx=0x7f1adf401168) at /data/src/10.2/storage/innobase/include/trx0trx.h:1423
      		 
      # 2017-03-21T19:55:03 [23375] #9  0x00007f1af61cee0c in ha_innobase::general_fetch (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001", direction=1, match_mode=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10304
      		 
      # 2017-03-21T19:55:03 [23375] #10 0x00007f1af61cf4a0 in ha_innobase::rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10532
      		 
      # 2017-03-21T19:55:03 [23375] #11 0x00007f1af5ebe121 in handler::ha_rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/sql/handler.cc:2577
      		 
      # 2017-03-21T19:55:03 [23375] #12 0x00007f1af60268bc in rr_sequential (info=0x7f1ac0c62188) at /data/src/10.2/sql/records.cc:484
      		 
      # 2017-03-21T19:55:03 [23375] #13 0x00007f1af5cbd0be in sub_select (join=0x7f1ac0c60ff0, join_tab=0x7f1ac0c620c0, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18436
      		 
      # 2017-03-21T19:55:03 [23375] #14 0x00007f1af5cbc5a3 in do_select (join=0x7f1ac0c60ff0, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:17961
      		 
      # 2017-03-21T19:55:03 [23375] #15 0x00007f1af5c975b7 in JOIN::exec_inner (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3463
      		 
      # 2017-03-21T19:55:03 [23375] #16 0x00007f1af5c96abc in JOIN::exec (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3266
      		 
      # 2017-03-21T19:55:03 [23375] #17 0x00007f1af5c97c2f in mysql_select (thd=0x7f1ac0c16070, tables=0x7f1ac0c608f8, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=553247836928, result=0x7f1ac0c60f48, unit=0x7f1ac0c19b50, select_lex=0x7f1ac0c1a280) at /data/src/10.2/sql/sql_select.cc:3658
      		 
      # 2017-03-21T19:55:03 [23375] #18 0x00007f1af5c8c710 in handle_select (thd=0x7f1ac0c16070, lex=0x7f1ac0c19a88, result=0x7f1ac0c60f48, setup_tables_done_option=1073741824) at /data/src/10.2/sql/sql_select.cc:373
      		 
      # 2017-03-21T19:55:03 [23375] #19 0x00007f1af5c51b98 in mysql_execute_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:4498
      		 
      # 2017-03-21T19:55:03 [23375] #20 0x00007f1af5c5c52c in mysql_parse (thd=0x7f1ac0c16070, rawbuf=0x7f1ac0c60088 "INSERT INTO tmp SELECT * FROM t2  /* QNO 31 CON_ID 12 */", length=56, parser_state=0x7f1af6d28e20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7858
      		 
      # 2017-03-21T19:55:03 [23375] #21 0x00007f1af5c4a5f2 in dispatch_command (command=COM_QUERY, thd=0x7f1ac0c16070, packet=0x7f1ac0c54071 " INSERT INTO tmp SELECT * FROM t2  /* QNO 31 CON_ID 12 */ ", packet_length=58, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
      		 
      # 2017-03-21T19:55:03 [23375] #22 0x00007f1af5c48f62 in do_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:1362
      		 
      # 2017-03-21T19:55:03 [23375] #23 0x00007f1af5d91f3f in do_handle_one_connection (connect=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1358
      		 
      # 2017-03-21T19:55:03 [23375] #24 0x00007f1af5d91ccc in handle_one_connection (arg=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1264
      		 
      # 2017-03-21T19:55:03 [23375] #25 0x00007f1af5273064 in start_thread (arg=0x7f1af6d2a300) at pthread_create.c:309
      		 
      # 2017-03-21T19:55:03 [23375] #26 0x00007f1af342b62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

      Non-deterministic concurrent test

      git clone https://github.com/elenst/rqg --branch mdev11197 rqg-mdev11197
      		 
      cd rqg-mdev11197
      		 
      perl ./runall-new.pl --skip-gendata --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --basedir=<your 10.2 basedir> --vardir=<your vardir>
      		 
      # or, if you want to run it on an already started server (e.g. under debugger), 
      # assuming it's running on port 3306
      		 
      perl ./gentest.pl --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --dsn='dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test'

      Attachments

        Activity

          Ascending order - Click to sort in descending order
          elenst Elena Stepanova created issue -
          elenst Elena Stepanova made changes -
          Field Original Value New Value
          Fix Version/s 10.2 [ 14601 ]
          Description http://buildbot.askmonty.org/buildbot/builders/kvm-qa-linux/builds/809/steps/shell_5/logs/stdio
          {noformat}
          2016-10-31 12:04:50 0x7f88a5a45300 InnoDB: Assertion failure in thread 140224871289600 in file trx0trx.h line 1426
          InnoDB: Failing assertion: srv_read_only_mode || trx->in_depth > 0
          InnoDB: We intentionally generate a memory trap.
          InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
          InnoDB: If you get repeated assertion failures or crashes, even
          InnoDB: immediately after the mysqld startup, there may be
          InnoDB: corruption in the InnoDB tablespace. Please refer to
          InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
          InnoDB: about forcing recovery.
          161031 12:04:50 [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.2.3-MariaDB-debug-log
          key_buffer_size=134217728
          read_buffer_size=131072
          max_used_connections=11
          max_threads=1001
          thread_count=11
          It is possible that mysqld could use up to
          key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2312531 K bytes of memory
          Hope that's ok; if not, decrease some variables in the equation.

          Thread pointer: 0x0x7f889b4c7070
          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 = 0x7f88a5a44908 thread_stack 0x48c00
          /home/buildbot/build/sql/mysqld(my_print_stacktrace+0x38)[0x7f88a6acba7a]
          /home/buildbot/build/sql/mysqld(handle_fatal_signal+0x3a8)[0x7f88a6348b6b]
          /lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7f88a573b8d0]
          /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f88a3839067]
          /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f88a383a448]
          /home/buildbot/build/sql/mysqld(+0xbf63c2)[0x7f88a67623c2]
          /home/buildbot/build/sql/mysqld(+0x9e82a8)[0x7f88a65542a8]
          /home/buildbot/build/sql/mysqld(+0x9ce8cc)[0x7f88a653a8cc]
          /home/buildbot/build/sql/mysqld(+0x7ed2aa)[0x7f88a63592aa]
          /home/buildbot/build/sql/mysqld(_ZN7handler18index_read_idx_mapEPhjPKhm16ha_rkey_function+0x64)[0x7f88a635656a]
          /home/buildbot/build/sql/mysqld(_ZN7handler21ha_index_read_idx_mapEPhjPKhm16ha_rkey_function+0x1c7)[0x7f88a634fc0d]
          /home/buildbot/build/sql/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0x4c3)[0x7f88a60c0ff4]
          /home/buildbot/build/sql/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0xea4)[0x7f88a60bf2fd]
          mysys/stacktrace.c:267(my_print_stacktrace)[0x7f88a60e6248]
          /home/buildbot/build/sql/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x29a)[0x7f88a60f16f6]
          include/trx0trx.h:1427(TrxInInnoDB::is_aborted(trx_t const*))[0x7f88a60df464]
          sql/handler.h:3074(handler::index_read_map(unsigned char*, unsigned char const*, unsigned long, ha_rkey_function))[0x7f88a60dde3e]
          sql/sql_insert.cc:1670(write_record(THD*, TABLE*, st_copy_info*))[0x7f88a6288f89]
          sql/threadpool_common.cc:319(threadpool_process_request)[0x7f88a6288bad]
          sql/threadpool_generic.cc:1582(worker_main)[0x7f88a630a1e9]
          perfschema/pfs.cc:1864(pfs_spawn_thread)[0x7f88a693675c]
          /lib/x86_64-linux-gnu/libpthread.so.0(+0x80a4)[0x7f88a57340a4]
          /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f88a38ec87d]

          Trying to get some variables.
          Some pointers may be invalid and cause the dump to abort.
          Query (0x7f889b4d7088): REPLACE INTO test./* table1_innodb_int table10_int_autoinc v1_nontrans_safe_for_sbr_2016 */ table10_innodb_int ( `col_tinyint_unsigned`, col_tinyint ) VALUES ( f1_3_2016 (), 66 ) /* QNO 6216 CON_ID 11 */
          Connection ID (thread ID): 11
          Status: NOT_KILLED

          Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
          {noformat}
          {noformat}
          # 2016-10-31T12:05:02 [1917] #3 <signal handler called>
          # 2016-10-31T12:05:02 [1917] #4 0x00007f88a3839067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
          # 2016-10-31T12:05:02 [1917] #5 0x00007f88a383a448 in __GI_abort () at abort.c:89
          # 2016-10-31T12:05:02 [1917] #6 0x00007f88a67623c2 in ut_dbg_assertion_failed (expr=0x7f88a6c67b50 "srv_read_only_mode || trx->in_depth > 0", file=0x7f88a6c67b18 "/home/buildbot/build/storage/innobase/include/trx0trx.h", line=1426) at /home/buildbot/build/storage/innobase/ut/ut0dbg.cc:67
          # 2016-10-31T12:05:02 [1917] #7 0x00007f88a65542a8 in TrxInInnoDB::is_aborted (trx=0x7f8892c01638) at /home/buildbot/build/storage/innobase/include/trx0trx.h:1426
          # 2016-10-31T12:05:02 [1917] #8 0x00007f88a653a8cc in ha_innobase::index_read (this=0x7f8855ddd888, buf=0x7f8862afb5b0 "\377", key_ptr=0x7f88a5a42d80 "", key_len=4, find_flag=HA_READ_KEY_EXACT) at /home/buildbot/build/storage/innobase/handler/ha_innodb.cc:10419
          # 2016-10-31T12:05:02 [1917] #9 0x00007f88a63592aa in handler::index_read_map (this=0x7f8855ddd888, buf=0x7f8862afb5b0 "\377", key=0x7f88a5a42d80 "", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at /home/buildbot/build/sql/handler.h:3073
          # 2016-10-31T12:05:02 [1917] #10 0x00007f88a635656a in handler::index_read_idx_map (this=0x7f8855ddd888, buf=0x7f8862afb5b0 "\377", index=0, key=0x7f88a5a42d80 "", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at /home/buildbot/build/sql/handler.cc:5442
          # 2016-10-31T12:05:02 [1917] #11 0x00007f88a634fc0d in handler::ha_index_read_idx_map (this=0x7f8855ddd888, buf=0x7f8862afb5b0 "\377", index=0, key=0x7f88a5a42d80 "", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at /home/buildbot/build/sql/handler.cc:2645
          # 2016-10-31T12:05:02 [1917] #12 0x00007f88a60c0ff4 in write_record (thd=0x7f889b4c7070, table=0x7f8866d57470, info=0x7f88a5a42fa0) at /home/buildbot/build/sql/sql_insert.cc:1670
          # 2016-10-31T12:05:02 [1917] #13 0x00007f88a60bf2fd in mysql_insert (thd=0x7f889b4c7070, table_list=0x7f889b4d72f8, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_REPLACE, ignore=false) at /home/buildbot/build/sql/sql_insert.cc:983
          # 2016-10-31T12:05:02 [1917] #14 0x00007f88a60e6248 in mysql_execute_command (thd=0x7f889b4c7070) at /home/buildbot/build/sql/sql_parse.cc:4326
          # 2016-10-31T12:05:02 [1917] #15 0x00007f88a60f16f6 in mysql_parse (thd=0x7f889b4c7070, rawbuf=0x7f889b4d7088 "REPLACE INTO test./* table1_innodb_int table10_int_autoinc v1_nontrans_safe_for_sbr_2016 */ table10_innodb_int ( `col_tinyint_unsigned`, col_tinyint ) VALUES ( f1_3_2016 (), 66 ) /* QNO 6216 CON_ID 11 */", length=204, parser_state=0x7f88a5a43ce0, is_com_multi=false, is_next_command=false) at /home/buildbot/build/sql/sql_parse.cc:7796
          # 2016-10-31T12:05:02 [1917] #16 0x00007f88a60df464 in dispatch_command (command=COM_QUERY, thd=0x7f889b4c7070, packet=0x7f889b711071 " REPLACE INTO test./* table1_innodb_int table10_int_autoinc v1_nontrans_safe_for_sbr_2016 */ table10_innodb_int ( `col_tinyint_unsigned`, col_tinyint ) VALUES ( f1_3_2016 (), 66 ) /* QNO 6216 CON_ID 11 */ ", packet_length=206, is_com_multi=false, is_next_command=false) at /home/buildbot/build/sql/sql_parse.cc:1806
          # 2016-10-31T12:05:02 [1917] #17 0x00007f88a60dde3e in do_command (thd=0x7f889b4c7070) at /home/buildbot/build/sql/sql_parse.cc:1366
          # 2016-10-31T12:05:02 [1917] #18 0x00007f88a6288f89 in threadpool_process_request (thd=0x7f889b4c7070) at /home/buildbot/build/sql/threadpool_common.cc:319
          # 2016-10-31T12:05:02 [1917] #19 0x00007f88a6288bad in tp_callback (c=0x7f889cfe2b00) at /home/buildbot/build/sql/threadpool_common.cc:158
          # 2016-10-31T12:05:02 [1917] #20 0x00007f88a630a1e9 in worker_main (param=0x7f888c7f5430) at /home/buildbot/build/sql/threadpool_generic.cc:1581
          # 2016-10-31T12:05:02 [1917] #21 0x00007f88a693675c in pfs_spawn_thread (arg=0x7f889cfc0270) at /home/buildbot/build/storage/perfschema/pfs.cc:1862
          # 2016-10-31T12:05:02 [1917] #22 0x00007f88a57340a4 in start_thread (arg=0x7f88a5a45300) at pthread_create.c:309
          # 2016-10-31T12:05:02 [1917] #23 0x00007f88a38ec87d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
          {noformat}
          {noformat}
          # 2016-10-31T12:02:14 [1917] Final command line:
          # 2016-10-31T12:02:14 [1917] perl /home/buildbot/rqg/runall-new.pl --no-mask --seed=1477929734 --threads=8 --duration=300 --queries=100M --reporters=QueryTimeout,Backtrace,ErrorLog,Deadlock --validators=QueryProperties --redefine=conf/mariadb/general-workarounds.yy --redefine=conf/mariadb/redefine_multiple_triggers.yy --redefine=conf/mariadb/redefine_temporary_tables.yy --mysqld=--log_output=FILE --mysqld=--log_bin_trust_function_creators=1 --use-gtid=current_pos --mysqld=--slave_parallel_threads=8 --mysqld=--performance_schema=1 --mysqld=--log_bin --mysqld=--binlog_format=MIXED --mysqld=--thread_handling=pool-of-threads --grammar=conf/replication/replication-ddl_sql.yy --gendata=conf/replication/replication-ddl_data.zz --mtr-build-thread=300 --basedir1=/home/buildbot/build --vardir1=/home/buildbot/10.2-features/current1_1
          {noformat}
          		{noformat:title=10.2 1ca8637ae35061}
          mysqld: /data/src/10.2/storage/innobase/include/trx0trx.h:1423: static bool TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed.
          170321 19:54:53 [ERROR] mysqld got signal 6 ;
          {noformat}
          {noformat}
          # 2017-03-21T19:55:03 [23375] #7 0x00007f1af3371312 in __GI___assert_fail (assertion=0x7f1af67ef450 "srv_read_only_mode || trx->in_depth > 0", file=0x7f1af67ef418 "/data/src/10.2/storage/innobase/include/trx0trx.h", line=1423, function=0x7f1af67fde60 <TrxInInnoDB::is_aborted(trx_t const*)::__PRETTY_FUNCTION__> "static bool TrxInInnoDB::is_aborted(const trx_t*)") at assert.c:101
          # 2017-03-21T19:55:03 [23375] #8 0x00007f1af61e7259 in TrxInInnoDB::is_aborted (trx=0x7f1adf401168) at /data/src/10.2/storage/innobase/include/trx0trx.h:1423
          # 2017-03-21T19:55:03 [23375] #9 0x00007f1af61cee0c in ha_innobase::general_fetch (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001", direction=1, match_mode=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10304
          # 2017-03-21T19:55:03 [23375] #10 0x00007f1af61cf4a0 in ha_innobase::rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10532
          # 2017-03-21T19:55:03 [23375] #11 0x00007f1af5ebe121 in handler::ha_rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/sql/handler.cc:2577
          # 2017-03-21T19:55:03 [23375] #12 0x00007f1af60268bc in rr_sequential (info=0x7f1ac0c62188) at /data/src/10.2/sql/records.cc:484
          # 2017-03-21T19:55:03 [23375] #13 0x00007f1af5cbd0be in sub_select (join=0x7f1ac0c60ff0, join_tab=0x7f1ac0c620c0, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18436
          # 2017-03-21T19:55:03 [23375] #14 0x00007f1af5cbc5a3 in do_select (join=0x7f1ac0c60ff0, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:17961
          # 2017-03-21T19:55:03 [23375] #15 0x00007f1af5c975b7 in JOIN::exec_inner (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3463
          # 2017-03-21T19:55:03 [23375] #16 0x00007f1af5c96abc in JOIN::exec (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3266
          # 2017-03-21T19:55:03 [23375] #17 0x00007f1af5c97c2f in mysql_select (thd=0x7f1ac0c16070, tables=0x7f1ac0c608f8, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=553247836928, result=0x7f1ac0c60f48, unit=0x7f1ac0c19b50, select_lex=0x7f1ac0c1a280) at /data/src/10.2/sql/sql_select.cc:3658
          # 2017-03-21T19:55:03 [23375] #18 0x00007f1af5c8c710 in handle_select (thd=0x7f1ac0c16070, lex=0x7f1ac0c19a88, result=0x7f1ac0c60f48, setup_tables_done_option=1073741824) at /data/src/10.2/sql/sql_select.cc:373
          # 2017-03-21T19:55:03 [23375] #19 0x00007f1af5c51b98 in mysql_execute_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:4498
          # 2017-03-21T19:55:03 [23375] #20 0x00007f1af5c5c52c in mysql_parse (thd=0x7f1ac0c16070, rawbuf=0x7f1ac0c60088 "INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */", length=56, parser_state=0x7f1af6d28e20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7858
          # 2017-03-21T19:55:03 [23375] #21 0x00007f1af5c4a5f2 in dispatch_command (command=COM_QUERY, thd=0x7f1ac0c16070, packet=0x7f1ac0c54071 " INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */ ", packet_length=58, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
          # 2017-03-21T19:55:03 [23375] #22 0x00007f1af5c48f62 in do_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:1362
          # 2017-03-21T19:55:03 [23375] #23 0x00007f1af5d91f3f in do_handle_one_connection (connect=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1358
          # 2017-03-21T19:55:03 [23375] #24 0x00007f1af5d91ccc in handle_one_connection (arg=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1264
          # 2017-03-21T19:55:03 [23375] #25 0x00007f1af5273064 in start_thread (arg=0x7f1af6d2a300) at pthread_create.c:309
          # 2017-03-21T19:55:03 [23375] #26 0x00007f1af342b62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
          {noformat}

          Non-deterministic concurrent test
          {noformat}
          git clone https://github.com/elenst/rqg --branch mdev11197 rqg-mdev11197
          cd mdev11197
          perl ./runall-new.pl --skip-gendata --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --basedir=<your 10.2 basedir> --vardir=<your vardir>
          # or, if you want to run it on an already started server (e.g. under debugger),
          # assuming it's running on port 3306
          perl ./gentest.pl --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --dsn='dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test'
          {noformat}
          Summary [Draft] Failing assertion: srv_read_only_mode || trx->in_depth > 0 TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed
          elenst Elena Stepanova made changes -
          Comment [ Started happening again recently (e.g. a06da5c848e6feeef0b1559e84479890a76c446e)
          {noformat}
          perl ./runall-new.pl --no-mask --seed=1489882639 --threads=2 --duration=28800 --queries=100M --redefine=conf/mariadb/redefine_multiple_triggers.yy --redefine=conf/mariadb/redefine_temporary_tables.yy --mysqld=--log_output=FILE --grammar=conf/replication/replication-ddl_sql.yy --gendata=conf/replication/replication-ddl_data.zz --mtr-build-thread=300 --basedir1=/data/bld/10.2 --vardir1=/data/logs/analyze5
          {noformat}
          ]
          elenst Elena Stepanova made changes -
          Assignee Elena Stepanova [ elenst ] Marko Mäkelä [ marko ]
          elenst Elena Stepanova made changes -
          Assignee Marko Mäkelä [ marko ] Elena Stepanova [ elenst ]
          elenst Elena Stepanova made changes -
          Description {noformat:title=10.2 1ca8637ae35061}
          mysqld: /data/src/10.2/storage/innobase/include/trx0trx.h:1423: static bool TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed.
          170321 19:54:53 [ERROR] mysqld got signal 6 ;
          {noformat}
          {noformat}
          # 2017-03-21T19:55:03 [23375] #7 0x00007f1af3371312 in __GI___assert_fail (assertion=0x7f1af67ef450 "srv_read_only_mode || trx->in_depth > 0", file=0x7f1af67ef418 "/data/src/10.2/storage/innobase/include/trx0trx.h", line=1423, function=0x7f1af67fde60 <TrxInInnoDB::is_aborted(trx_t const*)::__PRETTY_FUNCTION__> "static bool TrxInInnoDB::is_aborted(const trx_t*)") at assert.c:101
          # 2017-03-21T19:55:03 [23375] #8 0x00007f1af61e7259 in TrxInInnoDB::is_aborted (trx=0x7f1adf401168) at /data/src/10.2/storage/innobase/include/trx0trx.h:1423
          # 2017-03-21T19:55:03 [23375] #9 0x00007f1af61cee0c in ha_innobase::general_fetch (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001", direction=1, match_mode=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10304
          # 2017-03-21T19:55:03 [23375] #10 0x00007f1af61cf4a0 in ha_innobase::rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10532
          # 2017-03-21T19:55:03 [23375] #11 0x00007f1af5ebe121 in handler::ha_rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/sql/handler.cc:2577
          # 2017-03-21T19:55:03 [23375] #12 0x00007f1af60268bc in rr_sequential (info=0x7f1ac0c62188) at /data/src/10.2/sql/records.cc:484
          # 2017-03-21T19:55:03 [23375] #13 0x00007f1af5cbd0be in sub_select (join=0x7f1ac0c60ff0, join_tab=0x7f1ac0c620c0, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18436
          # 2017-03-21T19:55:03 [23375] #14 0x00007f1af5cbc5a3 in do_select (join=0x7f1ac0c60ff0, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:17961
          # 2017-03-21T19:55:03 [23375] #15 0x00007f1af5c975b7 in JOIN::exec_inner (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3463
          # 2017-03-21T19:55:03 [23375] #16 0x00007f1af5c96abc in JOIN::exec (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3266
          # 2017-03-21T19:55:03 [23375] #17 0x00007f1af5c97c2f in mysql_select (thd=0x7f1ac0c16070, tables=0x7f1ac0c608f8, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=553247836928, result=0x7f1ac0c60f48, unit=0x7f1ac0c19b50, select_lex=0x7f1ac0c1a280) at /data/src/10.2/sql/sql_select.cc:3658
          # 2017-03-21T19:55:03 [23375] #18 0x00007f1af5c8c710 in handle_select (thd=0x7f1ac0c16070, lex=0x7f1ac0c19a88, result=0x7f1ac0c60f48, setup_tables_done_option=1073741824) at /data/src/10.2/sql/sql_select.cc:373
          # 2017-03-21T19:55:03 [23375] #19 0x00007f1af5c51b98 in mysql_execute_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:4498
          # 2017-03-21T19:55:03 [23375] #20 0x00007f1af5c5c52c in mysql_parse (thd=0x7f1ac0c16070, rawbuf=0x7f1ac0c60088 "INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */", length=56, parser_state=0x7f1af6d28e20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7858
          # 2017-03-21T19:55:03 [23375] #21 0x00007f1af5c4a5f2 in dispatch_command (command=COM_QUERY, thd=0x7f1ac0c16070, packet=0x7f1ac0c54071 " INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */ ", packet_length=58, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
          # 2017-03-21T19:55:03 [23375] #22 0x00007f1af5c48f62 in do_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:1362
          # 2017-03-21T19:55:03 [23375] #23 0x00007f1af5d91f3f in do_handle_one_connection (connect=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1358
          # 2017-03-21T19:55:03 [23375] #24 0x00007f1af5d91ccc in handle_one_connection (arg=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1264
          # 2017-03-21T19:55:03 [23375] #25 0x00007f1af5273064 in start_thread (arg=0x7f1af6d2a300) at pthread_create.c:309
          # 2017-03-21T19:55:03 [23375] #26 0x00007f1af342b62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
          {noformat}

          Non-deterministic concurrent test
          {noformat}
          git clone https://github.com/elenst/rqg --branch mdev11197 rqg-mdev11197
          cd mdev11197
          perl ./runall-new.pl --skip-gendata --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --basedir=<your 10.2 basedir> --vardir=<your vardir>
          # or, if you want to run it on an already started server (e.g. under debugger),
          # assuming it's running on port 3306
          perl ./gentest.pl --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --dsn='dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test'
          {noformat}           		{noformat:title=10.2 1ca8637ae35061}
          mysqld: /data/src/10.2/storage/innobase/include/trx0trx.h:1423: static bool TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed.
          170321 19:54:53 [ERROR] mysqld got signal 6 ;
          {noformat}
          {noformat}
          # 2017-03-21T19:55:03 [23375] #7 0x00007f1af3371312 in __GI___assert_fail (assertion=0x7f1af67ef450 "srv_read_only_mode || trx->in_depth > 0", file=0x7f1af67ef418 "/data/src/10.2/storage/innobase/include/trx0trx.h", line=1423, function=0x7f1af67fde60 <TrxInInnoDB::is_aborted(trx_t const*)::__PRETTY_FUNCTION__> "static bool TrxInInnoDB::is_aborted(const trx_t*)") at assert.c:101
          # 2017-03-21T19:55:03 [23375] #8 0x00007f1af61e7259 in TrxInInnoDB::is_aborted (trx=0x7f1adf401168) at /data/src/10.2/storage/innobase/include/trx0trx.h:1423
          # 2017-03-21T19:55:03 [23375] #9 0x00007f1af61cee0c in ha_innobase::general_fetch (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001", direction=1, match_mode=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10304
          # 2017-03-21T19:55:03 [23375] #10 0x00007f1af61cf4a0 in ha_innobase::rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10532
          # 2017-03-21T19:55:03 [23375] #11 0x00007f1af5ebe121 in handler::ha_rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/sql/handler.cc:2577
          # 2017-03-21T19:55:03 [23375] #12 0x00007f1af60268bc in rr_sequential (info=0x7f1ac0c62188) at /data/src/10.2/sql/records.cc:484
          # 2017-03-21T19:55:03 [23375] #13 0x00007f1af5cbd0be in sub_select (join=0x7f1ac0c60ff0, join_tab=0x7f1ac0c620c0, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18436
          # 2017-03-21T19:55:03 [23375] #14 0x00007f1af5cbc5a3 in do_select (join=0x7f1ac0c60ff0, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:17961
          # 2017-03-21T19:55:03 [23375] #15 0x00007f1af5c975b7 in JOIN::exec_inner (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3463
          # 2017-03-21T19:55:03 [23375] #16 0x00007f1af5c96abc in JOIN::exec (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3266
          # 2017-03-21T19:55:03 [23375] #17 0x00007f1af5c97c2f in mysql_select (thd=0x7f1ac0c16070, tables=0x7f1ac0c608f8, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=553247836928, result=0x7f1ac0c60f48, unit=0x7f1ac0c19b50, select_lex=0x7f1ac0c1a280) at /data/src/10.2/sql/sql_select.cc:3658
          # 2017-03-21T19:55:03 [23375] #18 0x00007f1af5c8c710 in handle_select (thd=0x7f1ac0c16070, lex=0x7f1ac0c19a88, result=0x7f1ac0c60f48, setup_tables_done_option=1073741824) at /data/src/10.2/sql/sql_select.cc:373
          # 2017-03-21T19:55:03 [23375] #19 0x00007f1af5c51b98 in mysql_execute_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:4498
          # 2017-03-21T19:55:03 [23375] #20 0x00007f1af5c5c52c in mysql_parse (thd=0x7f1ac0c16070, rawbuf=0x7f1ac0c60088 "INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */", length=56, parser_state=0x7f1af6d28e20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7858
          # 2017-03-21T19:55:03 [23375] #21 0x00007f1af5c4a5f2 in dispatch_command (command=COM_QUERY, thd=0x7f1ac0c16070, packet=0x7f1ac0c54071 " INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */ ", packet_length=58, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
          # 2017-03-21T19:55:03 [23375] #22 0x00007f1af5c48f62 in do_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:1362
          # 2017-03-21T19:55:03 [23375] #23 0x00007f1af5d91f3f in do_handle_one_connection (connect=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1358
          # 2017-03-21T19:55:03 [23375] #24 0x00007f1af5d91ccc in handle_one_connection (arg=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1264
          # 2017-03-21T19:55:03 [23375] #25 0x00007f1af5273064 in start_thread (arg=0x7f1af6d2a300) at pthread_create.c:309
          # 2017-03-21T19:55:03 [23375] #26 0x00007f1af342b62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
          {noformat}

          Non-deterministic concurrent test
          {noformat}
          git clone https://github.com/elenst/rqg --branch mdev11197 rqg-mdev11197
          cd rqg-mdev11197
          perl ./runall-new.pl --skip-gendata --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --basedir=<your 10.2 basedir> --vardir=<your vardir>
          # or, if you want to run it on an already started server (e.g. under debugger),
          # assuming it's running on port 3306
          perl ./gentest.pl --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --dsn='dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test'
          {noformat}
          elenst Elena Stepanova made changes -
          Assignee Elena Stepanova [ elenst ] Marko Mäkelä [ marko ]
          marko Marko Mäkelä added a comment -

          It seems to me that there could be a problem when merging from MySQL 5.7. The function innobase_kill_connection() which is bound to handlerton::kill_connection does not exist in MariaDB, but instead we have a similar function innobase_kill_query() that is bound to handlerton::kill_query().

          At the very least, comments that refer to innobase_kill_connection() should be revised to refer to innobase_kill_query(). I suspect some difference near lock_trx_handle_wait().

          While I was investigating this bug, I came up with the following clean-up patch that might marginally improve performance:

          diff --git a/storage/innobase/include/trx0trx.h b/storage/innobase/include/trx0trx.h
          		 
          index d0a67a7ed28..2d4132237af 100644
          		 
          --- a/storage/innobase/include/trx0trx.h
          		 
          +++ b/storage/innobase/include/trx0trx.h
          		 
          @@ -1473,12 +1473,8 @@ class TrxInInnoDB {
          		 
           
           		ut_ad(!is_async_rollback(trx));
          		 
           
          -		++trx->in_depth;
          		 
          -
          		 
          -		/* If trx->in_depth is greater than 1 then
          		 
          -		transaction is already in InnoDB. */
          		 
          -		if (trx->in_depth > 1) {
          		 
          -
          		 
          +		if (trx->in_depth++) {
          		 
          +			/* The transaction is already inside InnoDB. */
          		 
           			return;
          		 
           		}
          		 
           
          @@ -1528,9 +1524,7 @@ class TrxInInnoDB {
          		 
           
           		ut_ad(trx->in_depth > 0);
          		 
           
          -		--trx->in_depth;
          		 
          -
          		 
          -		if (trx->in_depth > 0) {
          		 
          +		if (--trx->in_depth > 0) {
          		 
           
           			return;
          		 
           		}

          Also, while I was looking at this, I noticed that my change to deprecate innodb_support_xa in MySQL 5.7.10 has not been merged.

          marko Marko Mäkelä added a comment - It seems to me that there could be a problem when merging from MySQL 5.7. The function innobase_kill_connection() which is bound to handlerton::kill_connection does not exist in MariaDB, but instead we have a similar function innobase_kill_query() that is bound to handlerton::kill_query(). At the very least, comments that refer to innobase_kill_connection() should be revised to refer to innobase_kill_query(). I suspect some difference near lock_trx_handle_wait(). While I was investigating this bug, I came up with the following clean-up patch that might marginally improve performance: diff --git a/storage/innobase/include/trx0trx.h b/storage/innobase/include/trx0trx.h index d0a67a7ed28..2d4132237af 100644 --- a/storage/innobase/include/trx0trx.h +++ b/storage/innobase/include/trx0trx.h @@ -1473,12 +1473,8 @@ class TrxInInnoDB { ut_ad(!is_async_rollback(trx)); - ++trx->in_depth; - - /* If trx->in_depth is greater than 1 then - transaction is already in InnoDB. */ - if (trx->in_depth > 1) { - + if (trx->in_depth++) { + /* The transaction is already inside InnoDB. */ return; } @@ -1528,9 +1524,7 @@ class TrxInInnoDB { ut_ad(trx->in_depth > 0); - --trx->in_depth; - - if (trx->in_depth > 0) { + if (--trx->in_depth > 0) { return; } Also, while I was looking at this, I noticed that my change to deprecate innodb_support_xa in MySQL 5.7.10 has not been merged.
          marko Marko Mäkelä made changes -
          Assignee Marko Mäkelä [ marko ] Jan Lindström [ jplindst ]
          elenst Elena Stepanova added a comment -

          Happened again, 10.2 revision 8f05c848c5d856f53fa907ae202deac465a17656.

          elenst Elena Stepanova added a comment - Happened again, 10.2 revision 8f05c848c5d856f53fa907ae202deac465a17656.
          jplindst Jan Lindström (Inactive) added a comment -

          To me this looks like optimizer does not stop when InnoDB has already reported transaction abort instead it just continues the statement execution but InnoDB has already thrown transaction away.

          jplindst Jan Lindström (Inactive) added a comment - To me this looks like optimizer does not stop when InnoDB has already reported transaction abort instead it just continues the statement execution but InnoDB has already thrown transaction away.
          jplindst Jan Lindström (Inactive) added a comment -

          Does not repeat with MySQL 5.7.18, repeats easily with current 10.2.

          jplindst Jan Lindström (Inactive) added a comment - Does not repeat with MySQL 5.7.18, repeats easily with current 10.2.
          jplindst Jan Lindström (Inactive) made changes -
          Status Open [ 1 ] In Progress [ 3 ]
          jplindst Jan Lindström (Inactive) added a comment -

          http://lists.askmonty.org/pipermail/commits/2017-May/011141.html

          Could not yet construct repeatable test case from RQG test case log.

          jplindst Jan Lindström (Inactive) added a comment - http://lists.askmonty.org/pipermail/commits/2017-May/011141.html Could not yet construct repeatable test case from RQG test case log.
          jplindst Jan Lindström (Inactive) made changes -
          Assignee Jan Lindström [ jplindst ] Marko Mäkelä [ marko ]
          Status In Progress [ 3 ] In Review [ 10002 ]
          marko Marko Mäkelä added a comment -

          Please include my clean-up patch as well, and do not construct the TrxInInnoDB object before DBUG_ENTER.

          For what it is worth, starting with MDEV-11236, InnoDB in MariaDB now tolerates (and ignores) a statement rollback from the SQL layer even after the transaction has been aborted.

          marko Marko Mäkelä added a comment - Please include my clean-up patch as well, and do not construct the TrxInInnoDB object before DBUG_ENTER. For what it is worth, starting with MDEV-11236 , InnoDB in MariaDB now tolerates (and ignores) a statement rollback from the SQL layer even after the transaction has been aborted.
          marko Marko Mäkelä made changes -
          Assignee Marko Mäkelä [ marko ] Jan Lindström [ jplindst ]
          Status In Review [ 10002 ] Stalled [ 10000 ]
          jplindst Jan Lindström (Inactive) made changes -
          Status Stalled [ 10000 ] In Progress [ 3 ]
          jplindst Jan Lindström (Inactive) added a comment -

          commit f4df8c00c957146f04db031f1f9f80aab229d1d2
          Author: Jan Lindström <jan.lindstrom@mariadb.com>
          Date: Wed May 10 23:13:06 2017 +0300

          MDEV-11197: TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed

          TrxInInnoDB should be constructed to track if a transaction is executing
          inside InnoDB code i.e. it is like a gate between Server and InnoDB
          ::rnd_next() is called from Server and thus construct TrxInInnoDB
          also there.

          Applied suggested clean-up to TrxInInnoDB class functions enter()
          and exit(). Note that exactly original did not work for enter().

          jplindst Jan Lindström (Inactive) added a comment - commit f4df8c00c957146f04db031f1f9f80aab229d1d2 Author: Jan Lindström <jan.lindstrom@mariadb.com> Date: Wed May 10 23:13:06 2017 +0300 MDEV-11197 : TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed TrxInInnoDB should be constructed to track if a transaction is executing inside InnoDB code i.e. it is like a gate between Server and InnoDB ::rnd_next() is called from Server and thus construct TrxInInnoDB also there. Applied suggested clean-up to TrxInInnoDB class functions enter() and exit(). Note that exactly original did not work for enter().
          jplindst Jan Lindström (Inactive) made changes -
          Fix Version/s 10.2.6 [ 22527 ]
          Fix Version/s 10.2 [ 14601 ]
          Resolution Fixed [ 1 ]
          Status In Progress [ 3 ] Closed [ 6 ]
          serg Sergei Golubchik made changes -
          Workflow MariaDB v3 [ 78160 ] MariaDB v4 [ 151162 ]

          People

            jplindst Jan Lindström (Inactive)
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            3 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.