BUG#39934: Slave stops for engine that only support row-based logging

This is a post-push fix addressing review requests and
problems with extra warnings.

Problem 1: The sub-statement where an unsafe warning was detected was
printed as part of the warning. This was ok for statements that
were unsafe due to, e.g., calls to UUID(), but did not make
sense for statements that were unsafe because there was more than
one autoincrement column (unsafeness in this case comes from the
combination of several sub-statements).
Fix 1: Instead of printing the sub-statement, print an explanation
of why the statement is unsafe.

Problem 2:
When a recursive construct (i.e., stored proceure, stored
function, trigger, view, prepared statement) contained several
sub-statements, and at least one of them was unsafe, there would be
one unsafeness warning per sub-statement - even for safe
sub-statements.
Fix 2:
Ensure that each type of warning is printed at most once, by
remembering throughout the execution of the statement which types
of warnings have been printed.


mysql-test/extra/rpl_tests/create_recursive_construct.inc:
  - Clarified comment per review request.
  - Added checks for the number of warnings in each invocation.
mysql-test/extra/rpl_tests/rpl_insert_delayed.test:
  Per review request, replaced @@session.binlog_format by
  @@global.binlog_format, since INSERT DELAYED reads the global
  variable. (In this test case, the two variables have the same
  value, so the change is cosmetic.)
mysql-test/r/sp_trans.result:
  updated result file
mysql-test/suite/binlog/r/binlog_statement_insert_delayed.result:
  updated result file
mysql-test/suite/binlog/r/binlog_stm_ps.result:
  updated result file
mysql-test/suite/binlog/r/binlog_stm_unsafe_warning.result:
  updated result file
mysql-test/suite/binlog/r/binlog_unsafe.result:
  Updated result file. Note that duplicate warnings are now gone.
mysql-test/suite/binlog/t/binlog_unsafe.test:
  - Added tests for: (1) a statement that is unsafe in many ways;
    (2) a statement that is unsafe in the same way several times.
  - Use -- style to invoke mysqltest commands.
mysql-test/suite/rpl/r/rpl_stm_found_rows.result:
  updated result file
mysql-test/suite/rpl/r/rpl_stm_loadfile.result:
  updated result file
mysql-test/suite/rpl/t/rpl_mix_found_rows.test:
  Per review request, added comment explaining what the test case
  does (copied from rpl_stm_found_rows.test)
mysql-test/suite/rpl/t/rpl_stm_found_rows.test:
  Clarified grammar in comment.
mysql-test/suite/rpl_ndb/r/rpl_ndb_binlog_format_errors.result:
  Updated result file.
sql/item_create.cc:
  Made set_stmt_unsafe take one parameter, describing the
  type of unsafeness.
sql/sp_head.cc:
  Added unsafe_flags field and made it hold all the unsafe flags.
sql/sp_head.h:
  - Removed the BINLOG_ROW_BASED_IF_MIXED flag from m_flags.
    Instead, we use the new unsafe_flags field to hold the
    unsafeness state of the sp.
  - Made propagate_attributes() copy all unsafe flags.
sql/sql_base.cc:
  - Made LEX::set_stmt_unsafe() take an extra argument.
  - Made binlog_unsafe_warning_flags store the type of unsafeness.
  - Per review requests, clarified comments
  - Added DBUG printouts
sql/sql_class.cc:
  - Made warnings be generated in issue_warnings() and call that from
    binlog_query(). Wrote issue_warnings(), which prints zero or more
    warnings, avoiding to print warnings more than once per statement.
  - Per review request, added @todo so that we remember to assert
    correct behavior in binlog_query.
sql/sql_class.h:
  - Removed BINLOG_WARNING_PRINTED 
  - Use [set|clear]_current_stmt_binlog_row_based() instead of
    modifying the flag directly.
  - added issue_unsafe_warnings() (only called from binlog_unsafe)
  - Per review request, improved some documentation.
sql/sql_insert.cc:
  Added extra argument to LEX::set_stmt_unsafe()
sql/sql_lex.h:
  - Added enum_binlog_stmt_unsafe, listing all types of unsafe
    statements.
  - Per review requests, improved many comments for member
    functions.
  - Added [get|set]_stmt_unsafe_flags(), which return/set all the
    unsafe flags for a statement.
sql/sql_parse.cc:
  - Renamed binlog_warning_flags to binlog_unsafe_warning_flags.
  - Per review requests, improved comment.
sql/sql_view.cc:
  Made views propagate all the new unsafe flags.
sql/sql_yacc.yy:
  Added parameter to set_stmt_unsafe().
storage/innobase/handler/ha_innodb.cc:
  Per review requests, replaced DBUG_EXECUTE_IF() by DBUG_EVALUATE_IF().

1 files changed, 94 insertions, 29 deletions

diff --git a/sql/sql_class.cc b/sql/sql_class.cc
index f401daaee9b..4f8f0a30544 100644
--- a/sql/sql_class.cc
+++ b/sql/sql_class.cc
@@ -39,6 +39,7 @@
 #include <io.h>
 #endif
 #include <mysys_err.h>
+#include <limits.h>
 
 #include "sp_rcontext.h"
 #include "sp_cache.h"
@@ -540,7 +541,7 @@ THD::THD()
    lock_id(&main_lock_id),
    user_time(0), in_sub_stmt(0),
    sql_log_bin_toplevel(false),
-   binlog_warning_flags(0UL), binlog_table_maps(0),
+   binlog_unsafe_warning_flags(0), binlog_table_maps(0),
    table_map_for_update(0),
    arg_of_last_insert_id_function(FALSE),
    first_successful_insert_id_in_prev_stmt(0),
@@ -3634,6 +3635,93 @@ show_query_type(THD::enum_binlog_query_type qtype)
 
 
 /**
+  Auxiliary method used by @c binlog_query() to raise warnings.
+
+  @param err An ER_BINLOG_UNSAFE_* constant; the warning to print.
+*/
+void THD::issue_unsafe_warnings()
+{
+  DBUG_ENTER("issue_unsafe_warnings");
+  /*
+    Ensure that binlog_unsafe_warning_flags is big enough to hold all
+    bits.  This is actually a constant expression.
+  */
+  DBUG_ASSERT(BINLOG_STMT_WARNING_COUNT + 2 * LEX::BINLOG_STMT_UNSAFE_COUNT <=
+              sizeof(binlog_unsafe_warning_flags) * CHAR_BIT);
+
+  /**
+    @note The order of the elements of this array must correspond to
+    the order of elements in enum_binlog_stmt_unsafe.
+  */
+  static const char *explanations[LEX::BINLOG_STMT_UNSAFE_COUNT] =
+  {
+    "Statement uses a LIMIT clause. This is unsafe because the set of rows included cannot be predicted.",
+    "Statement uses INSERT DELAYED. This is unsafe because the time when rows are inserted cannot be predicted.",
+    "Statement uses the general_log or slow_log table. This is unsafe because system tables may differ on slave.",
+    "Statement updates two AUTO_INCREMENT columns. This is unsafe because the generated value cannot be predicted by slave.",
+    "Statement uses a UDF. It cannot be determined if the UDF will return the same value on slave.",
+    "Statement uses a system variable whose value may differ on slave.",
+    "Statement uses a system function whose value may differ on slave."
+  };
+  uint32 flags= binlog_unsafe_warning_flags;
+  /* No warnings (yet) for this statement. */
+  if (flags == 0)
+    DBUG_VOID_RETURN;
+
+  /* Get the types of unsafeness that affect the current statement. */
+  uint32 unsafe_type_flags= flags >> BINLOG_STMT_WARNING_COUNT;
+  DBUG_ASSERT((unsafe_type_flags & LEX::BINLOG_STMT_UNSAFE_ALL_FLAGS) != 0);
+  /*
+    Clear (1) bits above BINLOG_STMT_UNSAFE_COUNT; (2) bits for
+    warnings that have been printed already.
+  */
+  unsafe_type_flags &= (LEX::BINLOG_STMT_UNSAFE_ALL_FLAGS ^
+                        (unsafe_type_flags >> LEX::BINLOG_STMT_UNSAFE_COUNT));
+  /* If all warnings have been printed already, return. */
+  if (unsafe_type_flags == 0)
+    DBUG_VOID_RETURN;
+
+  /* Figure out which error code to issue. */
+  int err;
+  if (binlog_unsafe_warning_flags &
+      (1 << BINLOG_STMT_WARNING_UNSAFE_AND_STMT_ENGINE))
+    err= ER_BINLOG_UNSAFE_AND_STMT_ENGINE;
+  else {
+    DBUG_ASSERT(binlog_unsafe_warning_flags &
+                (1 << BINLOG_STMT_WARNING_UNSAFE_AND_STMT_MODE));
+    err= ER_BINLOG_UNSAFE_STATEMENT;
+  }
+
+  DBUG_PRINT("info", ("flags: 0x%x  err: %d", unsafe_type_flags, err));
+
+  /*
+    For each unsafe_type, check if the statement is unsafe in this way
+    and issue a warning.
+  */
+  for (int unsafe_type=0;
+       unsafe_type < LEX::BINLOG_STMT_UNSAFE_COUNT;
+       unsafe_type++)
+  {
+    if ((unsafe_type_flags & (1 << unsafe_type)) != 0)
+    {
+      push_warning_printf(this, MYSQL_ERROR::WARN_LEVEL_NOTE, err,
+                          "%s Reason: %s",
+                          ER(err), explanations[unsafe_type]);
+      sql_print_warning("%s Reason: %s Statement: %s",
+                        ER(err), explanations[unsafe_type], query);
+    }
+  }
+  /*
+    Mark these unsafe types as already printed, to avoid printing
+    warnings for them again.
+  */
+  binlog_unsafe_warning_flags|= unsafe_type_flags <<
+    (BINLOG_STMT_WARNING_COUNT + LEX::BINLOG_STMT_UNSAFE_COUNT);
+  DBUG_VOID_RETURN;
+}
+
+
+/**
   Log the current query.
 
   The query will be logged in either row format or statement format
@@ -3688,34 +3776,7 @@ int THD::binlog_query(THD::enum_binlog_query_type qtype, char const *query_arg,
     know for sure if the statement will be logged.
   */
   if (sql_log_bin_toplevel)
-  {
-    if (binlog_warning_flags &
-        (1 << BINLOG_WARNING_FLAG_UNSAFE_AND_STMT_ENGINE))
-    {
-      push_warning_printf(this, MYSQL_ERROR::WARN_LEVEL_NOTE,
-                          ER_BINLOG_UNSAFE_AND_STMT_ENGINE,
-                          "%s Statement: %.*s",
-                          ER(ER_BINLOG_UNSAFE_AND_STMT_ENGINE),
-                          MYSQL_ERRMSG_SIZE, query_arg);
-      sql_print_warning("%s Statement: %.*s",
-                        ER(ER_BINLOG_UNSAFE_AND_STMT_ENGINE),
-                        MYSQL_ERRMSG_SIZE, query_arg);
-      binlog_warning_flags|= 1 << BINLOG_WARNING_FLAG_PRINTED;
-    }
-    else if (binlog_warning_flags &
-             (1 << BINLOG_WARNING_FLAG_UNSAFE_AND_STMT_MODE))
-    {
-      push_warning_printf(this, MYSQL_ERROR::WARN_LEVEL_NOTE,
-                          ER_BINLOG_UNSAFE_STATEMENT,
-                          "%s Statement: %.*s",
-                          ER(ER_BINLOG_UNSAFE_STATEMENT),
-                          MYSQL_ERRMSG_SIZE, query_arg);
-      sql_print_warning("%s Statement: %.*s",
-                        ER(ER_BINLOG_UNSAFE_STATEMENT),
-                        MYSQL_ERRMSG_SIZE, query_arg);
-      binlog_warning_flags|= 1 << BINLOG_WARNING_FLAG_PRINTED;
-    }
-  }
+    issue_unsafe_warnings();
 
   switch (qtype) {
     /*
@@ -3738,6 +3799,10 @@ int THD::binlog_query(THD::enum_binlog_query_type qtype, char const *query_arg,
       format; it cannot be logged in row format.  This is typically
       used by DDL statements.  It is an error to use this query type
       if current_stmt_binlog_row_based is set.
+
+      @todo Currently there are places that call this method with
+      STMT_QUERY_TYPE and current_stmt_binlog_row_based.  Fix those
+      places and add assert to ensure correct behavior. /Sven
     */
   case THD::STMT_QUERY_TYPE:
     /*