Commit 8e4566e9 authored by Michael Widenius's avatar Michael Widenius

Don't give warning if there are two unique keys used with INSERT .. ON DUPLICATE KEY UPDATE.

We should assume that the store engine will report the first duplicate key for this case.

Old code of suppression of unsafe logging error with LIMIT didn't work, because of wrong usage of my_interval_timer().

Suppress unsafe logging errors to the error log if we get too many unsafe logging errors in a short time.
This is to not overflow the error log with meaningless errors.

- Each error code is suppressed and counted separately.
- We do a 5 minute suppression of new errors if we get more than 10 errors in that time.

Only print unsafe logging errors if log_warnings > 1.



mysql-test/suite/binlog/r/binlog_stm_unsafe_warning.result:
  Update test results as INSERT ... ON DUPLICATE KEY UPDATE doesn't get logged anymore
mysql-test/suite/binlog/r/binlog_unsafe.result:
  Update test results as INSERT ... ON DUPLICATE KEY UPDATE doesn't get logged anymore
mysql-test/suite/engines/README:
  Fixed typos
mysql-test/suite/rpl/r/rpl_known_bugs_detection.result:
  Update test results as INSERT ... ON DUPLICATE KEY UPDATE doesn't get logged anymore
sql/sql_base.cc:
  Don't log warning if there are two unique keys used with INSERT .. ON DUPLICATE KEY UPDATE.
  We should assume that the store engine will report the first duplicate key for this case.
sql/sql_class.cc:
  Suppress error in binary log if we get too many unsafe logging errors in a short time.
  Only print unsafe logging errors if log_warnings > 1
parent e167c48a
...@@ -67,7 +67,7 @@ DROP TABLE t1; ...@@ -67,7 +67,7 @@ DROP TABLE t1;
SET GLOBAL log_warnings = @old_log_warnings; SET GLOBAL log_warnings = @old_log_warnings;
# Count the number of times the "Unsafe" message was printed # Count the number of times the "Unsafe" message was printed
# to the error log. # to the error log.
Occurrences: 1 Occurrences: 0
create table t1 (n1 int, n2 int, n3 int, create table t1 (n1 int, n2 int, n3 int,
key (n1, n2, n3), key (n1, n2, n3),
key (n2, n3, n1), key (n2, n3, n1),
......
...@@ -2706,8 +2706,6 @@ Warnings: ...@@ -2706,8 +2706,6 @@ Warnings:
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. CREATE... REPLACE SELECT is unsafe because the order in which rows are retrieved by the SELECT determines which (if any) rows are replaced. This order cannot be predicted and may differ on master and the slave. Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. CREATE... REPLACE SELECT is unsafe because the order in which rows are retrieved by the SELECT determines which (if any) rows are replaced. This order cannot be predicted and may differ on master and the slave.
INSERT INTO insert_2_keys VALUES (1, 2) INSERT INTO insert_2_keys VALUES (1, 2)
ON DUPLICATE KEY UPDATE a=VALUES(a)+10, b=VALUES(b)+10; ON DUPLICATE KEY UPDATE a=VALUES(a)+10, b=VALUES(b)+10;
Warnings:
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. INSERT... ON DUPLICATE KEY UPDATE on a table with more than one UNIQUE KEY is unsafe
DROP TABLE filler_table; DROP TABLE filler_table;
DROP TABLE insert_table; DROP TABLE insert_table;
DROP TABLE update_table; DROP TABLE update_table;
......
This directory includes a set of three test suites aimed as testing
functionality in an engine independent way, that is - the tests should
work identically against different engines.
This directory includes a set of three test suites aimed as testing functionality
in an engine independent way, that is - the tests should work identically against
different engines.
The following suites are included: The following suites are included:
1) 'funcs' suite 1) 'funcs' suite
------------- -------------
A collection of functional tests covering basic engine and server functionality that can be run A collection of functional tests covering basic engine and server
against iany engine. functionality that can be run against any engine.
To run the test suite: To run the test suite:
cd INSTALL_DIR/mysql-test cd INSTALL_DIR/mysql-test
...@@ -19,7 +15,7 @@ The following suites are included: ...@@ -19,7 +15,7 @@ The following suites are included:
2) 'iuds' suite 2) 'iuds' suite
------------ ------------
Similar to the above focused on insert/update/delete operations of different different data types. Similar to the above focused on insert/update/delete operations of different data types.
To run the test suite: To run the test suite:
cd INSTALL_DIR/mysql-test cd INSTALL_DIR/mysql-test
...@@ -44,13 +40,13 @@ The following suites are included: ...@@ -44,13 +40,13 @@ The following suites are included:
3) Copy the 'init_innodb.txt' file to 'init_<engine>.txt file and change its content to be "init_<engine>". 3) Copy the 'init_innodb.txt' file to 'init_<engine>.txt file and change its content to be "init_<engine>".
4) In the 't' directory copy the "init_innodb.test" file to "init_<engine>.test" and change the value of 4) In the 't' directory copy the "init_innodb.test" file to "init_<engine>.test" and change the value of
the '$engine' variable to <engine>. the '$engine' variable to <engine>.
5) In the 'r' directory copy "the init_innodb.result" file to "init_<engine>.result" and change refrences 5) In the 'r' directory copy "the init_innodb.result" file to "init_<engine>.result" and change references
to 'InnoDB' to <engine>. to 'InnoDB' to <engine>.
Known Issues Known Issues
------------ ------------
1) The folowing tests in the 'iuds' suite: 1) The following tests in the 'iuds' suite:
- delete_decimal - delete_decimal
- insert_decimal - insert_decimal
- update_decimal - update_decimal
...@@ -63,9 +59,9 @@ Known Issues ...@@ -63,9 +59,9 @@ Known Issues
- ix_unique_string_length (bug 52056, masked by an 'Out of memory error' on some 32-bit platforms) - ix_unique_string_length (bug 52056, masked by an 'Out of memory error' on some 32-bit platforms)
Add the '--force' option to prevent the test run from aborting. Add the '--force' option to prevent the test run from aborting.
3) Some of the rpl_xxx tests in the 'funcs' suite require a secific binlog_forat setting and will be 3) Some of the rpl_xxx tests in the 'funcs' suite require a specific
skipped otherwise. binlog_format setting and will be skipped otherwise.
4) Some of the rpl_xxx tests in the 'funcs' suite will report a 'Statement unsafe for replication' warning
when run againsr a server configured to use statement based replication.
4) Some of the rpl_xxx tests in the 'funcs' suite will report a
'Statement unsafe for replication' warning when run against a
server configured to use statement based replication.
...@@ -5,8 +5,6 @@ call mtr.add_suppression("Unsafe statement written to the binary log using state ...@@ -5,8 +5,6 @@ call mtr.add_suppression("Unsafe statement written to the binary log using state
CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY AUTO_INCREMENT, b INT, CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY AUTO_INCREMENT, b INT,
UNIQUE(b)); UNIQUE(b));
INSERT INTO t1(b) VALUES(1),(1),(2) ON DUPLICATE KEY UPDATE t1.b=10; INSERT INTO t1(b) VALUES(1),(1),(2) ON DUPLICATE KEY UPDATE t1.b=10;
Warnings:
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. INSERT... ON DUPLICATE KEY UPDATE on a table with more than one UNIQUE KEY is unsafe
SELECT * FROM t1; SELECT * FROM t1;
a b a b
1 10 1 10
......
...@@ -5304,6 +5304,7 @@ bool lock_tables(THD *thd, TABLE_LIST *tables, uint count, ...@@ -5304,6 +5304,7 @@ bool lock_tables(THD *thd, TABLE_LIST *tables, uint count,
thd->lex->set_stmt_unsafe(LEX::BINLOG_STMT_UNSAFE_AUTOINC_NOT_FIRST); thd->lex->set_stmt_unsafe(LEX::BINLOG_STMT_UNSAFE_AUTOINC_NOT_FIRST);
} }
#ifdef NOT_USED_IN_MARIADB
/* /*
INSERT...ON DUPLICATE KEY UPDATE on a table with more than one unique keys INSERT...ON DUPLICATE KEY UPDATE on a table with more than one unique keys
can be unsafe. can be unsafe.
...@@ -5329,6 +5330,7 @@ bool lock_tables(THD *thd, TABLE_LIST *tables, uint count, ...@@ -5329,6 +5330,7 @@ bool lock_tables(THD *thd, TABLE_LIST *tables, uint count,
thd->lex->duplicates == DUP_UPDATE) thd->lex->duplicates == DUP_UPDATE)
thd->lex->set_stmt_unsafe(LEX::BINLOG_STMT_UNSAFE_INSERT_TWO_KEYS); thd->lex->set_stmt_unsafe(LEX::BINLOG_STMT_UNSAFE_INSERT_TWO_KEYS);
} }
#endif
/* We have to emulate LOCK TABLES if we are statement needs prelocking. */ /* We have to emulate LOCK TABLES if we are statement needs prelocking. */
if (thd->lex->requires_prelocking()) if (thd->lex->requires_prelocking())
......
...@@ -5974,23 +5974,35 @@ show_query_type(THD::enum_binlog_query_type qtype) ...@@ -5974,23 +5974,35 @@ show_query_type(THD::enum_binlog_query_type qtype)
Constants required for the limit unsafe warnings suppression Constants required for the limit unsafe warnings suppression
*/ */
//seconds after which the limit unsafe warnings suppression will be activated //seconds after which the limit unsafe warnings suppression will be activated
#define LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT 50 #define LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT 5*60
//number of limit unsafe warnings after which the suppression will be activated //number of limit unsafe warnings after which the suppression will be activated
#define LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT 50 #define LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT 10
static ulonglong limit_unsafe_suppression_start_time= 0; static ulonglong unsafe_suppression_start_time= 0;
static bool unsafe_warning_suppression_is_activated= false; static bool unsafe_warning_suppression_active[LEX::BINLOG_STMT_UNSAFE_COUNT];
static int limit_unsafe_warning_count= 0; static ulong unsafe_warnings_count[LEX::BINLOG_STMT_UNSAFE_COUNT];
static ulong total_unsafe_warnings_count;
/** /**
Auxiliary function to reset the limit unsafety warning suppression. Auxiliary function to reset the limit unsafety warning suppression.
This is done without mutex protection, but this should be good
enough as it doesn't matter if we loose a couple of suppressed
messages or if this is called multiple times.
*/ */
static void reset_binlog_unsafe_suppression()
static void reset_binlog_unsafe_suppression(ulonglong now)
{ {
uint i;
DBUG_ENTER("reset_binlog_unsafe_suppression"); DBUG_ENTER("reset_binlog_unsafe_suppression");
unsafe_warning_suppression_is_activated= false;
limit_unsafe_warning_count= 0; unsafe_suppression_start_time= now;
limit_unsafe_suppression_start_time= my_interval_timer()/10000000; total_unsafe_warnings_count= 0;
for (i= 0 ; i < LEX::BINLOG_STMT_UNSAFE_COUNT ; i++)
{
unsafe_warnings_count[i]= 0;
unsafe_warning_suppression_active[i]= 0;
}
DBUG_VOID_RETURN; DBUG_VOID_RETURN;
} }
...@@ -6008,44 +6020,57 @@ static void print_unsafe_warning_to_log(int unsafe_type, char* buf, ...@@ -6008,44 +6020,57 @@ static void print_unsafe_warning_to_log(int unsafe_type, char* buf,
} }
/** /**
Auxiliary function to check if the warning for limit unsafety should be Auxiliary function to check if the warning for unsafe repliction statements
thrown or suppressed. Details of the implementation can be found in the should be thrown or suppressed.
comments inline.
Logic is:
- If we get more than LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT errors
of one type, that type of errors will be suppressed for
LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT.
- When the time limit has been reached, all suppression is reset.
This means that if one gets many different types of errors, some of them
may be reset less than LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT. However at
least one error is disable for this time.
SYNOPSIS: SYNOPSIS:
@params @params
buf - buffer to hold the warning message text
unsafe_type - The type of unsafety. unsafe_type - The type of unsafety.
query - The actual query statement.
TODO: Remove this function and implement a general service for all warnings RETURN:
that would prevent flooding the error log. 0 0k to log
1 Message suppressed
*/ */
static void do_unsafe_limit_checkout(char* buf, int unsafe_type, char* query)
static bool protect_against_unsafe_warning_flood(int unsafe_type)
{ {
ulonglong now= 0; ulong count;
DBUG_ENTER("do_unsafe_limit_checkout"); ulonglong now= my_interval_timer()/1000000000ULL;
DBUG_ASSERT(unsafe_type == LEX::BINLOG_STMT_UNSAFE_LIMIT); DBUG_ENTER("protect_against_unsafe_warning_flood");
limit_unsafe_warning_count++;
count= ++unsafe_warnings_count[unsafe_type];
total_unsafe_warnings_count++;
/* /*
INITIALIZING: INITIALIZING:
If this is the first time this function is called with log warning If this is the first time this function is called with log warning
enabled, the monitoring the unsafe warnings should start. enabled, the monitoring the unsafe warnings should start.
*/ */
if (limit_unsafe_suppression_start_time == 0) if (unsafe_suppression_start_time == 0)
{ {
limit_unsafe_suppression_start_time= my_interval_timer()/10000000; reset_binlog_unsafe_suppression(now);
print_unsafe_warning_to_log(unsafe_type, buf, query); DBUG_RETURN(0);
} }
else
{
if (!unsafe_warning_suppression_is_activated)
print_unsafe_warning_to_log(unsafe_type, buf, query);
if (limit_unsafe_warning_count >= /*
LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT) The following is true if we got too many errors or if the error was
already suppressed
*/
if (count >= LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT)
{ {
now= my_interval_timer()/10000000; ulonglong diff_time= (now - unsafe_suppression_start_time);
if (!unsafe_warning_suppression_is_activated)
if (!unsafe_warning_suppression_active[unsafe_type])
{ {
/* /*
ACTIVATION: ACTIVATION:
...@@ -6053,50 +6078,36 @@ static void do_unsafe_limit_checkout(char* buf, int unsafe_type, char* query) ...@@ -6053,50 +6078,36 @@ static void do_unsafe_limit_checkout(char* buf, int unsafe_type, char* query)
less than LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT we activate the less than LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT we activate the
suppression. suppression.
*/ */
if ((now-limit_unsafe_suppression_start_time) <= if (diff_time <= LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT)
LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT)
{ {
unsafe_warning_suppression_is_activated= true; unsafe_warning_suppression_active[unsafe_type]= 1;
DBUG_PRINT("info",("A warning flood has been detected and the limit \ sql_print_information("Suppressing warnings of type '%s' for up to %d seconds because of flooding",
unsafety warning suppression has been activated.")); ER(LEX::binlog_stmt_unsafe_errcode[unsafe_type]),
LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT);
} }
else else
{ {
/* /*
there is no flooding till now, therefore we restart the monitoring There is no flooding till now, therefore we restart the monitoring
*/ */
limit_unsafe_suppression_start_time= my_interval_timer()/10000000; reset_binlog_unsafe_suppression(now);
limit_unsafe_warning_count= 0;
} }
} }
else else
{ {
/* /* This type of warnings was suppressed */
Print the suppression note and the unsafe warning. if (diff_time > LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT)
*/
sql_print_information("The following warning was suppressed %d times \
during the last %d seconds in the error log",
limit_unsafe_warning_count,
(int)
(now-limit_unsafe_suppression_start_time));
print_unsafe_warning_to_log(unsafe_type, buf, query);
/*
DEACTIVATION: We got LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT
warnings in more than LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT, the
suppression should be deactivated.
*/
if ((now - limit_unsafe_suppression_start_time) >
LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT)
{ {
reset_binlog_unsafe_suppression(); ulong save_count= total_unsafe_warnings_count;
DBUG_PRINT("info",("The limit unsafety warning supression has been \ /* Print a suppression note and remove the suppression */
deactivated")); reset_binlog_unsafe_suppression(now);
} sql_print_information("Suppressed %lu unsafe warnings during "
"the last %d seconds",
save_count, (int) diff_time);
} }
limit_unsafe_warning_count= 0;
} }
} }
DBUG_VOID_RETURN; DBUG_RETURN(unsafe_warning_suppression_active[unsafe_type]);
} }
/** /**
...@@ -6108,6 +6119,7 @@ deactivated")); ...@@ -6108,6 +6119,7 @@ deactivated"));
void THD::issue_unsafe_warnings() void THD::issue_unsafe_warnings()
{ {
char buf[MYSQL_ERRMSG_SIZE * 2]; char buf[MYSQL_ERRMSG_SIZE * 2];
uint32 unsafe_type_flags;
DBUG_ENTER("issue_unsafe_warnings"); DBUG_ENTER("issue_unsafe_warnings");
/* /*
Ensure that binlog_unsafe_warning_flags is big enough to hold all Ensure that binlog_unsafe_warning_flags is big enough to hold all
...@@ -6116,7 +6128,9 @@ void THD::issue_unsafe_warnings() ...@@ -6116,7 +6128,9 @@ void THD::issue_unsafe_warnings()
DBUG_ASSERT(LEX::BINLOG_STMT_UNSAFE_COUNT <= DBUG_ASSERT(LEX::BINLOG_STMT_UNSAFE_COUNT <=
sizeof(binlog_unsafe_warning_flags) * CHAR_BIT); sizeof(binlog_unsafe_warning_flags) * CHAR_BIT);
uint32 unsafe_type_flags= binlog_unsafe_warning_flags; if (!(unsafe_type_flags= binlog_unsafe_warning_flags))
DBUG_VOID_RETURN; // Nothing to do
/* /*
For each unsafe_type, check if the statement is unsafe in this way For each unsafe_type, check if the statement is unsafe in this way
and issue a warning. and issue a warning.
...@@ -6131,15 +6145,11 @@ void THD::issue_unsafe_warnings() ...@@ -6131,15 +6145,11 @@ void THD::issue_unsafe_warnings()
ER_BINLOG_UNSAFE_STATEMENT, ER_BINLOG_UNSAFE_STATEMENT,
ER(ER_BINLOG_UNSAFE_STATEMENT), ER(ER_BINLOG_UNSAFE_STATEMENT),
ER(LEX::binlog_stmt_unsafe_errcode[unsafe_type])); ER(LEX::binlog_stmt_unsafe_errcode[unsafe_type]));
if (global_system_variables.log_warnings) if (global_system_variables.log_warnings > 1 &&
{ !protect_against_unsafe_warning_flood(unsafe_type))
if (unsafe_type == LEX::BINLOG_STMT_UNSAFE_LIMIT)
do_unsafe_limit_checkout( buf, unsafe_type, query());
else //cases other than LIMIT unsafety
print_unsafe_warning_to_log(unsafe_type, buf, query()); print_unsafe_warning_to_log(unsafe_type, buf, query());
} }
} }
}
DBUG_VOID_RETURN; DBUG_VOID_RETURN;
} }
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment