[Commits] ee61d3757c3: MDEV-10259 mysqld crash with certain statement length and...

18 May 2018

revision-id: ee61d3757c3e12861d8801ce868c396efc0da61f (mariadb-10.1.33-12-gee61d3757c3)
parent(s): 0bd2b802546c09361fe7823624e09bde16c976ac
author: sachin
committer: sachin
timestamp: 2018-05-18 17:35:33 +0530
message:

MDEV-10259 mysqld crash with certain statement length and...
order with Galera and encrypt-tmp-files=1

Problem:- If trans_cache (IO_CACHE) uses encrypted tmp file
then on next DML server will crash.

Case:-
 Lets take a case , we have a table t1 , We try to do 2 inserts in t1
  1. A really long insert so that trans_cache has to use temp_file
  2. Just a small insert

Analysis:- Actually server crashes from inside of galera
library.
/lib64/libc.so.6(abort+0x175)[0x7fb5ba779dc5]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera3FSMINS_9TrxHandle5State...
mysys/stacktrace.c:247(my_print_stacktrace)[0x7fb5a714940e]
sql/signal_handler.cc:160(handle_fatal_signal)[0x7fb5a715c1bd]
sql/wsrep_hton.cc:257(wsrep_rollback)[0x7fb5bcce923a]
sql/wsrep_hton.cc:268(wsrep_rollback)[0x7fb5bcce9368]
sql/handler.cc:1658(ha_rollback_trans(THD*, bool))[0x7fb5bcd4f41a]
sql/handler.cc:1483(ha_commit_trans(THD*, bool))[0x7fb5bcd4f804]

but actual issue is not in galera but in mariadb, because for 2nd
insert we should never call rollback. We are calling rollback because
log_and_order fails it fails because write_cache fails , It fails
because after reinit_io_cache(trans_cache) , my_b_bytes_in_cache says 0
so we look into tmp_file for data , which is obviously wrong since temp
was used for previous insert and it no longer exist.
wsrep_write_cache_inc() reads the IO_CACHE in a loop, filling it with
my_b_fill() until it returns "0 bytes read". Later
MYSQL_BIN_LOG::write_cache() does the same.  wsrep_write_cache_inc()
assumes that reading a zero bytes past EOF leaves the old data in the
cache

Solution:- There is two issue in my_b_encr_read
1st we should never equal read_end to info->buffer. I mean this
does not make sense read_end should always point to end of buffer.
2nd For most of the case(apart from async IO_CACHE) info->pos_in_file
should be equal to info->buffer position wrt to temp file , since
in this case we are not changing info->buffer it should remain
unchanged.

---
 .../suite/galera/r/galera_encrypt_tmp_files.result | 35 +++++++++++
 .../suite/galera/t/galera_encrypt_tmp_files.cnf    |  8 +++
 .../suite/galera/t/galera_encrypt_tmp_files.test   | 57 +++++++++++++++++
 sql/mf_iocache_encr.cc                             |  4 +-
 unittest/sql/mf_iocache-t.cc                       | 72 +++++++++++++++++++++-
 5 files changed, 173 insertions(+), 3 deletions(-)

diff --git a/mysql-test/suite/galera/r/galera_encrypt_tmp_files.result b/mysql-test/suite/galera/r/galera_encrypt_tmp_files.result
new file mode 100644
index 00000000000..63f6c281af1
--- /dev/null
+++ b/mysql-test/suite/galera/r/galera_encrypt_tmp_files.result
@@ -0,0 +1,35 @@
+SELECT VARIABLE_VALUE = 'Synced' FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_local_state_comment';
+VARIABLE_VALUE = 'Synced'
+1
+SELECT VARIABLE_VALUE = 2 FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_cluster_size';
+VARIABLE_VALUE = 2
+1
+CREATE TABLE t1 (f1 INTEGER PRIMARY KEY) Engine=InnoDB;
+INSERT INTO t1 VALUES (1);
+SELECT VARIABLE_VALUE = 'Synced' FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_local_state_comment';
+VARIABLE_VALUE = 'Synced'
+1
+SELECT VARIABLE_VALUE = 2 FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_cluster_size';
+VARIABLE_VALUE = 2
+1
+SELECT COUNT(*) = 1 FROM t1;
+COUNT(*) = 1
+1
+DROP TABLE t1;
+CREATE TABLE `t1` (
+`col1` int(11) NOT NULL,
+`col2` varchar(64) NOT NULL DEFAULT '',
+`col3` varchar(32) NOT NULL DEFAULT '0',
+`col4` varchar(64) NOT NULL DEFAULT '',
+`col5` tinyint(4) NOT NULL DEFAULT '0',
+`col6` int(11) NOT NULL DEFAULT '0',
+`col7` varchar(64) NOT NULL DEFAULT '',
+`col8` tinyint(4) NOT NULL DEFAULT '0',
+`col9` tinyint(4) NOT NULL DEFAULT '0',
+`col10` text NOT NULL,
+`col11` varchar(255) NOT NULL DEFAULT '',
+`col12` tinyint(4) NOT NULL DEFAULT '1'
+) ;
+create table t2 (test int);
+insert into t2 values (1);
+drop table t1,t2;
diff --git a/mysql-test/suite/galera/t/galera_encrypt_tmp_files.cnf b/mysql-test/suite/galera/t/galera_encrypt_tmp_files.cnf
new file mode 100644
index 00000000000..0f7f80b7d0b
--- /dev/null
+++ b/mysql-test/suite/galera/t/galera_encrypt_tmp_files.cnf
@@ -0,0 +1,8 @@
+!include ../galera_2nodes.cnf
+[mysqld]
+
+encrypt-tmp-files = 1
+plugin-load-add= @ENV.FILE_KEY_MANAGEMENT_SO
+file-key-management
+loose-file-key-management-filename= @ENV.MYSQL_TEST_DIR/std_data/keys.txt
+log-bin
diff --git a/mysql-test/suite/galera/t/galera_encrypt_tmp_files.test b/mysql-test/suite/galera/t/galera_encrypt_tmp_files.test
new file mode 100644
index 00000000000..c42c3dbd98a
--- /dev/null
+++ b/mysql-test/suite/galera/t/galera_encrypt_tmp_files.test
@@ -0,0 +1,57 @@
+#  This file tests that mariadb cluster should not crash when encrypt_tmp_file
+#  is enabled
+
+--source include/galera_cluster.inc
+--source include/have_innodb.inc
+
+SELECT VARIABLE_VALUE = 'Synced' FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_local_state_comment';
+SELECT VARIABLE_VALUE = 2 FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_cluster_size';
+
+CREATE TABLE t1 (f1 INTEGER PRIMARY KEY) Engine=InnoDB;
+INSERT INTO t1 VALUES (1);
+
+--connection node_2
+SELECT VARIABLE_VALUE = 'Synced' FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_local_state_comment';
+SELECT VARIABLE_VALUE = 2 FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_cluster_size';
+
+SELECT COUNT(*) = 1 FROM t1;
+
+DROP TABLE t1;
+
+--connection node_1
+
+CREATE TABLE `t1` (
+  `col1` int(11) NOT NULL,
+  `col2` varchar(64) NOT NULL DEFAULT '',
+  `col3` varchar(32) NOT NULL DEFAULT '0',
+  `col4` varchar(64) NOT NULL DEFAULT '',
+  `col5` tinyint(4) NOT NULL DEFAULT '0',
+  `col6` int(11) NOT NULL DEFAULT '0',
+  `col7` varchar(64) NOT NULL DEFAULT '',
+  `col8` tinyint(4) NOT NULL DEFAULT '0',
+  `col9` tinyint(4) NOT NULL DEFAULT '0',
+  `col10` text NOT NULL,
+  `col11` varchar(255) NOT NULL DEFAULT '',
+  `col12` tinyint(4) NOT NULL DEFAULT '1'
+) ;
+
+#Although we just need $counter >= 907 for IO_CACHE to use
+#encrypted temp file. Just on safe side I am using $counter
+# = 1100
+--disable_query_log
+--let $counter=1100
+--let $query= (1,'test','test','test',0,0,'-1',0,0,'','',-1)
+while($counter)
+{
+  --let $query= $query ,(1,'test','test','test',0,0,'-1',0,0,'','',-1)
+  --dec $counter
+}
+--let $query= INSERT INTO t1 values $query ;
+--eval $query
+--enable_query_log
+#INSERT INTO `t1` VALUE
+
+create table t2 (test int);
+insert into t2 values (1);
+
+drop table t1,t2;
diff --git a/sql/mf_iocache_encr.cc b/sql/mf_iocache_encr.cc
index 149e6feb605..f26a437a25a 100644
--- a/sql/mf_iocache_encr.cc
+++ b/sql/mf_iocache_encr.cc
@@ -49,8 +49,8 @@ static int my_b_encr_read(IO_CACHE *info, uchar *Buffer, size_t Count)
 
   if (pos_in_file == info->end_of_file)
   {
-    info->read_pos= info->read_end= info->buffer;
-    info->pos_in_file= pos_in_file;
+    /*  reading past EOF should not empty the cache */
+    info->read_pos= info->read_end;
     info->error= 0;
     DBUG_RETURN(MY_TEST(Count));
   }
diff --git a/unittest/sql/mf_iocache-t.cc b/unittest/sql/mf_iocache-t.cc
index 31f98562521..1b04f8eb0d3 100644
--- a/unittest/sql/mf_iocache-t.cc
+++ b/unittest/sql/mf_iocache-t.cc
@@ -187,10 +187,76 @@ void mdev9044()
   close_cached_file(&info);
 }
 
+/* 2 Reads (with my_b_fill) in cache makes second read to fail */
+void mdev10259()
+{
+  int res;
+  uchar buf[200];
+  memset(buf, FILL, sizeof(buf));
+
+  diag("MDEV-10259- mysqld crash with certain statement length and order with"
+         " Galera and encrypt-tmp-files=1");
+
+  init_io_cache_encryption();
+
+  res= open_cached_file(&info, 0, 0, CACHE_SIZE, 0);
+  ok(res == 0, "open_cached_file" INFO_TAIL);
+
+  res= my_b_write(&info, buf, sizeof(buf));
+  ok(res == 0 && info.pos_in_file == 0, "200 write" INFO_TAIL);
+
+  res= my_b_flush_io_cache(&info, 1);
+  ok(res == 0, "flush" INFO_TAIL);
+
+  ulong saved_pos=  my_b_tell(&info);
+  res= reinit_io_cache(&info, READ_CACHE, 0, 0, 0);
+  ok(res == 0, "reinit READ_CACHE" INFO_TAIL);
+
+  res= my_b_fill(&info);
+  ok(res == 200, "fill" INFO_TAIL);
+
+  res= my_b_fill(&info);
+  ok(res == 0, "fill" INFO_TAIL);
+
+  res= my_b_fill(&info);
+  ok(res == 0, "fill" INFO_TAIL);
+
+  res= reinit_io_cache(&info, WRITE_CACHE, saved_pos, 0, 0);
+  ok(res == 0, "reinit WRITE_CACHE" INFO_TAIL);
+
+  res= reinit_io_cache(&info, READ_CACHE, 0, 0, 0);
+  ok(res == 0, "reinit READ_CACHE" INFO_TAIL);
+
+  ok(200 == my_b_bytes_in_cache(&info),"my_b_bytes_in_cache == 200");
+
+  res= my_b_fill(&info);
+  ok(res == 0, "fill" INFO_TAIL);
+
+  res= my_b_fill(&info);
+  ok(res == 0, "fill" INFO_TAIL);
+
+  res= my_b_fill(&info);
+  ok(res == 0, "fill" INFO_TAIL);
+
+  res= reinit_io_cache(&info, WRITE_CACHE, saved_pos, 0, 0);
+  ok(res == 0, "reinit WRITE_CACHE" INFO_TAIL);
+
+  res= reinit_io_cache(&info, READ_CACHE, 0, 0, 0);
+  ok(res == 0, "reinit READ_CACHE" INFO_TAIL);
+
+  ok(200 == my_b_bytes_in_cache(&info),"my_b_bytes_in_cache == 200");
+
+  res= my_b_read(&info, buf, sizeof(buf)) || data_bad(buf, sizeof(buf));
+  ok(res == 0 && info.pos_in_file == 0, "large read" INFO_TAIL);
+
+  close_cached_file(&info);
+
+}
+
 int main(int argc __attribute__((unused)),char *argv[])
 {
   MY_INIT(argv[0]);
-  plan(29);
+  plan(46);
 
   /* temp files with and without encryption */
   encrypt_tmp_files= 1;
@@ -202,6 +268,10 @@ int main(int argc __attribute__((unused)),char *argv[])
   /* regression tests */
   mdev9044();
 
+  encrypt_tmp_files= 1;
+  mdev10259();
+  encrypt_tmp_files= 0;
+
   my_end(0);
   return exit_status();
 }

    