1berry/MariaDB-server
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

BUG#11759333: SBR LOGGING WARNING MESSAGES FOR PRIMARY

Browse Source 
KEY UPDATES WITH A LIMIT OF 1

Problem: The unsafety warning for statements such as
update...limit1 where pk=1 are thrown when binlog-format
= STATEMENT,despite of the fact that such statements are
actually safe. this leads to filling up of the disk space 
with false warnings.
 
Solution: This is not a complete fix for the problem, but
prevents the disks from getting filled up. This should
therefore be regarded as a workaround. In the future this
should be overriden by server general suppress/filtering
framework. It should also be noted that another worklog is
supposed to defeat this case's artificial unsafety.

We use a warning suppression mechanism to detect warning flood,
enable the suppression, and disable this when the average
warnings/second has reduced to acceptable limits.
 
  Activation: The supression for LIMIT unsafe statements are
  activated when the last 50 warnings were logged in less 
  than 50 seconds. 
 
  Supression: Once activated this supression will prevent the
  individual warnings to be logged in the error log, but print
  the warning for every 50 warnings with the note:
  "The last warning was repeated N times in last S seconds"  
  Noteworthy is the fact that this supression works only on the
  error logs and the warnings seen by the clients will remain as
  it is (i.e. one warning/ unsafe statement)
 
  Deactivation: The supression will be deactivated once the
  average # of warnings/sec have gone down to the acceptable limits.
This commit is contained in:
Rohit Kalhans 2012-07-10 18:24:11 +05:30
parent ce9e2b6b96
commit abf4b3fa6a
1 changed files with 139 additions and 5 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

144
sql/sql_class.cc
View File

@ -4806,6 +4806,140 @@ show_query_type(THD::enum_binlog_query_type qtype)
}
#endif
/*
Constants required for the limit unsafe warnings suppression
*/
//seconds after which the limit unsafe warnings suppression will be activated
#define LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT 50
//number of limit unsafe warnings after which the suppression will be activated
#define LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT 50
static struct timeval limit_unsafe_suppression_start_time;
static struct timezone limit_unsafe_suppression_start_time_zone;
static bool unsafe_warning_suppression_is_activated= false;
static int limit_unsafe_warning_count= 0;
/**
Auxiliary function to reset the limit unsafety warning suppression.
*/
static void reset_binlog_unsafe_suppression()
{
DBUG_ENTER("reset_binlog_unsafe_suppression");
unsafe_warning_suppression_is_activated= false;
limit_unsafe_warning_count= 0;
gettimeofday(&limit_unsafe_suppression_start_time,
&limit_unsafe_suppression_start_time_zone);
DBUG_VOID_RETURN;
}
/**
Auxiliary function to print warning in the error log.
*/
static void print_unsafe_warning_to_log(int unsafe_type, char* buf,
char* query)
{
DBUG_ENTER("print_unsafe_warning_in_log");
sprintf(buf, ER(ER_BINLOG_UNSAFE_STATEMENT),
ER(LEX::binlog_stmt_unsafe_errcode[unsafe_type]));
sql_print_warning(ER(ER_MESSAGE_AND_STATEMENT), buf, query);
DBUG_VOID_RETURN;
}
/**
Auxiliary function to check if the warning for limit unsafety should be
thrown or suppressed. Details of the implementation can be found in the
comments inline.
SYNOPSIS:
@params
buf - buffer to hold the warning message text
unsafe_type - The type of unsafety.
query - The actual query statement.
TODO: Remove this function and implement a general service for all warnings
that would prevent flooding the error log.
*/
static void do_unsafe_limit_checkout(char* buf, int unsafe_type, char* query)
{
struct timeval now;
struct timezone tz_now;
DBUG_ENTER("do_unsafe_limit_checkout");
DBUG_ASSERT(unsafe_type == LEX::BINLOG_STMT_UNSAFE_LIMIT);
limit_unsafe_warning_count++;
/*
INITIALIZING:
If this is the first time this function is called with log warning
enabled, the monitoring the unsafe warnings should start.
*/
if (limit_unsafe_suppression_start_time.tv_sec == 0)
{
gettimeofday(&limit_unsafe_suppression_start_time,
&limit_unsafe_suppression_start_time_zone);
print_unsafe_warning_to_log(unsafe_type, buf, query);
}
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)
{
gettimeofday (&now, &tz_now);
if (!unsafe_warning_suppression_is_activated)
{
/*
ACTIVATION:
We got LIMIT_UNSAFE_WARNING_ACTIVATION_THRESHOLD_COUNT warnings in
less than LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT we activate the
suppression.
*/
if ((now.tv_sec-limit_unsafe_suppression_start_time.tv_sec) <=
LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT)
{
unsafe_warning_suppression_is_activated= true;
DBUG_PRINT("info",("A warning flood has been detected and the limit \
unsafety warning suppression has been activated."));
}
else
{
/*
there is no flooding till now, therefore we restart the monitoring
*/
gettimeofday(&limit_unsafe_suppression_start_time,
&limit_unsafe_suppression_start_time_zone);
limit_unsafe_warning_count= 0;
}
}
else
{
/*
Print the suppression note and the unsafe warning.
*/
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.tv_sec -
limit_unsafe_suppression_start_time.tv_sec));
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.tv_sec - limit_unsafe_suppression_start_time.tv_sec) >
LIMIT_UNSAFE_WARNING_ACTIVATION_TIMEOUT)
{
reset_binlog_unsafe_suppression();
DBUG_PRINT("info",("The limit unsafety warning supression has been \
deactivated"));
}
}
limit_unsafe_warning_count= 0;
}
}
DBUG_VOID_RETURN;
}
/**
Auxiliary method used by @c binlog_query() to raise warnings.
@ -4815,6 +4949,7 @@ show_query_type(THD::enum_binlog_query_type qtype)
*/
void THD::issue_unsafe_warnings()
{
char buf[MYSQL_ERRMSG_SIZE * 2];
DBUG_ENTER("issue_unsafe_warnings");
/*
Ensure that binlog_unsafe_warning_flags is big enough to hold all
@ -4840,17 +4975,16 @@ void THD::issue_unsafe_warnings()
ER(LEX::binlog_stmt_unsafe_errcode[unsafe_type]));
if (global_system_variables.log_warnings)
{
char buf[MYSQL_ERRMSG_SIZE * 2];
sprintf(buf, ER(ER_BINLOG_UNSAFE_STATEMENT),
ER(LEX::binlog_stmt_unsafe_errcode[unsafe_type]));
sql_print_warning(ER(ER_MESSAGE_AND_STATEMENT), buf, query());
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());
}
}
}
DBUG_VOID_RETURN;
}
/**
Log the current query.