Read MySQL Binlogs better with rows query log events

Introduction : 

In MySQL the replication is logical. And the DB changes were written to mysqlbinlog. This mysqlbinlog is pulled (IO Thread) and applied ( SQL Thread) by the slave servers. Binlog is the key for MySQL Replication.

Binary logging format is of three types.

  • Statement
  • ROW
  • Mixed

ROW based replication benefits the smaller writes ( OLTP ) work load. The events are logged based on how individual table rows are affected. Primary key and Unique keys on tables benefits the efficient writes.

Major Drawbacks in Row Based Replication ( RBR ):

MySQL Binlog troubleshooting becomes harder at times when you have ROW/Mixed binlog formats.

ROW format is claimed to be a better Binlog Format for data consistency and scalability. But ROW based replication tends to have a couple of drawbacks when it was initially released in 5.1.

  1. Size of the Binlog Growth
  2. Hard to troubleshoot and fetch query causing the changes.

Solutions made by MySQL Team:

The MySQL version 5.6 overcomes this two drawbacks by

With MySQL Binlog format as ROW (default) from MySQL 5.7.7 . It benefits a lot to have this variable enabled as a MySQL standard practice.

I have already written about MySQL Binlog Row image in a blog. Now let us see about MySQL Binlog Rows Query Log Events.

Reading a MySQL Binlog (ROW) using mysqlbinlog and getting the right information from it for troubleshooting is not an easy task. Sometimes we interchange the purpose of –base64-output=decode-rows and -v ( verbose ) it was explained well by Sveta Smirnova in this blog.

In ROW based replication we can’t find out what is the exact SQL that modified the data. Let us consider an example ,

I have used OSM databases as an example here in MySQL 5.7.18. Below is my major config in my.cnf

[mysqld]
server_id=101
log_bin=mysql-bin
binlog_rows_query_log_events=ON
binlog_row_image=MINIMAL
binlog_format=ROW

Let us consider the table relations_new (copy of relations) in OSM.

mysql> use osm
Database changed
mysql> select relation_id,version,visible from relations_new where version > 400;
+-------------+---------+---------+
| relation_id | version | visible |
+-------------+---------+---------+
|        4601 |    1067 |       1 |
|        8127 |     546 |       1 |
|       10952 |     975 |       1 |
|       12461 |    1162 |       1 |
|       20469 |    1161 |       1 |
|       75880 |     489 |       1 |
|      103222 |     998 |       1 |
|      112662 |     421 |       1 |
|      125414 |     519 |       1 |
|      151304 |     537 |       1 |
|      166487 |     429 |       1 |
|      214454 |     541 |       1 |
|     1248389 |     433 |       1 |
|     1271719 |     425 |       1 |
+-------------+---------+---------+

Now i have updated the Visible column to “0”.

mysql> update relations_new set visible=0 where  version > 400;
Query OK, 14 rows affected (1.27 sec)
Rows matched: 14  Changed: 14  Warnings: 0

Let us analyse the mysqlbinlog to view the transaction made

mysqlbinlog --base64-output=decode-rows -vv mysql-bin.000004
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 290
#170803 13:03:20 server id 101  end_log_pos 350 CRC32 0x8a4a51dc        Table_map: `osm`.`relations_new` mapped to number 202
# at 350
#170803 13:03:20 server id 101  end_log_pos 652 CRC32 0xe1ab71ae        Update_rows: table id 202 flags: STMT_END_F
### UPDATE `osm`.`relations_new`
### WHERE
###   @1=4601 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=1067 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @5=0 /* TINYINT meta=0 nullable=0 is_null=0 */
### UPDATE `osm`.`relations_new`
### WHERE
###   @1=8127 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=546 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @5=0 /* TINYINT meta=0 nullable=0 is_null=0 */
### UPDATE `osm`.`relations_new`
### WHERE
###   @1=10952 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=975 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @5=0 /* TINYINT meta=0 nullable=0 is_null=0 */

In the above binlog output we can view that there is a change in table relations_new but does not state the SQL which triggered the update.

Now let us enable binlog_rows_query_log_events dynamically and make the update.

mysql> set global binlog_rows_query_log_events=1;
Query OK, 0 rows affected (0.01 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.21 sec)

mysql> \r
Connection id:    156
Current database: osm

mysql> update relations_new set visible=0 where  version > 400;
Query OK, 14 rows affected (0.66 sec)
Rows matched: 14  Changed: 14  Warnings: 0

Now let us analyse back the binary log with mysqlbinlog utility.

SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 290
#170803 13:35:09 server id 101  end_log_pos 369 CRC32 0x3242fb8c        Rows_query
# update relations_new set visible=0 where  version > 400
# at 369
#170803 13:35:09 server id 101  end_log_pos 429 CRC32 0xb4393d00        Table_map: `osm`.`relations_new` mapped to number 202
# at 429
#170803 13:35:09 server id 101  end_log_pos 731 CRC32 0x01812a1d        Update_rows: table id 202 flags: STMT_END_F
### UPDATE `osm`.`relations_new`
### WHERE
###   @1=4601 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=1067 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @5=0 /* TINYINT meta=0 nullable=0 is_null=0 */
### UPDATE `osm`.`relations_new`
### WHERE
###   @1=8127 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=546 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @5=0 /* TINYINT meta=0 nullable=0 is_null=0 */
### UPDATE `osm`.`relations_new`
### WHERE
###   @1=10952 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=975 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @5=0 /* TINYINT meta=0 nullable=0 is_null=0 */

With binlog_row_query_log_events it makes things easier to read the binary logs ( ROW format ). It can be enabled by default in production environments it benefits more than the additional IO usage.

Note :

  1. Percona XtraDB cluster (Galera) do not support binlog_rows_query_log_events.
Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s