BUG#11754117 incorrect logging of INSERT into auto-increment

BUG#11761686 insert_id event is not filtered.
  
Two issues are covered.
  
INSERT into autoincrement field which is not the first part in the composed primary key 
is unsafe by autoincrement logging design. The case is specific to MyISAM engine
because Innodb does not allow such table definition.
  
However no warnings and row-format logging in the MIXED mode was done, and
that is fixed.
  
Int-, Rand-, User-var log-events were not filtered along with their parent
query that made possible them to screw up execution context of the following
query.
  
Fixed with deferring their execution until the parent query.

******
Bug#11754117 

Post review fixes.

15 files changed, 397 insertions, 4 deletions

diff --git a/mysql-test/suite/rpl/r/rpl_auto_increment_bug45679.result b/mysql-test/suite/rpl/r/rpl_auto_increment_bug45679.result
new file mode 100644
index 00000000000..75f4e661dc1
--- /dev/null
+++ b/mysql-test/suite/rpl/r/rpl_auto_increment_bug45679.result
@@ -0,0 +1,36 @@
+include/master-slave.inc
+[connection master]
+call mtr.add_suppression('Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT.');
+create table tm (b int auto_increment, a int, primary key (a,b)) engine= myisam;
+create table ti (b int auto_increment, a int, primary key (a,b)) engine= innodb;
+ERROR 42000: Incorrect table definition; there can be only one auto column and it must be defined as a key
+create table ti (b int auto_increment, a int, primary key (b,a)) engine= innodb;
+set @@binlog_format=statement;
+*** autoincrement field is not the first in PK warning must be there: ***
+insert into tm set b=null, a=1;
+Warnings:
+Note	1592	Statement may not be safe to log in statement format.
+show warnings;
+Level	Code	Message
+Note	1592	Statement may not be safe to log in statement format.
+*** no warning when autoincrement is the first in PK
+insert into ti set b=null, a=1;
+show warnings;
+Level	Code	Message
+create function multi_part_pk_with_autoinc (arg int)
+returns int
+begin
+insert into tm set b=null, a=arg;
+return arg;
+end//
+select multi_part_pk_with_autoinc (3);
+multi_part_pk_with_autoinc (3)
+3
+*** autoincrement field is not the first in PK warning must be there: ***
+show warnings;
+Level	Code	Message
+set @@binlog_format=mixed;
+insert into tm set b=null, a=2;
+drop table tm, ti;
+drop function multi_part_pk_with_autoinc;
+include/rpl_end.inc
diff --git a/mysql-test/suite/rpl/r/rpl_filter_tables_not_exist.result b/mysql-test/suite/rpl/r/rpl_filter_tables_not_exist.result
index c88dcee9dbc..f0dc97b71f2 100644
--- a/mysql-test/suite/rpl/r/rpl_filter_tables_not_exist.result
+++ b/mysql-test/suite/rpl/r/rpl_filter_tables_not_exist.result
@@ -114,4 +114,25 @@ id	c
 3	3
 [on master]
 drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+CREATE TABLE test.t5 (a INT AUTO_INCREMENT PRIMARY KEY, b INT, c INT);
+CREATE TABLE test.t1 (a INT);
+INSERT INTO test.t1 VALUES(1);
+call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT");
+CREATE TABLE test.t_slave (a INT AUTO_INCREMENT PRIMARY KEY, b INT, c INT);
+CREATE TRIGGER t1_update AFTER UPDATE ON test.t1 FOR EACH ROW
+INSERT INTO test.t_slave VALUES(NULL, ROUND(RAND() * 1000), @c);
+SET INSERT_ID=2;
+SET @c=2;
+SET @@rand_seed1=10000000, @@rand_seed2=1000000;
+INSERT INTO t5 VALUES (NULL, ROUND(RAND() * 1000), @c);
+Warnings:
+Note	1592	Statement may not be safe to log in statement format.
+SELECT b into @b FROM test.t5;
+UPDATE test.t1 SET a=2;
+SELECT a AS 'ONE' into @a FROM test.t_slave;
+SELECT c AS 'NULL' into @c FROM test.t_slave;
+SELECT b into @b FROM test.t_slave;
+drop table test.t5;
+drop table test.t1;
+drop table test.t_slave;
 include/rpl_end.inc
diff --git a/mysql-test/suite/rpl/t/rpl_auto_increment_bug45679.test b/mysql-test/suite/rpl/t/rpl_auto_increment_bug45679.test
new file mode 100644
index 00000000000..6996e1c73c7
--- /dev/null
+++ b/mysql-test/suite/rpl/t/rpl_auto_increment_bug45679.test
@@ -0,0 +1,62 @@
+# Test of auto-increment.
+#
+# BUG#11754117-45670 
+# Multipart primary key with the autoincrement part not first in it
+# is replication unsafe.
+#
+
+source include/master-slave.inc;
+source include/have_binlog_format_mixed.inc;
+source include/have_innodb.inc;
+
+call mtr.add_suppression('Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT.');
+
+--connection master
+create table tm (b int auto_increment, a int, primary key (a,b)) engine= myisam;
+--error ER_WRONG_AUTO_KEY
+create table ti (b int auto_increment, a int, primary key (a,b)) engine= innodb;
+create table ti (b int auto_increment, a int, primary key (b,a)) engine= innodb;
+
+set @@binlog_format=statement;
+--echo *** autoincrement field is not the first in PK warning must be there: ***
+insert into tm set b=null, a=1;
+show warnings;
+--echo *** no warning when autoincrement is the first in PK
+insert into ti set b=null, a=1;
+show warnings;
+
+delimiter //;
+create function multi_part_pk_with_autoinc (arg int)
+returns int
+begin
+  insert into tm set b=null, a=arg;
+  return arg;
+end//
+delimiter ;//
+
+select multi_part_pk_with_autoinc (3);
+--echo *** autoincrement field is not the first in PK warning must be there: ***
+show warnings;
+
+set @@binlog_format=mixed;
+insert into tm set b=null, a=2;
+
+sync_slave_with_master;
+
+if (`select count(*) <> 3 from tm`)
+{
+  --echo Wrong result from SELECT on the slave side.
+  select * from tm;
+  --die
+}
+
+# cleanup
+
+--connection master
+
+drop table tm, ti;
+drop function multi_part_pk_with_autoinc;
+
+sync_slave_with_master;
+
+--source include/rpl_end.inc
diff --git a/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test b/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test
index 13c66f9f64b..b62a6e96437 100644
--- a/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test
+++ b/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test
@@ -206,4 +206,64 @@ SELECT * FROM t3;
 connection master;
 echo [on master];
 drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+
+--sync_slave_with_master
+
+#
+# BUG#11754117 - 45670: INTVAR_EVENTS FOR FILTERED-OUT QUERY_LOG_EVENTS ARE EXECUTED
+# Int-, Rand- and User- var events accompaning a filtered out Query-log-event should
+# be filtered as well.
+#
+connection master;
+CREATE TABLE test.t5 (a INT AUTO_INCREMENT PRIMARY KEY, b INT, c INT); # ignored on slave
+CREATE TABLE test.t1 (a INT); # accepted on slave
+INSERT INTO test.t1 VALUES(1);
+
+--sync_slave_with_master
+call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT");
+CREATE TABLE test.t_slave (a INT AUTO_INCREMENT PRIMARY KEY, b INT, c INT);
+CREATE TRIGGER t1_update AFTER UPDATE ON test.t1 FOR EACH ROW
+                               INSERT INTO test.t_slave VALUES(NULL, ROUND(RAND() * 1000), @c);
+
+connection master;
+SET INSERT_ID=2;
+SET @c=2;
+SET @@rand_seed1=10000000, @@rand_seed2=1000000;
+INSERT INTO t5 VALUES (NULL, ROUND(RAND() * 1000), @c); # to be ignored
+SELECT b into @b FROM test.t5;
+--let $b_master=`select @b`
+UPDATE test.t1 SET a=2; # to run trigger on slave
+
+--sync_slave_with_master
+
+# The proof:
+SELECT a AS 'ONE' into @a FROM test.t_slave;
+SELECT c AS 'NULL' into @c FROM test.t_slave;
+
+let $count= 1;
+let $table= test.t_slave;
+source include/wait_until_rows_count.inc;
+
+if (`SELECT @a != 2 and @c != NULL`)
+{
+    SELECT * FROM test.t_slave;
+    --die Intvar or user var from replication events unexpetedly escaped out to screw a following query applying context.
+}
+
+SELECT b into @b FROM test.t_slave;
+--let $b_slave=`select @b`
+
+if (`SELECT $b_slave = $b_master`)
+{
+    --echo Might be pure coincidence of two randoms from master and slave table. Don not panic yet.
+}
+
+# cleanup BUG#11754117
+connection master;
+drop table test.t5;
+drop table test.t1;
+
+--sync_slave_with_master
+drop table test.t_slave;
+
 --source include/rpl_end.inc
diff --git a/sql/log_event.cc b/sql/log_event.cc
index 427f27650dd..8606964113c 100644
--- a/sql/log_event.cc
+++ b/sql/log_event.cc
@@ -5257,11 +5257,12 @@ void Intvar_log_event::print(FILE* file, PRINT_EVENT_INFO* print_event_info)
 #endif
 
 
+#if defined(HAVE_REPLICATION)&& !defined(MYSQL_CLIENT)
+
 /*
   Intvar_log_event::do_apply_event()
 */
 
-#if defined(HAVE_REPLICATION)&& !defined(MYSQL_CLIENT)
 int Intvar_log_event::do_apply_event(Relay_log_info const *rli)
 {
   /*
@@ -5270,6 +5271,9 @@ int Intvar_log_event::do_apply_event(Relay_log_info const *rli)
    */
   const_cast<Relay_log_info*>(rli)->set_flag(Relay_log_info::IN_STMT);
 
+  if (rli->deferred_events_collecting)
+    return rli->deferred_events->add(this);
+
   switch (type) {
   case LAST_INSERT_ID_EVENT:
     thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt= 1;
@@ -5375,6 +5379,9 @@ int Rand_log_event::do_apply_event(Relay_log_info const *rli)
    */
   const_cast<Relay_log_info*>(rli)->set_flag(Relay_log_info::IN_STMT);
 
+  if (rli->deferred_events_collecting)
+    return rli->deferred_events->add(this);
+
   thd->rand.seed1= (ulong) seed1;
   thd->rand.seed2= (ulong) seed2;
   return 0;
@@ -5401,6 +5408,29 @@ Rand_log_event::do_shall_skip(Relay_log_info *rli)
   return continue_group(rli);
 }
 
+/**
+   Exec deferred Int-, Rand- and User- var events prefixing
+   a Query-log-event event.
+
+   @param thd THD handle
+
+   @return false on success, true if a failure in an event applying occurred.
+*/
+bool slave_execute_deferred_events(THD *thd)
+{
+  bool res= false;
+  Relay_log_info *rli= thd->rli_slave;
+
+  DBUG_ASSERT(rli && (!rli->deferred_events_collecting || rli->deferred_events));
+
+  if (!rli->deferred_events_collecting || rli->deferred_events->is_empty())
+    return res;
+
+  res= rli->deferred_events->execute(rli);
+
+  return res;
+}
+
 #endif /* !MYSQL_CLIENT */
 
 
@@ -5785,6 +5815,10 @@ int User_var_log_event::do_apply_event(Relay_log_info const *rli)
 {
   Item *it= 0;
   CHARSET_INFO *charset;
+
+  if (rli->deferred_events_collecting)
+    return rli->deferred_events->add(this);
+
   if (!(charset= get_charset(charset_number, MYF(MY_WME))))
     return 1;
   LEX_STRING user_var_name;
diff --git a/sql/log_event.h b/sql/log_event.h
index 7c707c29278..4c80148458c 100644
--- a/sql/log_event.h
+++ b/sql/log_event.h
@@ -3961,6 +3961,16 @@ static inline bool copy_event_cache_to_file_and_reinit(IO_CACHE *cache,
     reinit_io_cache(cache, WRITE_CACHE, 0, FALSE, TRUE);
 }
 
+#ifndef MYSQL_CLIENT
+/**
+   The function is called by slave applier in case there are
+   active table filtering rules to force gathering events associated
+   with Query-log-event into an array to execute
+   them once the fate of the Query is determined for execution.
+*/
+bool slave_execute_deferred_events(THD *thd);
+#endif
+
 /**
   @} (end of group Replication)
 */
diff --git a/sql/rpl_rli.cc b/sql/rpl_rli.cc
index 6fe4cbd4ea6..904b5533f3b 100644
--- a/sql/rpl_rli.cc
+++ b/sql/rpl_rli.cc
@@ -45,7 +45,9 @@ Relay_log_info::Relay_log_info()
    inited(0), abort_slave(0), slave_running(0), until_condition(UNTIL_NONE),
    until_log_pos(0), retried_trans(0),
    tables_to_lock(0), tables_to_lock_count(0),
-   last_event_start_time(0), m_flags(0)
+   last_event_start_time(0),
+   deferred_events(NULL),
+   m_flags(0)
 {
   DBUG_ENTER("Relay_log_info::Relay_log_info");
 
diff --git a/sql/rpl_rli.h b/sql/rpl_rli.h
index f49be72db46..959105b16e0 100644
--- a/sql/rpl_rli.h
+++ b/sql/rpl_rli.h
@@ -369,6 +369,41 @@ public:
    */
   time_t last_event_start_time;
 
+  /*
+    A container to hold on Intvar-, Rand-, Uservar- log-events in case
+    the slave is configured with table filtering rules.
+    The withhold events are executed when their parent Query destiny is
+    determined for execution as well.
+  */
+  Deferred_log_events *deferred_events;
+
+  /*
+    State of the container: true stands for IRU events gathering, 
+    false does for execution, either deferred or direct.
+  */
+  bool deferred_events_collecting;
+
+  /* 
+     Returns true if the argument event resides in the containter;
+     more specifically, the checking is done against the last added event.
+  */
+  bool is_deferred_event(Log_event * ev)
+  {
+    return deferred_events_collecting ? deferred_events->is_last(ev) : false;
+  };
+  /* The general cleanup that slave applier may need at the end of query. */
+  inline void cleanup_after_query()
+  {
+    if (deferred_events)
+      deferred_events->rewind();
+  };
+  /* The general cleanup that slave applier may need at the end of session. */
+  void cleanup_after_session()
+  {
+    if (deferred_events)
+      delete deferred_events;
+  };
+   
   /**
     Helper function to do after statement completion.
 
diff --git a/sql/rpl_utility.cc b/sql/rpl_utility.cc
index 46c93f7cd20..5f2b5cbf86b 100644
--- a/sql/rpl_utility.cc
+++ b/sql/rpl_utility.cc
@@ -226,3 +226,64 @@ table_def::compatible_with(Relay_log_info const *rli_arg, TABLE *table)
 
   return error;
 }
+
+#ifndef MYSQL_CLIENT
+Deferred_log_events::Deferred_log_events(Relay_log_info *rli) : last_added(NULL)
+{
+  my_init_dynamic_array(&array, sizeof(Log_event *), 32, 16);
+}
+
+Deferred_log_events::~Deferred_log_events() 
+{
+  delete_dynamic(&array);
+}
+
+int Deferred_log_events::add(Log_event *ev)
+{
+  last_added= ev;
+  insert_dynamic(&array, (uchar*) &ev);
+  return 0;
+}
+
+bool Deferred_log_events::is_empty()
+{  
+  return array.elements == 0;
+}
+
+bool Deferred_log_events::execute(Relay_log_info *rli)
+{
+  bool res= false;
+
+  DBUG_ASSERT(rli->deferred_events_collecting);
+
+  rli->deferred_events_collecting= false;
+  for (uint i=  0; !res && i < array.elements; i++)
+  {
+    Log_event *ev= (* (Log_event **)
+                    dynamic_array_ptr(&array, i));
+    res= ev->apply_event(rli);
+  }
+  rli->deferred_events_collecting= true;
+  return res;
+}
+
+void Deferred_log_events::rewind()
+{
+  /*
+    Reset preceeding Query log event events which execution was
+    deferred because of slave side filtering.
+  */
+  if (!is_empty())
+  {
+    for (uint i=  0; i < array.elements; i++)
+    {
+      Log_event *ev= *(Log_event **) dynamic_array_ptr(&array, i);
+      delete ev;
+    }
+    if (array.elements > array.max_element)
+      freeze_size(&array);
+    reset_dynamic(&array);
+  }
+}
+
+#endif
diff --git a/sql/rpl_utility.h b/sql/rpl_utility.h
index 4036a41bc60..81a10cca814 100644
--- a/sql/rpl_utility.h
+++ b/sql/rpl_utility.h
@@ -290,6 +290,24 @@ namespace {
   };
 
 }
+
+class Deferred_log_events
+{
+private:
+  DYNAMIC_ARRAY array;
+  Log_event *last_added;
+
+public:
+  Deferred_log_events(Relay_log_info *rli);
+  ~Deferred_log_events();
+  /* queue for exection at Query-log-event time prior the Query */;
+  int add(Log_event *ev);
+  bool is_empty();
+  bool execute(Relay_log_info *rli);
+  void rewind();
+  bool is_last(Log_event *ev) { return ev == last_added; };
+};
+
 #endif
 
 // NB. number of printed bit values is limited to sizeof(buf) - 1
diff --git a/sql/slave.cc b/sql/slave.cc
index be109a385da..0910d196583 100644
--- a/sql/slave.cc
+++ b/sql/slave.cc
@@ -2360,7 +2360,8 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli)
       used to read info about the relay log's format; it will be deleted when
       the SQL thread does not need it, i.e. when this thread terminates.
     */
-    if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT)
+    if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT &&
+        !rli->is_deferred_event(ev))
     {
       DBUG_PRINT("info", ("Deleting the event after it has been executed"));
       delete ev;
@@ -2990,6 +2991,12 @@ pthread_handler_t handle_slave_sql(void *arg)
     goto err;
   }
   thd->init_for_queries();
+  thd->rli_slave= rli;
+  if ((rli->deferred_events_collecting= rpl_filter->is_on()))
+  {
+    rli->deferred_events= new Deferred_log_events(rli);
+  }
+
   thd->temporary_tables = rli->save_temporary_tables; // restore temp tables
   set_thd_in_use_temporary_tables(rli);   // (re)set sql_thd in use for saved temp tables
   pthread_mutex_lock(&LOCK_thread_count);
diff --git a/sql/sql_base.cc b/sql/sql_base.cc
index ace78947054..ca24830db63 100644
--- a/sql/sql_base.cc
+++ b/sql/sql_base.cc
@@ -116,6 +116,8 @@ static void close_old_data_files(THD *thd, TABLE *table, bool morph_locks,
                                  bool send_refresh);
 static bool
 has_write_table_with_auto_increment(TABLE_LIST *tables);
+static bool
+has_write_table_auto_increment_not_first_in_pk(TABLE_LIST *tables);
 
 
 extern "C" uchar *table_cache_key(const uchar *record, size_t *length,
@@ -5471,6 +5473,12 @@ int lock_tables(THD *thd, TABLE_LIST *tables, uint count, bool *need_reopen)
 	*(ptr++)= table->table;
     }
 
+    if (thd->variables.binlog_format != BINLOG_FORMAT_ROW && tables)
+    {
+      if (has_write_table_auto_increment_not_first_in_pk(tables))
+        thd->lex->set_stmt_unsafe();
+    }
+
     /* We have to emulate LOCK TABLES if we are statement needs prelocking. */
     if (thd->lex->requires_prelocking())
     {
@@ -9065,6 +9073,32 @@ has_write_table_with_auto_increment(TABLE_LIST *tables)
   return 0;
 }
 
+/*
+  Tells if there is a table whose auto_increment column is a part
+  of a compound primary key while is not the first column in
+  the table definition.
+
+  @param tables Table list
+
+  @return true if the table exists, fais if does not.
+*/
+
+static bool
+has_write_table_auto_increment_not_first_in_pk(TABLE_LIST *tables)
+{
+  for (TABLE_LIST *table= tables; table; table= table->next_global)
+  {
+    /* we must do preliminary checks as table->table may be NULL */
+    if (!table->placeholder() &&
+        table->table->found_next_number_field &&
+        (table->lock_type >= TL_WRITE_ALLOW_WRITE)
+        && table->table->s->next_number_keypart != 0)
+      return 1;
+  }
+
+  return 0;
+}
+
 
 /*
   Open and lock system tables for read.
diff --git a/sql/sql_class.cc b/sql/sql_class.cc
index 32e2e90acd7..2f3e8153cbd 100644
--- a/sql/sql_class.cc
+++ b/sql/sql_class.cc
@@ -601,7 +601,7 @@ Diagnostics_area::disable_status()
 THD::THD()
    :Statement(&main_lex, &main_mem_root, CONVENTIONAL_EXECUTION,
               /* statement id */ 0),
-   Open_tables_state(refresh_version), rli_fake(0),
+   Open_tables_state(refresh_version), rli_fake(NULL), rli_slave(NULL),
    lock_id(&main_lock_id),
    user_time(0), in_sub_stmt(0),
    sql_log_bin_toplevel(false),
@@ -1035,6 +1035,8 @@ THD::~THD()
     delete rli_fake;
     rli_fake= NULL;
   }
+  if (rli_slave)
+    rli_slave->cleanup_after_session();
 #endif
 
   free_root(&main_mem_root, MYF(0));
@@ -1267,6 +1269,10 @@ void THD::cleanup_after_query()
   /* reset table map for multi-table update */
   table_map_for_update= 0;
   m_binlog_invoker= FALSE;
+#ifndef EMBEDDED_LIBRARY
+  if (rli_slave)
+    rli_slave->cleanup_after_query();
+#endif
 }
 
 
diff --git a/sql/sql_class.h b/sql/sql_class.h
index 3c1b2c1330f..31d2c664aae 100644
--- a/sql/sql_class.h
+++ b/sql/sql_class.h
@@ -1291,6 +1291,8 @@ class THD :public Statement,
 public:
   /* Used to execute base64 coded binlog events in MySQL server */
   Relay_log_info* rli_fake;
+  /* Slave applier execution context */
+  Relay_log_info* rli_slave;
 
   /*
     Constant for THD::where initialization in the beginning of every query.
diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc
index 14b778328d2..729a963eef1 100644
--- a/sql/sql_parse.cc
+++ b/sql/sql_parse.cc
@@ -2248,6 +2248,11 @@ mysql_execute_command(THD *thd)
       }
       DBUG_RETURN(0);
     }
+    /* 
+       Execute deferred events first
+    */
+    if (slave_execute_deferred_events(thd))
+      DBUG_RETURN(-1);
   }
   else
   {