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

Server crashes in Binlog_crypt_data::init trying to feed encrypted log without decryption capabilities

Details

    Description

      10.1 bccd0b5e0e

      #3  <signal handler called>
      #4  0x0000000000000000 in ?? ()
      #5  0x00007ff144ec1a60 in Binlog_crypt_data::init (this=0x7ff139c105b0, sch=1, kv=1) at /data/src/10.1/sql/rpl_constants.h:99
      #6  0x00007ff144ed0303 in Format_description_log_event::start_decryption (this=0x7ff139c104f0, sele=0x7ff139c5e570) at /data/src/10.1/sql/log_event.cc:5331
      #7  0x00007ff144bd1a16 in send_format_descriptor_event (info=0x7ff145a23b80, log=0x7ff145a23730, linfo=0x7ff145a238b0, start_pos=4) at /data/src/10.1/sql/sql_repl.cc:2399
      #8  0x00007ff144bd2b0a in mysql_binlog_send (thd=0x7ff13b0cf070, log_ident=0x7ff139c22088 "master-bin.000001", pos=4, flags=0) at /data/src/10.1/sql/sql_repl.cc:2855
      #9  0x00007ff144b9b4fa in dispatch_command (command=COM_BINLOG_DUMP, thd=0x7ff13b0cf070, packet=0x7ff13b0d5071 "", packet_length=27) at /data/src/10.1/sql/sql_parse.cc:1724
      #10 0x00007ff144b99610 in do_command (thd=0x7ff13b0cf070) at /data/src/10.1/sql/sql_parse.cc:1108
      #11 0x00007ff144ccf6db in do_handle_one_connection (thd_arg=0x7ff13b0cf070) at /data/src/10.1/sql/sql_connect.cc:1350
      #12 0x00007ff144ccf43f in handle_one_connection (arg=0x7ff13b0cf070) at /data/src/10.1/sql/sql_connect.cc:1262
      #13 0x00007ff144fb25a2 in pfs_spawn_thread (arg=0x7ff1418283f0) at /data/src/10.1/storage/perfschema/pfs.cc:1860
      #14 0x00007ff1442970a4 in start_thread (arg=0x7ff145a25b00) at pthread_create.c:309
      #15 0x00007ff14244f87d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
      

      Note: The test is for reproducing and debugging. There will be no need to add it to MTR suites, instead binlog_encryption.encrypted_master_switch_to_unencrypted should be finalized – it currently does not have result file, and probably the test itself will need to be modified to match the expected behavior after the fix.

      Test case

      --source include/master-slave.inc
      --source include/have_binlog_format_mixed.inc
       
      --connection slave
      --source include/stop_slave.inc
       
      --connection master
      --enable_reconnect
       
      --exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
      shutdown_server 10;
      --source include/wait_until_disconnected.inc
       
      --exec echo "restart:--encrypt-binlog=1 --plugin-load-add=$FILE_KEY_MANAGEMENT_SO --file-key-management --loose-file-key-management-filename=$MYSQL_TEST_DIR/std_data/keys.txt" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
      --source include/wait_until_connected_again.inc
       
      CREATE TABLE t (i INT);
       
      --exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
      shutdown_server 10;
      --source include/wait_until_disconnected.inc
       
      --exec echo "restart:--encrypt-binlog=0" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
      --source include/wait_until_connected_again.inc
       
      --save_master_pos
       
      --connection slave
      --source include/start_slave.inc
      --sync_with_master
      

      Attachments

        Activity

          Please also check if you get the stack trace in the error log, I don't:

          161116  2:02:26 [ERROR] mysqld got signal 11 ;
          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.1.20-MariaDB-debug
          key_buffer_size=1048576
          read_buffer_size=131072
          max_used_connections=2
          max_threads=153
          thread_count=2
          It is possible that mysqld could use up to 
          key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62983 K  bytes of memory
          Hope that's ok; if not, decrease some variables in the equation.
           
          Thread pointer: 0x0x7ff13b0cf070
          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 = 0x7ff145a25230 thread_stack 0x48400
          /data/bld/10.1/bin/mysqld(my_print_stacktrace+0x38)[0x7ff145438125]
          /data/bld/10.1/bin/mysqld(handle_fatal_signal+0x399)[0x7ff144dd5250]
          /lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7ff14429e8d0]
           
          Trying to get some variables.
          Some pointers may be invalid and cause the dump to abort.
          Query (0x0): 
          Connection ID (thread ID): 4
          Status: NOT_KILLED
          

          If it's persistent, maybe it's a good chance to figure out why it happens, we've had this problem for a while, and it's pain.

          elenst Elena Stepanova added a comment - Please also check if you get the stack trace in the error log, I don't: 161116 2:02:26 [ERROR] mysqld got signal 11 ; 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.1.20-MariaDB-debug key_buffer_size=1048576 read_buffer_size=131072 max_used_connections=2 max_threads=153 thread_count=2 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62983 K bytes of memory Hope that's ok; if not, decrease some variables in the equation.   Thread pointer: 0x0x7ff13b0cf070 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 = 0x7ff145a25230 thread_stack 0x48400 /data/bld/10.1/bin/mysqld(my_print_stacktrace+0x38)[0x7ff145438125] /data/bld/10.1/bin/mysqld(handle_fatal_signal+0x399)[0x7ff144dd5250] /lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7ff14429e8d0]   Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0x0): Connection ID (thread ID): 4 Status: NOT_KILLED If it's persistent, maybe it's a good chance to figure out why it happens, we've had this problem for a while, and it's pain.

          Same happens upon server recovery from an encrypted binlog (if the master does not have decryption capabilities).

          elenst Elena Stepanova added a comment - Same happens upon server recovery from an encrypted binlog (if the master does not have decryption capabilities).

          People

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