Bug #41809 "Statement is not safe to log in statement format." as error instead of warning
Submitted: 31 Dec 2008 15:33 Modified: 1 Jan 2009 12:36
Reporter: Serdar S. Kacar Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S4 (Feature request)
Version:5.1.30 OS:Any
Assigned to: Alfranio Correia CPU Architecture:Any
Tags: innodb, SBL, STRICT sql mode
Triage: Needs Triage: D5 (Feature request)

[31 Dec 2008 15:33] Serdar S. Kacar
Description:
When SBL is in effect, triggers that might have different execution paths on different servers might cause
  "Statement is not safe to log in statement format."
ERROR (instead of warning) when InnoDB engine is involved in those different execution paths.

Even this behaviour is by design, 
a. there is workaround that might be a serious bug
b. allow users having SUPER privilege to code triggers in such way by some declarations like
  CREATE TRIGGER ....
    ALLOW UNSAFE
    FOR EACH ROW
     ..

How to repeat:
bash-3.00# mysql -u root -p
Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 185
Server version: 5.1.30-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> DROP TABLE IF EXISTS `test`.`a`;
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE  `test`.`a` (
    ->   `SRV` int(10) unsigned NOT NULL,
    ->   `ID` int(10) unsigned NOT NULL,
    ->   `VL` int(10) unsigned NOT NULL,
    ->   PRIMARY KEY (`SRV`,`ID`)
    -> ) ENGINE=Blackhole DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.02 sec)

mysql>
mysql> DROP TABLE IF EXISTS `test`.`b`;
Query OK, 0 rows affected (0.02 sec)

mysql> CREATE TABLE  `test`.`b` (
    ->   `SRV` int(10) unsigned NOT NULL,
    ->   `ID` int(10) unsigned NOT NULL,
    ->   `VL` int(10) unsigned NOT NULL,
    ->   PRIMARY KEY (`SRV`,`ID`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.03 sec)

mysql>
mysql> DROP TABLE IF EXISTS `test`.`c`;
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE  `test`.`c` (
    ->   `SRV` int(10) unsigned NOT NULL,
    ->   `ID` int(10) unsigned NOT NULL,
    ->   `VL` int(10) unsigned NOT NULL,
    ->   PRIMARY KEY (`SRV`,`ID`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.03 sec)

mysql>
mysql> delimiter $$
mysql>
mysql> DROP TRIGGER IF EXISTS `test`.`a_AFTER_INSERT` $$
Query OK, 0 rows affected, 1 warning (0.01 sec)

mysql> CREATE TRIGGER `test`.`a_AFTER_INSERT` AFTER INSERT ON `test`.`a`
    ->   FOR EACH ROW
    ->     IF NEW.`SRV` = @@server_id THEN
    ->       INSERT IGNORE INTO `test`.`b` SET `SRV` = NEW.`SRV`, `ID` = NEW.`ID`, `VL` = NEW.`VL`;
    ->     ELSE
    ->       INSERT IGNORE INTO `test`.`c` SET `SRV` = NEW.`SRV`, `ID` = NEW.`ID`, `VL` = NEW.`VL`;
    ->     END IF;
    -> $$
Query OK, 0 rows affected (0.01 sec)

mysql>
mysql> delimiter ;
mysql>
mysql> -- Observe the error :
mysql> SET @@BINLOG_FORMAT = 'STATEMENT';
Query OK, 0 rows affected (0.00 sec)

mysql> INSERT INTO test.a VALUES (1, 1, 1);
ERROR 1592 (HY000): Statement is not safe to log in statement format.

mysql> -- Workaround :
mysql>
mysql> DROP TABLE IF EXISTS `test`.`dbgproc`;
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE  `test`.`dbgproc` (
    ->   `LBL` varchar(32) NOT NULL DEFAULT '',
    ->   `UPDDT` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
    ->   `ID` bigint(4) NOT NULL DEFAULT '0',
    ->   `USER` varchar(16) NOT NULL DEFAULT '',
    ->   `HOST` varchar(64) NOT NULL DEFAULT '',
    ->   `DB` varchar(64) DEFAULT NULL,
    ->   `COMMAND` varchar(16) NOT NULL DEFAULT '',
    ->   `TIME` bigint(7) NOT NULL DEFAULT '0',
    ->   `STATE` varchar(64) DEFAULT NULL,
    ->   PRIMARY KEY (`LBL`)
    -> ) ENGINE=MEMORY DEFAULT CHARSET=utf8;
Query OK, 0 rows affected (0.03 sec)

mysql>
mysql> DELIMITER $$
mysql>
mysql> DROP PROCEDURE IF EXISTS `qa`.`DbgProcMe`$$
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE DEFINER=`root`@`localhost` PROCEDURE  `qa`.`DbgProcMe`(sLBL VARCHAR(32))
    ->     SQL SECURITY INVOKER
    -> BEGIN
    ->   -- WORK AROUND VERSION :
    ->   DECLARE COL_ID bigint(4);
    ->   DECLARE COL_USER varchar(16);
    ->   DECLARE COL_HOST varchar(64);
    ->   DECLARE COL_DB varchar(64);
    ->   DECLARE COL_COMMAND varchar(16);
    ->   DECLARE COL_TIME bigint(7);
    ->   DECLARE COL_STATE varchar(64);
    ->   DECLARE CONTINUE HANDLER FOR SQLEXCEPTION BEGIN END; -- information_schema.`PROCESSLIST` can be buggy any time any version.
    ->     -- dangerous places are
    ->     -- - while processing init_file (read qa.SysInit())
    ->     -- - in triggers
    ->
    ->
    ->   SELECT A.`ID`, A.`USER`, A.`HOST`, A.`DB`, A.`COMMAND`, A.`TIME`, A.`STATE`
    ->     INTO COL_ID, COL_USER, COL_HOST, COL_DB, COL_COMMAND, COL_TIME, COL_STATE
    ->     FROM information_schema.`PROCESSLIST` A WHERE A.`ID` = CONNECTION_ID();
    ->
    ->   REPLACE qnorep.dbgproc
    ->   -- CREATE TEMPORARY TABLE dbg ENGINE=MyISAM
    ->     SELECT sLBL, NOW(), IFNULL(COL_ID,CONNECTION_ID()), COL_USER, COL_HOST, COL_DB, COL_COMMAND, COL_TIME, COL_STATE;
    ->
    ->   -- BEWARE : this version does not work on solaris 10u6 as of mysql 5.1.30 :
    ->   -- Error is "Data too long for column 'STATE'", Bug #41686
    ->   -- REPLACE dbgproc SELECT  sLBL,  NOW(),  A.`ID`,  A.`USER`,  A.`HOST`,  A.`DB`,  A.`COMMAND`,  A.`TIME`,  A.`STATE`
    ->   --  FROM information_schema.`PROCESSLIST` A WHERE A.`ID` = CONNECTION_ID();
    -> END $$
Query OK, 0 rows affected (0.02 sec)

mysql>
mysql>
mysql> DROP TRIGGER IF EXISTS `test`.`a_AFTER_INSERT` $$
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TRIGGER `test`.`a_AFTER_INSERT` AFTER INSERT ON `test`.`a`
    ->   FOR EACH ROW
    ->   BEGIN
    ->     CALL qa.DbgProcMe('HackSBLUnsafe'); -- otherwise error pops !
    ->     IF NEW.`SRV` = @@server_id THEN
    ->       INSERT IGNORE INTO `test`.`b` SET `SRV` = NEW.`SRV`, `ID` = NEW.`ID`, `VL` = NEW.`VL`;
    ->     ELSE
    ->       INSERT IGNORE INTO `test`.`c` SET `SRV` = NEW.`SRV`, `ID` = NEW.`ID`, `VL` = NEW.`VL`;
    ->     END IF;
    ->   END;
    -> $$
Query OK, 0 rows affected (0.01 sec)

mysql>
mysql> delimiter ;
mysql>
mysql> -- now it only gives a warning as documented :
mysql> SET @@BINLOG_FORMAT = 'STATEMENT';
Query OK, 0 rows affected (0.00 sec)

mysql> INSERT INTO test.a VALUES (1, 1, 1);
Query OK, 1 row affected, 2 warnings (0.03 sec)

mysql>
mysql>
mysql> SHOW WARNINGS \G
*************************** 1. row ***************************
  Level: Warning
   Code: 1265
Message: Data truncated for column 'STATE' at row 1
*************************** 2. row ***************************
  Level: Warning
   Code: 1592
Message: Statement is not safe to log in statement format.
2 rows in set (0.00 sec)

mysql>
[31 Dec 2008 15:34] Serdar S. Kacar
Configuration file

Attachment: my.cnf (text/plain), 2.92 KiB.

[31 Dec 2008 16:32] Sveta Smirnova
Thank you for the report.

You have sql_mode set to STRICT_TRANS_TABLES. InnoDB is transactional table, so converting warnings to errors is expected. So I close the report as "Not a Bug".
[1 Jan 2009 10:39] Serdar S. Kacar
Please provide TRIGGER level declaration flags to resolve such cases like
CREATE TRIGGER ....
  LOOSEN STRICT SQL 
  ...

Note that changing the SQL_MODE "inside" the trigger code does not work.

Only thing that works currently in such cases is, ensuring sql effects a non-transactional engine table before entering into transactional engine realm.
[1 Jan 2009 12:36] Sveta Smirnova
Thank you for the feedback.

Verified as feature request.