Bug #89741 Events log Note level messages even for log_warnings=0
Submitted: 21 Feb 2018 4:55 Modified: 21 Feb 2018 7:56
Reporter: Nikolai Ikhalainen Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Options Severity:S3 (Non-critical)
Version:5.6.39, 5.5.59 OS:Any
Assigned to: CPU Architecture:Any

[21 Feb 2018 4:55] Nikolai Ikhalainen
Description:
Event Scheduler spams error log with warnings from statements:
2018-02-21 04:30:32 1 [Note] Event Scheduler: [root@localhost][test.e1] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. 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.

maybe similar to: https://bugs.mysql.com/bug.php?id=38066

How to repeat:
docker pull mysql:5.6
docker run --name m56 -it -e MYSQL_ALLOW_EMPTY_PASSWORD=1 mysql:5.6 --log-bin --server-id=51 --event-scheduler --binlog_format=statement --log-warnings=0

in second terminal:
docker exec -it m56 mysql -e 'create database test;create table test.t (c int);create table test.t1(c int);insert into test.t1 values (1),(2),(3),(4),(5);create event test.e1 on schedule every 1 minute starts current_timestamp + interval 1 minute do replace into t select * from t1;'

There is no such problem with mysql 5.7.21 (docker mysql:5.7).
[21 Feb 2018 7:56] MySQL Verification Team
Hello Nikolai,

Thank you for the report.
Observed that 5.6.39 is affected.

Thanks,
Umesh
[21 Feb 2018 7:57] MySQL Verification Team
test results

Attachment: 89741.results (application/octet-stream, text), 24.43 KiB.

[21 Feb 2018 8:03] MySQL Verification Team
-- 5.5.59 also affected

rm -rf 89696
scripts/mysql_install_db --basedir=$PWD --datadir=$PWD/89696 -v
bin/mysqld --no-defaults --basedir=$PWD --datadir=$PWD/89696 --core-file --socket=/tmp/mysql_ushastry.sock   --port=3307 --log-error=$PWD/89696/log.err --log-bin --server-id=51 --event-scheduler --binlog_format=statement --log-warnings=0 2>&1 &

[umshastr@hod03]/export/umesh/server/binaries/GABuilds/mysql-5.5.59: bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.5.59-log MySQL Community Server (GPL)

Copyright (c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show variables like 'log%';
+---------------------------------+-------------------------------------------------------------------+
| Variable_name                   | Value                                                             |
+---------------------------------+-------------------------------------------------------------------+
| log                             | OFF                                                               |
| log_bin                         | ON                                                                |
| log_bin_trust_function_creators | OFF                                                               |
| log_error                       | /export/umesh/server/binaries/GABuilds/mysql-5.5.59/89696/log.err |
| log_output                      | FILE                                                              |
| log_queries_not_using_indexes   | OFF                                                               |
| log_slave_updates               | OFF                                                               |
| log_slow_queries                | OFF                                                               |
| log_warnings                    | 0                                                                 |
+---------------------------------+-------------------------------------------------------------------+
9 rows in set (0.00 sec)

mysql> create table test.t (c int);create table test.t1(c int);insert into test.t1 values (1),(2),(3),(4),(5);create event test.e1 on schedule every 1 minute starts current_timestamp + interval 1 minute do replace into t select * from t1;
Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.01 sec)

Query OK, 5 rows affected (0.00 sec)
Records: 5  Duplicates: 0  Warnings: 0

Query OK, 0 rows affected (0.00 sec)

mysql>

--
[umshastr@hod03]/export/umesh/server/binaries/GABuilds/mysql-5.5.59: tail -f 89696/log.err
InnoDB: Foreign key constraint system tables created
180221  8:59:00  InnoDB: Waiting for the background threads to start
180221  8:59:01 InnoDB: 5.5.59 started; log sequence number 0
180221  8:59:01 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3307
180221  8:59:01 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
180221  8:59:01 [Note] Server socket created on IP: '0.0.0.0'.
180221  8:59:01 [Note] Event Scheduler: Loaded 0 events
180221  8:59:01 [Note] bin/mysqld: ready for connections.
Version: '5.5.59-log'  socket: '/tmp/mysql_ushastry.sock'  port: 3307  MySQL Community Server (GPL)
180221  8:59:01 [Note] Event Scheduler: scheduler thread started with id 1
180221  9:01:21 [Note] Event Scheduler: [root@localhost][test.e1] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. 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.
180221  9:02:21 [Note] Event Scheduler: [root@localhost][test.e1] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. 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.