Friday, September 12, 2008

Decoding binlog entries with row-based replication


rowing

If you have tried using row based replication, you may have noticed two things: (1) it fixes many inconsistencies of statement-based replication, but (2) the binlog is unfit for humans. Inspecting it after a problem occurs won't provide any useful information.
The instructions look like line noise, and when you don't see the result you were expecting you wonder if that's the case.

For example, after executing this code:
create table t1 (id int, c char(10), d date);
insert into t1 values (1, 'abc', '2008-01-01');
insert into t1 values (2, 'def', '2008-08-19');
insert into t1 values (3, 'ghi', current_date());
select * from t1;
+------+------+------------+
| id | c | d |
+------+------+------------+
| 1 | abc | 2008-01-01 |
| 2 | def | 2008-08-19 |
| 3 | ghi | 2008-09-12 |
+------+------+------------+

The binlog, as shown by mysqlbinlog, gives output like

# at 182
#080912 17:15:07 server id 1 end_log_pos 289 Query thread_id=5 exec_time=0 error_code=0
SET TIMESTAMP=1221232507/*!*/;
create table t1 (id int, c char(10), d date)
/*!*/;
# at 289
#080912 17:15:07 server id 1 end_log_pos 357 Query thread_id=5 exec_time=0 error_code=0
SET TIMESTAMP=1221232507/*!*/;
BEGIN
/*!*/;
# at 357
# at 402
#080912 17:15:07 server id 1 end_log_pos 402 Table_map: `test`.`t1` mapped to number 21
#080912 17:15:07 server id 1 end_log_pos 443 Write_rows: table id 21 flags: STMT_END_F

BINLOG '
e4fKSBMBAAAALQAAAJIBAAAAABUAAAAAAAAABHRlc3QAAnQxAAMD/goC/goH
e4fKSBcBAAAAKQAAALsBAAAQABUAAAAAAAEAA//4AQAAAANhYmMhsA8=
'/*!*/;
This is more difficult to read than ancient Etruscan. If you are a DBA, you curse and look for help.
But now it has changed.
Starting with MySQL 5.1.28 (available since September 13th), using the "--verbose" option, mysqlbinlog will add some human readable comments after the statement.

BINLOG '
e4fKSBMBAAAALQAAAJIBAAAAABUAAAAAAAAABHRlc3QAAnQxAAMD/goC/goH
e4fKSBcBAAAAKQAAALsBAAAQABUAAAAAAAEAA//4AQAAAANhYmMhsA8=
'/*!*/;
### INSERT INTO test.t1
### SET
### @1=1
### @2='abc'
### @3='2008:01:01'
# at 443
The manual has more information on this topic.
It is a much needed addition. Our support department insisted on having this feature developed before GA, and with reason. Assisting customers who have replication problems without being able to decode the binlog output is quite a hard task.
Jan Kneschke, the author of MySQL Proxy, showed the way with this proof of concept, and now the feature is out. Good job, all the developers involved!

No comments: