Bug #72464 the unsafe statement spam throttling is not good enough
Submitted: 26 Apr 2014 10:12
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:5.6.17 OS:Any
Assigned to: CPU Architecture:Any

[26 Apr 2014 10:12] Shane Bester
Description:
Key points here:

o)  Inability to correctly identify safe/unsafe statements.
    e.g. UPDATE t SET intPK=2 WHERE intPK=1 ORDER BY intPK LIMIT 1;

o)  The thresholds for throttling are hard-coded in the code.

  //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

o)  The implementation of thresholds causes more spam

  At some point, 50% of the log messages are of the type:
  [Note] The following warning was suppressed 50 times during the last 0 seconds in the error log

Look at the attached error log please.
First spam:
2014-04-26 11:33:44 2928 [Warning] Unsafe statement written

Last spam:
first suppression spam:
2014-04-26 11:34:14 2928 [Warning] Unsafe statement written

With 10 threads running DML, in 30 seconds I got over 6MB of log:

D:\mysql-5.6.17-win32\bin>cat s.txt|grep -i unsafe|wc -l
  14367

D:\mysql-5.6.17-win32\bin>cat s.txt|grep -i suppress|wc -l
  14317

2014/04/26  11:37         6 445 329 s.txt

How to repeat:
run:  mysqld --log-bin --server-id=777 --binlog-format=statement

drop table if exists t1;
create table t1(a int primary key)engine=innodb;

#shoot the following queries million times in x threads:
update t1 set a=2 where a = 1 order by a limit 1 ;
show warnings;
delete from t1 where a = 1 order by a limit 1;
show warnings;

Suggested fix:
o) Fix the unsafe detection for obvious queries like the ones here.
   The case 'WHERE PK = int ORDER BY PK, LIMIT 1' will help majority of people today who use 5.6.
   Complex queries and char/blob/multi PK can be for some future WL.

o) Make any throttling decisions configurable by the DBA.

o) a 234 character long message is far too long.  Devs don't like >80 chars per line, neither does DBA like it.   Make a code, and shorten this text:

"Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. The statement is unsafe because it uses a LIMIT clause. This is unsafe because the set of rows included cannot be predicted. Statement:"

to this:

"Binlog: maybe unsafe [reason:STATEMENT, LIMIT]: update t1 set..."

Customers and Users still open SR and Google the overly verbose message, because it is wrong and confusing anyway.
[26 Apr 2014 10:12] Shane Bester
http://bugs.mysql.com/bug.php?id=42415 got too complex for my liking.
[26 Apr 2014 10:14] Shane Bester
sample error log

Attachment: bug72464_sample_error_log.zip (application/octet-stream, text), 175.62 KiB.