[MDEV-11288] Server crashes in Binlog_crypt_data::init trying to feed encrypted log without decryption capabilities Created: 2016-11-16  Updated: 2016-12-06  Resolved: 2016-12-06

Status: Closed
Project: MariaDB Server
Component/s: Encryption, Replication
Affects Version/s: 10.1
Fix Version/s: 10.1.20

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: None


 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



 Comments   
Comment by Elena Stepanova [ 2016-11-16 ]

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.

Comment by Elena Stepanova [ 2016-11-22 ]

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

Generated at Thu Feb 08 07:48:47 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.