Bug #40360 Binlog related errors with binlog off
Submitted: 27 Oct 2008 20:27 Modified: 18 Jun 2010 23:12
Reporter: David Stavisski Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.1.29 OS:Microsoft Windows
Assigned to: Mats Kindahl CPU Architecture:Any
Triage: Triaged: D2 (Serious) / R3 (Medium) / E3 (Medium)

[27 Oct 2008 20:27] David Stavisski
Description:
after upgrading to 5.1.28 from 5.1.28 getting an error message on every update:

Binary logging not possible. Message: Transaction level 'READ-COMMITTED' in InnoDB is not safe for binlog mode 'STATEMENT'

The binlog and replication is off.

How to repeat:
set transaction isolation to Read Commited
update a table row
[27 Oct 2008 20:29] David Stavisski
intended: upgraded 5.1.28 -> 5.1.29
[28 Oct 2008 4:22] Valeriy Kravchuk
Thank you for a problem report. Please, send your my.cnf. I can not repeat the behaviour described:

C:\Program Files\MySQL\MySQL Server 5.0\bin>mysql -uroot -proot -P3310 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 20
Server version: 5.1.29-rc-community MySQL Community Server (GPL)

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

mysql> set global transaction isolation level read committed;
Query OK, 0 rows affected (0.05 sec)

mysql> show variables like '%bin%';
+---------------------------------+------------+
| Variable_name                   | Value      |
+---------------------------------+------------+
| binlog_cache_size               | 32768      |
| binlog_format                   | STATEMENT  |
| innodb_locks_unsafe_for_binlog  | OFF        |
| log_bin                         | OFF        |
| log_bin_trust_function_creators | OFF        |
| log_bin_trust_routine_creators  | OFF        |
| max_binlog_cache_size           | 4294967295 |
| max_binlog_size                 | 1073741824 |
| sql_log_bin                     | ON         |
| sync_binlog                     | 0          |
+---------------------------------+------------+
10 rows in set (0.06 sec)

mysql> create table tlb(c1 int primary key, c2 int) engine=InnoDB;
Query OK, 0 rows affected (0.36 sec)

mysql> insert into tlb values(1,1);
Query OK, 1 row affected (0.11 sec)

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

mysql> update tlb set c2=2;
Query OK, 1 row affected (0.11 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

What I am doing wrong?
[28 Oct 2008 15:34] Valeriy Kravchuk
Sorry, my fault (I had forgotten that SET GLOBAL will work for new sessions). Verified like this:

C:\Program Files\MySQL\MySQL Server 5.0\bin>mysql -uroot -proot -P3310 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 21
Server version: 5.1.29-rc-community MySQL Community Server (GPL)

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

mysql> CREATE TABLE `datetest` (
    ->   `a` bigint(20) unsigned NOT NULL,
    ->   `b` datetime default NULL
    -> ) ENGINE=InnoDB;
Query OK, 0 rows affected (0.11 sec)

mysql> INSERT INTO test.datetest VALUES(1,'4269-02-29');
ERROR 1598 (HY000): Binary logging not possible. Message: Transaction level 'REA
D-COMMITTED' in InnoDB is not safe for binlog mode 'STATEMENT'
mysql> show variables like '%bin%';
+---------------------------------+------------+
| Variable_name                   | Value      |
+---------------------------------+------------+
| binlog_cache_size               | 32768      |
| binlog_format                   | STATEMENT  |
| innodb_locks_unsafe_for_binlog  | OFF        |
| log_bin                         | OFF        |
| log_bin_trust_function_creators | OFF        |
| log_bin_trust_routine_creators  | OFF        |
| max_binlog_cache_size           | 4294967295 |
| max_binlog_size                 | 1073741824 |
| sql_log_bin                     | ON         |
| sync_binlog                     | 0          |
+---------------------------------+------------+
10 rows in set (0.02 sec)
[29 Oct 2008 3:15] Tom Daly
I have just downloaded and installed 5.1.29 on RHEL 5 and I am seeing the same problem.

to reproduce : 
mysql < test.sql 
ERROR 1598 (HY000) at line 11: Binary logging not possible. Message: Transaction level 'READ-COMMITTED' in InnoDB is not safe for binlog mode 'STATEMENT'

cat test.sql 
DROP TABLE IF EXISTS customer;
CREATE TABLE customer
  (id           integer not null,
   itemid       char(20),
   quantity     integer,             
   customerid   integer,
   value                numeric(12,2),
   PRIMARY KEY C_custinvkey (id)
) ENGINE = InnoDB;

CREATE INDEX test_idx ON customer(customerid);

mysql> show variables like '%bin%';
+---------------------------------+----------------------+
| Variable_name                   | Value                |
+---------------------------------+----------------------+
| binlog_cache_size               | 32768                | 
| binlog_format                   | STATEMENT            | 
| innodb_locks_unsafe_for_binlog  | OFF                  | 
| log_bin                         | OFF                  | 
| log_bin_trust_function_creators | OFF                  | 
| log_bin_trust_routine_creators  | OFF                  | 
| max_binlog_cache_size           | 18446744073709551615 | 
| max_binlog_size                 | 1073741824           | 
| sql_log_bin                     | ON                   | 
| sync_binlog                     | 0                    | 
+---------------------------------+----------------------+
10 rows in set (0.00 sec)

mysql> show variables like '%innodb%';
+---------------------------------+---------------------------+
| Variable_name                   | Value                     |
+---------------------------------+---------------------------+
| have_innodb                     | YES                       | 
| innodb_adaptive_hash_index      | ON                        | 
| innodb_additional_mem_pool_size | 20971520                  | 
| innodb_autoextend_increment     | 8                         | 
| innodb_autoinc_lock_mode        | 1                         | 
| innodb_buffer_pool_size         | 5242880000                | 
| innodb_checksums                | OFF                       | 
| innodb_commit_concurrency       | 0                         | 
| innodb_concurrency_tickets      | 500                       | 
| innodb_data_file_path           | ibdata1:10000M:autoextend | 
| innodb_data_home_dir            | /data/mysql/var           | 
| innodb_doublewrite              | OFF                       | 
| innodb_fast_shutdown            | 1                         | 
| innodb_file_io_threads          | 4                         | 
| innodb_file_per_table           | ON                        | 
| innodb_flush_log_at_trx_commit  | 1                         | 
| innodb_flush_method             | O_DIRECT                  | 
| innodb_force_recovery           | 0                         | 
| innodb_lock_wait_timeout        | 300                       | 
| innodb_locks_unsafe_for_binlog  | OFF                       | 
| innodb_log_buffer_size          | 16777216                  | 
| innodb_log_file_size            | 1677721600                | 
| innodb_log_files_in_group       | 2                         | 
| innodb_log_group_home_dir       | /log/mysql/var/           | 
| innodb_max_dirty_pages_pct      | 15                        | 
| innodb_max_purge_lag            | 0                         | 
| innodb_mirrored_log_groups      | 1                         | 
| innodb_open_files               | 300                       | 
| innodb_rollback_on_timeout      | OFF                       | 
| innodb_support_xa               | OFF                       | 
| innodb_sync_spin_loops          | 20                        | 
| innodb_table_locks              | ON                        | 
| innodb_thread_concurrency       | 0                         | 
| innodb_thread_sleep_delay       | 10000                     | 
+---------------------------

regards
Tom Daly (Sun Microsystems)
[29 Oct 2008 14:25] Trudy Pelzer
Per Joro:
This is a consequence of us changing the default binlog format for 5.1 to statement (http://bugs.mysql.com/bug.php?id=39812).
It seems that the InnoDB code has an incomplete check in ha_innobase::external_lock() :

6529         /* Statement based binlogging does not work in isolation level
6530         READ UNCOMMITTED and READ COMMITTED since the necessary
6531         locks cannot be taken. In this case, we print an
6532         informative error message and return with an error. */
6533         if (lock_type == F_WRLCK)
6534         {
6535                 ulong const binlog_format= thd_binlog_format(thd);
6536                 ulong const tx_isolation = thd_tx_isolation(current_thd);
6537                 if (tx_isolation <= ISO_READ_COMMITTED &&
6538                     binlog_format == BINLOG_FORMAT_STMT)
6539                 {
6540                         char buf[256];
6541                         my_snprintf(buf, sizeof(buf),
6542                                     "Transaction level '%s' in"
6543                                     " InnoDB is not safe for binlog mode '%s'",
6544                                     tx_isolation_names[tx_isolation],
6545                                     binlog_format_names[binlog_format]);
6546                         my_error(ER_BINLOG_LOGGING_IMPOSSIBLE, MYF(0), buf);
6547                         DBUG_RETURN(HA_ERR_LOGGING_IMPOSSIBLE);
6548                 } 

Note that it doesn't check if binary log is on or off when performing this check.

Workaround: switch to MIXED mode for your installation (as should be the default for new installations using the config file generated by the installer).
[29 Oct 2008 15:26] David Stavisski
Unfortunately the workaround does not work (or at least not completely):
if you set:
binlog_format=mixed
without enabling the bin-log, the serve does not start complaining that the bon-log is off. You have to enable it:
log-bin=mysql-bin
which carries a performance penalty.

Thx,
David Stavisski
[29 Oct 2008 15:39] Mikhail Izioumtchenko
Assigning to Vasil. R/E values based on the assumed one line fix. 
It would be also nice to add a test case for this.
[29 Oct 2008 17:34] Mike Mulligan
I receive this same error when trying to use MySQL 5.1.29 as a respository for Sun Identity Manager 7.1.1 using Netbeans 6.1.

When I set the repository in Netbeans and select MySQL JDBC driver, I get:

java.sql.SQLException: Binary logging not possible. Message: Transaction level 'READ-COMMITTED' in InnoDB is not safe for binlog mode 'STATEMENT'

I had to roll back to MySQL 5.0.67 to get Sun IdM/Netbeans to work.
[29 Oct 2008 21:08] Vasil Dimov
From sql/log.h:

556 enum enum_binlog_format {
557   /*
558     statement-based except for cases where only row-based can work (UUID()
559     etc):
560   */
561   BINLOG_FORMAT_MIXED= 0,
562   BINLOG_FORMAT_STMT= 1, // statement-based
563   BINLOG_FORMAT_ROW= 2, // row_based
564 /*
565   This value is last, after the end of binlog_format_typelib: it has no
566   corresponding cell in this typelib. We use this value to be able to know if
567   the user has explicitely specified a binlog format at startup or not.
568 */
569   BINLOG_FORMAT_UNSPEC= 3
570 };

So, why is the value returned by thd_binlog_format() BINLOG_FORMAT_STMT when no --binlog_format has been specified at startup?
[30 Oct 2008 7:01] Vasil Dimov
Sidenote:

This problem is present in 5.1.28 too, and I guess has always been there:

Start mysqld without any binlogging options:

Version: '5.1.28-rc'  socket: '/tmp/mysql.sock'  port: 0  FreeBSD port: mysql-server-5.1.28_1

mysql> set tx_isolation='read-committed';
Query OK, 0 rows affected (0.00 sec)

mysql> set binlog_format='statement';
Query OK, 0 rows affected (0.00 sec)

mysql> create table t (a int) engine=innodb;
Query OK, 0 rows affected (0.13 sec)

mysql> insert into t values (1);
ERROR 1598 (HY000): Binary logging not possible. Message: Transaction level 'READ-COMMITTED' in InnoDB is not safe for binlog mode 'STATEMENT'

It has just not been discovered because noone bothered to set binlog_format without turning binlogging on (and also setting tx_isolation to 'read-committed').
[30 Oct 2008 11:34] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/57440

2777 Georgi Kodinov	2008-10-30
      Bug #40360: Binlog related errors with binlog off
      
      Fixed MySQL to return BINLOG_FORMAT_UNSPEC when bin_log is off and no binlog_format was specified.
[30 Oct 2008 11:37] Georgi Kodinov
Proposed fix to MySQL committed
[30 Oct 2008 11:50] Vasil Dimov
From the commit message:

connect(localhost,root,,test,12000,/home/kgeorge/mysql/bzr/B40360-5.1-5.1.29-rc/mysql-test/var/tmp/master.sock);

are you sure the above is correct?
[30 Oct 2008 13:33] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/57450

2773 Mats Kindahl	2008-10-30
      Bug #40360: Binlog related errors with binlog off
      
      When statement-based replication is used, and the
      transaction isolation level is READ-COMMITTED or stricter,
      InnoDB will print an error because statement-based
      replication might lead to inconsistency between master
      and slave databases. However, when the binary log is not
      engaged, this is not an issue and an error should
      not be printed.
      
      This patch extends the check in InnoDB to also check if
      the binary log is engaged for the thread, that is, open
      and with SQL_LOG_BIN = 1.
[30 Oct 2008 14:00] Mats Kindahl
The submitted patch will is a tentative patch for fixing the issue, awaiting the final review by Innobase. The patch contain changes to both the server and the InnoDB handler.
[30 Oct 2008 14:15] Vasil Dimov
Just for the records:

The check inside ha_innobase::external_lock() probably originated from the fix of Bug#23051 READ COMMITTED breaks mixed and statement-based replication.
[3 Nov 2008 11:32] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/57684

2773 Mats Kindahl	2008-11-03
      Bug #40360: Binlog related errors with binlog off
            
      When statement-based replication is used, and the
      transaction isolation level is READ-COMMITTED or stricter,
      InnoDB will print an error because statement-based
      replication might lead to inconsistency between master
      and slave databases. However, when the binary log is not
      engaged, this is not an issue and an error should
      not be printed.
      
      This patch makes thd_binlog_format() return BINLOG_FORMAT_
      UNSPEC when the binary log is not engaged for the given
      thread.
[3 Nov 2008 17:47] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/57711

2774 Mats Kindahl	2008-11-03
      Bug #40360: Binlog related errors with binlog off
      
      Adding missing drop of created table and tidying display.
[4 Nov 2008 9:20] Bugs System
Pushed into 5.1.30  (revid:mats@sun.com-20081103174647-s4jyy5vqe0eo68q0) (version source revid:mats@sun.com-20081103174647-s4jyy5vqe0eo68q0) (pib:5)
[4 Nov 2008 16:26] Paul Dubois
Noted in 5.1.30 changelog.

With statement-based binary logging format and a transaction 
isolation level of READ COMMITTED or stricter, InnoDB printed an
error because statement-based logging might lead to inconsistency
between master and slave databases. However, this error was printed 
even when binary logging was not enabled (in which case, no such
inconsistency can occur).
[4 Nov 2008 16:26] Paul Dubois
Setting report to NDI pending push into 6.0.x.
[5 Nov 2008 10:28] Godofredo Miguel Solorzano
Bug: http://bugs.mysql.com/bug.php?id=40513 was marked as duplicate of this one.
[10 Nov 2008 10:50] Bugs System
Pushed into 6.0.8-alpha  (revid:mats@sun.com-20081103174647-s4jyy5vqe0eo68q0) (version source revid:kgeorge@mysql.com-20081106161825-9biri1v40v7b0kg3) (pib:5)
[10 Nov 2008 19:12] Paul Dubois
Note in 6.0.8 changelog.
[11 Nov 2008 16:33] Paul Dubois
6.0.9 changelog, not 6.0.8.
[21 Nov 2008 21:02] Bugs System
Pushed into 5.1.30-ndb-6.2.17  (revid:mats@sun.com-20081103174647-s4jyy5vqe0eo68q0) (version source revid:tomas.ulin@sun.com-20081121161314-jhz3twf5xjt8stnh) (pib:5)
[21 Nov 2008 23:45] Bugs System
Pushed into 5.1.30-ndb-6.3.20  (revid:mats@sun.com-20081103174647-s4jyy5vqe0eo68q0) (version source revid:tomas.ulin@sun.com-20081121210644-zas6e9wa5kuj7d6f) (pib:5)
[27 Nov 2008 14:52] Bugs System
Pushed into 5.1.30-ndb-6.4.0  (revid:mats@sun.com-20081103174647-s4jyy5vqe0eo68q0) (version source revid:tomas.ulin@sun.com-20081126125835-5sohkzk2jjwpq1wp) (pib:5)
[6 Feb 2009 3:48] James Day
Note that if you use READ-COMMITTED and binary logging (including for replication) 5.1 you must use row-based binlogging. It's expected that you will see this error if you try to add rows to an InnoDB table otherwise. For more information see the manual at http://dev.mysql.com/doc/refman/5.1/en/set-transaction.html . You should change the transaction isolation level or the binary logging mode.
[5 May 2010 15:21] Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[6 May 2010 16:52] Paul Dubois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.
[28 May 2010 5:51] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)
[28 May 2010 6:20] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[28 May 2010 6:49] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[29 May 2010 15:24] Paul Dubois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.
[15 Jun 2010 8:17] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100615080459-smuswd9ooeywcxuc) (version source revid:mmakela@bk-internal.mysql.com-20100415070122-1nxji8ym4mao13ao) (merge vers: 5.1.47) (pib:16)
[15 Jun 2010 8:34] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100615080558-cw01bzdqr1bdmmec) (version source revid:mmakela@bk-internal.mysql.com-20100415070122-1nxji8ym4mao13ao) (pib:16)
[17 Jun 2010 11:52] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:29] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:17] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)