MySQL Bugs: #72804: BINLOG statement can no longer be used to apply Query events

Bug #72804	BINLOG statement can no longer be used to apply Query events
Submitted:	29 May 2014 23:37	Modified:	19 Jun 2014 7:48
Reporter:	Davi Arnaut (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.6	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	binlog, regression

Description:
The patch for Bug#28760 changed the BINLOG statement to only accept format
description and row events. This makes it impossible preserve the context of
Query events when applying events without using replication threads. That is,
for example, when using log-slave-updates, it is not possible to preserve
the server-id of a query event without executing it via the BINLOG statement.

How to repeat:
Execute the BINLOG statement using a query event.

Suggested fix:
Allow the BINLOG statement to apply any kind of event.

Hello Davi,

Thank you for the bug report.
Could you please confirm if below steps are correct to reproduce this issue? If not then could you please provide the exact test case to reproduce this issue at our end?

1. Start server with strict mode or extra-safe options, no_zero_date, no_auto_value etc
2. Create some session environment  which overrides those safety options
3. Run some query which modifies data
4. logout, run mysqlbinlog on the binlog file
5. try to copy-paste BINLOG statement from the file

// 5.6.20

mysql> show global variables like 'sql_mode';
+---------------+---------------------+
| Variable_name | Value               |
+---------------+---------------------+
| sql_mode      | STRICT_TRANS_TABLES |
+---------------+---------------------+
1 row in set (0.00 sec)

mysql> create table t1(id int not null auto_increment, dtCol date not null, cText varchar(100) not null,key(id));
Query OK, 0 rows affected (0.03 sec)

mysql> insert into t1 values(0,'2014-06-03','bug');
Query OK, 1 row affected (0.00 sec)
mysql> insert into t1 values(0,'2014-06-03','bug 1');
Query OK, 1 row affected (0.00 sec)

mysql> select * from t1;
+----+------------+-------+
| id | dtCol      | cText |
+----+------------+-------+
|  1 | 2014-06-03 | bug   |
|  2 | 2014-06-03 | bug 1 |
+----+------------+-------+
2 rows in set (0.00 sec)

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

mysql> show variables like 'sql_mode';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| sql_mode      |       |
+---------------+-------+
1 row in set (0.00 sec)

mysql> insert into t1 values(0,'2014-06-00','');
Query OK, 1 row affected (0.00 sec)

mysql> select * from t1;
+----+------------+-------+
| id | dtCol      | cText |
+----+------------+-------+
|  1 | 2014-06-03 | bug   |
|  2 | 2014-06-03 | bug 1 |
|  3 | 2014-06-00 |       |
+----+------------+-------+
3 rows in set (0.00 sec)

// Extracted the snippet from binary log using mysqlbinlog
// Later, tried to replay

mysql> # at 771
mysql> #140605  7:56:05 server id 1  end_log_pos 820 CRC32 0x6af99f25  Table_map: `test`.`t1` mapped to number 75
mysql> # at 820
mysql> #140605  7:56:05 server id 1  end_log_pos 864 CRC32 0xfce3e9b9  Write_rows: table id 75 flags: STMT_END_F
mysql>
mysql> BINLOG '
    '> PdWPUxMBAAAAMQAAADQDAAAAAEsAAAAAAAEABHRlc3QAAnQxAAMDCg8CZAAAJZ/5ag==
    '> PdWPUx4BAAAALAAAAGADAAAAAEsAAAAAAAEAAgAD//gDAAAAwLwPALnp4/w=
    '> '/*!*/;
ERROR 1609 (HY000): The BINLOG statement of type `Table_map` was not preceded by a format description BINLOG statement.
mysql> # at 864
mysql> #140605  7:56:05 server id 1  end_log_pos 895 CRC32 0x1ae03485  Xid = 87
mysql> COMMIT/*!*/;
Query OK, 0 rows affected (0.00 sec)

==================================================================

Thanks,
Umesh

Davi, if you mean ROWS_QUERY_LOG_EVENT, then in the function check_event_type I still see it as allowed.  

 switch (type)
  {
  case START_EVENT_V3:
  case FORMAT_DESCRIPTION_EVENT:
    /*
      We need a preliminary FD event in order to parse the FD event,
      if we don't already have one.
    */
    if (!fd_event)
      rli->set_rli_description_event(new Format_description_log_event(4));

    /* It is always allowed to execute FD events. */
    return 0;

  case ROWS_QUERY_LOG_EVENT:
  case TABLE_MAP_EVENT:
  case WRITE_ROWS_EVENT:
  case UPDATE_ROWS_EVENT:
  case DELETE_ROWS_EVENT:
  case WRITE_ROWS_EVENT_V1:
  case UPDATE_ROWS_EVENT_V1:
  case DELETE_ROWS_EVENT_V1:
  case PRE_GA_WRITE_ROWS_EVENT:
  case PRE_GA_UPDATE_ROWS_EVENT:
  case PRE_GA_DELETE_ROWS_EVENT:
    /*
      Row events are only allowed if a Format_description_event has
      already been seen.
    */
    if (fd_event)
      return 0;
    else
    {
      my_error(ER_NO_FORMAT_DESCRIPTION_EVENT_BEFORE_BINLOG_STATEMENT,
               MYF(0), Log_event::get_type_str((Log_event_type)type));
      return 1;
    }
    break;

  default:
    /*
      It is not meaningful to execute other events than row-events and
      FD events. It would even be dangerous to execute Stop_log_event
      and Rotate_log_event since they call flush_relay_log_info, which
      is not allowed to call by other threads than the slave SQL
      thread when the slave SQL thread is running.
    */
    my_error(ER_ONLY_FD_AND_RBR_EVENTS_ALLOWED_IN_BINLOG_STATEMENT,
             MYF(0), Log_event::get_type_str((Log_event_type)type));
    return 1;
  }

How to reproduce:

BINLOG '
r8WhUw8BAAAAZwAAAGsAAAABAAQANS41LjM4LXZhbGdyaW5kLW1heC1kZWJ1Zy1sb2cAAAAAAAAA
AAAAAAAAAAAAAAAAAACvxaFTEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;

BINLOG '
s8WhUwIBAAAARAAAAK8AAAAIAAEAAAAAAAAABAAAGgAAAAAAAAEAAAAAAAAAAAYDc3RkBCEAIQAI
AHRlc3QAQkVHSU4=
'/*!*/;

The first BINLOG statement is for a FORMAT_DESCRIPTION_EVENT event (always required) and the second is for a QUERY_EVENT event (which is manually encoded).

mysql> BINLOG '
    '> r8WhUw8BAAAAZwAAAGsAAAABAAQANS41LjM4LXZhbGdyaW5kLW1heC1kZWJ1Zy1sb2cAAAAAAAAA
    '> AAAAAAAAAAAAAAAAAACvxaFTEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
    '> '/*!*/;
Query OK, 0 rows affected (0.00 sec)

mysql> BINLOG '
    '> s8WhUwIBAAAARAAAAK8AAAAIAAEAAAAAAAAABAAAGgAAAAAAAAEAAAAAAAAAAAYDc3RkBCEAIQAI
    '> AHRlc3QAQkVHSU4=
    '> '/*!*/;
ERROR 1730 (HY000): Only Format_description_log_event and row events are allowed in BINLOG statements (but Query was provided)
mysql>

> Davi, if you mean ROWS_QUERY_LOG_EVENT, then in the function check_event_type I still see it as allowed.  

That's not what I mean. I mean all the other types (including QUERY_EVENT) that are not allowed by that function.

Thank you for the test case.
Verified as described.

Thanks,
Umesh

Workaround:

copy a format description BINLOG statement from the beginning of the proceed binary file (first 11 lines in version 5.6).