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

[Draft] Server crashed in in _IO_vfprintf_internal

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.1
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None

      Description

      Observed once on 10.1 commit 3c4668c519999e002182a8c48cde93c3ebfaddd7

      #3  <signal handler called>
      #4  0x00007efff93bc061 in _IO_vfprintf_internal (s=<optimized out>, format=<optimized out>, ap=<optimized out>) at vfprintf.c:1630
      #5  0x00007efff93bee54 in buffered_vfprintf (s=0x7efff972a180, format=<optimized out>, args=<optimized out>) at vfprintf.c:2313
      #6  0x00007efff93b988e in _IO_vfprintf_internal (s=0x7efff972a180, format=0x117d4e0 "safe_mutex:  Count was %d in thread 0x%lx when locking mutex %s at %s, line %d (error: %d (%d))\n", ap=0x7effcd369738) at vfprintf.c:1316
      #7  0x00007efff93c44e7 in __fprintf (stream=<optimized out>, format=<optimized out>) at fprintf.c:33
      #8  0x0000000000ee9e3c in safe_cond_timedwait (cond=0x7effcd369a70, mp=0x7efff8b60870, abstime=0x7effcd369a30, file=0xfe36e0 "/home/elenst/git/10.1/include/mysql/psi/mysql_thread.h", line=1202) at /home/elenst/git/10.1/mysys/thr_mutex.c:566
      #9  0x000000000080d3ee in inline_mysql_cond_timedwait (that=0x7effcd369a70, mutex=0x7efff8b60870, abstime=0x7effcd369a30, src_file=0xfe3718 "/home/elenst/git/10.1/sql/my_apc.cc", src_line=194) at /home/elenst/git/10.1/include/mysql/psi/mysql_thread.h:1202
      #10 0x000000000080d96b in Apc_target::make_apc_call (this=0x7efff8b62ce8, caller_thd=0x7efff8b75070, call=0x7effcd369b10, timeout_sec=30, timed_out=0x7effcd369bde) at /home/elenst/git/10.1/sql/my_apc.cc:194
      #11 0x0000000000709702 in fill_show_explain (thd=0x7efff8b75070, table=0x7effddd89238, cond=0x0) at /home/elenst/git/10.1/sql/sql_show.cc:2656
      #12 0x000000000071d114 in get_schema_tables_result (join=0x7effddd54ea8, executed_place=PROCESSED_BY_JOIN_EXEC) at /home/elenst/git/10.1/sql/sql_show.cc:7939
      #13 0x00000000006c1b62 in JOIN::exec_inner (this=0x7effddd54ea8) at /home/elenst/git/10.1/sql/sql_select.cc:2547
      #14 0x00000000006c11db in JOIN::exec (this=0x7effddd54ea8) at /home/elenst/git/10.1/sql/sql_select.cc:2397
      #15 0x00000000006c478e in mysql_select (thd=0x7efff8b75070, rref_pointer_array=0x7effddd87ac8, tables=0x7effddd89238, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x7effddd54e88, unit=0x7effddd87160, select_lex=0x7effddd87850) at /home/elenst/git/10.1/sql/sql_select.cc:3326
      #16 0x00000000006ba8f7 in handle_select (thd=0x7efff8b75070, lex=0x7effddd87098, result=0x7effddd54e88, setup_tables_done_option=0) at /home/elenst/git/10.1/sql/sql_select.cc:373
      #17 0x000000000068bf78 in execute_sqlcom_select (thd=0x7efff8b75070, all_tables=0x7effddd89238) at /home/elenst/git/10.1/sql/sql_parse.cc:5782
      #18 0x00000000006822c2 in mysql_execute_command (thd=0x7efff8b75070) at /home/elenst/git/10.1/sql/sql_parse.cc:2926
      #19 0x00000000006a8e82 in Prepared_statement::execute (this=0x7effddd72470, expanded_query=0x7effcd36b550, open_cursor=false) at /home/elenst/git/10.1/sql/sql_prepare.cc:4012
      #20 0x00000000006a7d66 in Prepared_statement::execute_loop (this=0x7effddd72470, expanded_query=0x7effcd36b550, open_cursor=false, packet=0x0, packet_end=0x0) at /home/elenst/git/10.1/sql/sql_prepare.cc:3644
      #21 0x00000000006a5e3d in mysql_sql_stmt_execute (thd=0x7efff8b75070) at /home/elenst/git/10.1/sql/sql_prepare.cc:2777
      #22 0x00000000006822f3 in mysql_execute_command (thd=0x7efff8b75070) at /home/elenst/git/10.1/sql/sql_parse.cc:2937
      #23 0x000000000068f537 in mysql_parse (thd=0x7efff8b75070, rawbuf=0x7effddd54088 "EXECUTE show_expl_stmt USING @thread_id", length=39, parser_state=0x7effcd36c110) at /home/elenst/git/10.1/sql/sql_parse.cc:7165
      #24 0x000000000067e545 in dispatch_command (command=COM_QUERY, thd=0x7efff8b75070, packet=0x7efff8b7b071 " EXECUTE show_expl_stmt USING @thread_id", packet_length=40) at /home/elenst/git/10.1/sql/sql_parse.cc:1462
      #25 0x000000000067d30f in do_command (thd=0x7efff8b75070) at /home/elenst/git/10.1/sql/sql_parse.cc:1090
      #26 0x00000000007aa678 in do_handle_one_connection (thd_arg=0x7efff8b75070) at /home/elenst/git/10.1/sql/sql_connect.cc:1347
      #27 0x00000000007aa3bd in handle_one_connection (arg=0x7efff8b75070) at /home/elenst/git/10.1/sql/sql_connect.cc:1258
      #28 0x00007efff9d33e9a in start_thread (arg=0x7effcd36d700) at pthread_create.c:308
      #29 0x00007efff94648bd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
      
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7effddd54188): SHOW EXPLAIN FOR 20
      Connection ID (thread ID): 22
      Status: NOT_KILLED
      

      The test that was running:

      perl /home/elenst/bzr/randgen-mariadb-patches/runall-new.pl --no-mask --seed=1429761003 --threads=8 --duration=600 --queries=100M --reporters=QueryTimeout,Backtrace,ErrorLog,Deadlock --redefine=conf/mariadb/general-workarounds.yy --redefine=10.1-encryption-redefine.yy --mysqld=--log_output=FILE --mysqld=--log_bin_trust_function_creators=1 --mysqld=--slave_parallel_threads=8 --use-gtid=current_pos --mysqld=--plugin-load-add=file_key_management.so --mysqld=--file_key_management_filename=/home/elenst/git/10.1/mysql-test/std_data/keys.txt --views --grammar=conf/runtime/connect_kill_sql.yy --gendata=conf/runtime/connect_kill_data.zz --engine=InnoDB --rpl_mode=mixed --mysqld=--slave-skip-errors=1049,1305,1539,1505,1317 --mysqld=--innodb-encrypt-tables=OFF --mysqld=--innodb-encrypt-log=ON --mysqld=--innodb_encryption_rotate_key_age=100 --mysqld=--innodb_encryption_rotation_iops=100 --mysqld=--encrypt-tmp-disk-tables=1 --mtr-build-thread=300 --basedir1=/home/elenst/git/10.1 --vardir1=/home/elenst/test_results/encryption-3/current1_1
      

      RQG of lp:~elenst/randgen/mariadb-patches revno 1010 with the following patch:

      === modified file 'lib/DBServer/MySQL/MySQLd.pm'
      --- lib/DBServer/MySQL/MySQLd.pm        2014-08-12 22:46:54 +0000
      +++ lib/DBServer/MySQL/MySQLd.pm        2015-04-19 23:47:21 +0000
      @@ -364,6 +364,8 @@
               } else {
                 push(@$boot_options, @{$self->[MYSQLD_SERVER_OPTIONS]});
               }
      +       push @$boot_options, "--innodb-encrypt-tables=OFF";
      +       push @$boot_options, "--innodb-encrypt-log=OFF";
               push @$boot_options, "--skip-log-bin";
               my $command = $self->generateCommand($boot_options);
               my $bootlog = $self->vardir."/boot.log";
      
      

      10.1-encryption-redefine.yy, mysql.err, mysql.log and all threads' stack trace are attached.

        Gliffy Diagrams

          Attachments

          1. 10.1-encryption-redefine.yy
            5 kB
          2. mysql.err
            6 kB
          3. mysql.log
            37 kB
          4. threads
            66 kB
          5. threads_full
            257 kB

            Activity

            Hide
            elenst Elena Stepanova added a comment -

            Got another occasion of this.

            perl /home/elenst/bzr/randgen-mariadb-patches/runall-new.pl --no-mask --seed=1430256717 --threads=16 --duration=400 --queries=100M --reporters=QueryTimeout,Backtrace,ErrorLog,Deadlock --redefine=conf/mariadb/general-workarounds.yy --redefine=conf/mariadb/10.0-features-redefine.yy --mysqld=--log_output=FILE --mysqld=--slow_query_log --mysqld=--log_bin_trust_function_creators=1 --mysqld=--query_cache_size=64M --views --grammar=conf/runtime/connect_kill_sql.yy --gendata=conf/runtime/connect_kill_data.zz --engine=InnoDB --rpl_mode=mixed --mysqld=--slave-skip-errors=1049,1305,1539,1505,1317 --mysqld=--slave-parallel-mode=conservative --mysqld=--binlog_commit_wait_count=10 --mysqld=--binlog_commit_wait_usec=1000000 --mysqld=--slave-parallel-threads=1 --use-gtid=slave_pos --mtr-build-thread=73 --basedir1=/home/elenst/git/10.1 --vardir1=/home/elenst/test_results/10.1-parallel-replication-8/current1_1
            

            ~elenst/randgen/mariadb-patches revno 1016
            10.1 commit 46816996

            Show
            elenst Elena Stepanova added a comment - Got another occasion of this. perl /home/elenst/bzr/randgen-mariadb-patches/runall-new.pl --no-mask --seed=1430256717 --threads=16 --duration=400 --queries=100M --reporters=QueryTimeout,Backtrace,ErrorLog,Deadlock --redefine=conf/mariadb/general-workarounds.yy --redefine=conf/mariadb/10.0-features-redefine.yy --mysqld=--log_output=FILE --mysqld=--slow_query_log --mysqld=--log_bin_trust_function_creators=1 --mysqld=--query_cache_size=64M --views --grammar=conf/runtime/connect_kill_sql.yy --gendata=conf/runtime/connect_kill_data.zz --engine=InnoDB --rpl_mode=mixed --mysqld=--slave-skip-errors=1049,1305,1539,1505,1317 --mysqld=--slave-parallel-mode=conservative --mysqld=--binlog_commit_wait_count=10 --mysqld=--binlog_commit_wait_usec=1000000 --mysqld=--slave-parallel-threads=1 --use-gtid=slave_pos --mtr-build-thread=73 --basedir1=/home/elenst/git/10.1 --vardir1=/home/elenst/test_results/10.1-parallel-replication-8/current1_1 ~elenst/randgen/mariadb-patches revno 1016 10.1 commit 46816996

              People

              • Assignee:
                elenst Elena Stepanova
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated: