----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Store in binlog text of statements that caused RBR events CREATION DATE..: Sat, 15 Aug 2009, 23:48 SUPERVISOR.....: Monty IMPLEMENTOR....: COPIES TO......: Knielsen CATEGORY.......: Server-RawIdeaBin TASK ID........: 47 (http://askmonty.org/worklog/?tid=47) VERSION........: Server-9.x STATUS.........: Un-Assigned PRIORITY.......: 60 WORKED HOURS...: 0 ESTIMATE.......: 0 (hours remain) ORIG. ESTIMATE.: 0 PROGRESS NOTES: -=-=(Alexi - Wed, 02 Dec 2009, 13:31)=-=- High-Level Specification modified. --- /tmp/wklog.47.old.17414 2009-12-02 11:31:59.000000000 +0000 +++ /tmp/wklog.47.new.17414 2009-12-02 11:31:59.000000000 +0000 @@ -104,3 +104,10 @@ ### @1=1 /* INT meta=0 nullable=1 is_null=0 */ ... +When master sends Annotate rows events +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ +1. Master always sends Annotate_rows events to mysqlbinlog (in + remote case). +2. Master sends Annotate_rows events to a slave only if the slave has + both log-slave-updates and binlog-annotate-row-events options set. + -=-=(Knielsen - Mon, 30 Nov 2009, 11:21)=-=- High-Level Specification modified. --- /tmp/wklog.47.old.18210 2009-11-30 11:21:33.000000000 +0200 +++ /tmp/wklog.47.new.18210 2009-11-30 11:21:33.000000000 +0200 @@ -28,7 +28,14 @@ Describes the query which caused the corresponding row event. In binary log, precedes each Table_map_log_event. Contains empty post-header and the query -text in its data part. Example: +text in its data part. + +The numeric code for this event must be assigned carefully. It should be +coordinated with MySQL/Sun, otherwise we can get into a situation where MySQL +uses the same numeric code for one event that MariaDB uses for +ANNOTATE_ROWS_EVENT, which would make merging the two impossible. + +Example: ... ************************ -=-=(Alexi - Mon, 30 Nov 2009, 10:33)=-=- Low Level Design modified. --- /tmp/wklog.47.old.16188 2009-11-30 10:33:44.000000000 +0200 +++ /tmp/wklog.47.new.16188 2009-11-30 10:33:44.000000000 +0200 @@ -2,6 +2,7 @@ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 1. When sending events to a slave, master should simply skip Annotate_rows events (they are not needed for replication). + [ ??? Multi-master - currently not clear ] 2. When sending events to mysqlbinlog (remote case), master must send Annotate_rows events as well. -=-=(Alexi - Sun, 29 Nov 2009, 13:00)=-=- Low Level Design modified. --- /tmp/wklog.47.old.32047 2009-11-29 13:00:21.000000000 +0200 +++ /tmp/wklog.47.new.32047 2009-11-29 13:00:21.000000000 +0200 @@ -1 +1,7 @@ +mysql_binlog_send() [sql/sql_repl.cc] +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ +1. When sending events to a slave, master should simply skip + Annotate_rows events (they are not needed for replication). +2. When sending events to mysqlbinlog (remote case), master + must send Annotate_rows events as well. -=-=(Alexi - Sun, 29 Nov 2009, 09:50)=-=- High-Level Specification modified. --- /tmp/wklog.47.old.24993 2009-11-29 07:50:36.000000000 +0000 +++ /tmp/wklog.47.new.24993 2009-11-29 07:50:36.000000000 +0000 @@ -4,3 +4,96 @@
(Comment_log_event?). Unless we want to log an empty statement Query_log_event containing only a comment (a bit of a hack).
+New server option +~~~~~~~~~~~~~~~~~ + --binlog-annotate-row-events + +Setting this option makes RBR (row-) events in the binary log to be +preceded by Annotate rows events (see below). The corresponding +'binlog_annotate_row_events' system variable is dynamic and has both +global and session values. Default global value is OFF. + +Note. Session values are usefull to make it possible to annotate only + some selected statements: + + ... + SET SESSION binlog_annotate_row_events=ON; + ... statements to be annotated ... + SET SESSION binlog_annotate_row_events=OFF; + ... statements not to be annotated ... + +New binlog event type +~~~~~~~~~~~~~~~~~~~~~ + Annotate_rows_log_event [ ANNOTATE_ROWS_EVENT ] + +Describes the query which caused the corresponding row event. In binary log, +precedes each Table_map_log_event. Contains empty post-header and the query +text in its data part. Example: + + ... + ************************ + ANNOTATE_ROWS_EVENT [51] + ************************ + 000000C7 | 54 1B 12 4B | time_when = 1259477844 + 000000CB | 33 | event_type = 51 + 000000CC | 64 00 00 00 | server_id = 100 + 000000D0 | 2C 00 00 00 | event_len = 44 + 000000D4 | F3 00 00 00 | log_pos = 000000F3 + 000000D8 | 00 00 | flags = <none> + ------------------------ + 000000DA | 69 6E 73 65 | query = "insert into t1 values (1)" + 000000DE | 72 74 20 69 | + 000000E2 | 6E 74 6F 20 | + 000000E6 | 74 31 20 76 | + 000000EA | 61 6C 75 65 | + 000000EE | 73 20 28 31 | + 000000F2 | 29 | + ************************ + TABLE_MAP_EVENT [19] + ************************ + 000000F3 | 54 1B 12 4B | time_when = 1259477844 + 000000F7 | 13 | event_type = 19 + 000000F8 | 64 00 00 00 | server_id = 100 + 000000FC | 29 00 00 00 | event_len = 41 + 00000100 | 1C 01 00 00 | log_pos = 0000011C + 00000104 | 00 00 | flags = <none> + ------------------------ + ... + ************************ + WRITE_ROWS_EVENT [23] + ************************ + 0000011C | 54 1B 12 4B | time_when = 1259477844 + 00000120 | 17 | event_type = 23 + 00000121 | 64 00 00 00 | server_id = 100 + 00000125 | 22 00 00 00 | event_len = 34 + 00000129 | 3E 01 00 00 | log_pos = 0000013E + 0000012D | 10 00 | flags = LOG_EVENT_UPDATE_TABLE_MAP_VERSION_F + ------------------------ + 0000012F | 0F 00 00 00 | table_id = 15 + ... + +mysqlbinlog output +~~~~~~~~~~~~~~~~~~ +Something like this: + + ... + # at 199 + # at 243 + # at 284 + #091129 9:57:24 server id 100 end_log_pos 243 Query: `insert into t1 values +(1)` + #091129 9:57:24 server id 100 end_log_pos 284 Table_map: `test`.`t1` mapped +to number 15 + #091129 9:57:24 server id 100 end_log_pos 318 Write_rows: table id 15 +flags: STMT_END_F + + BINLOG ' + VBsSSzNkAAAALAAAAPMAAAAAAGluc2VydCBpbnRvIHQxIHZhbHVlcyAoMSk= + VBsSSxNkAAAAKQAAABwBAAAAAA8AAAAAAAAABHRlc3QAAnQxAAEDAAE= + VBsSSxdkAAAAIgAAAD4BAAAQAA8AAAAAAAEAAf/+AQAAAA== + '/*!*/; + ### INSERT INTO test.t1 + ### SET + ### @1=1 /* INT meta=0 nullable=1 is_null=0 */ + ... + -=-=(Knielsen - Fri, 27 Nov 2009, 13:30)=-=- Observers changed: Knielsen -=-=(Psergey - Sun, 16 Aug 2009, 11:08)=-=- High-Level Specification modified. --- /tmp/wklog.47.old.12485 2009-08-16 11:08:33.000000000 +0300 +++ /tmp/wklog.47.new.12485 2009-08-16 11:08:33.000000000 +0300 @@ -1 +1,6 @@ +First suggestion: + +> I think for this we would actually need a new binlog event type +> (Comment_log_event?). Unless we want to log an empty statement Query_log_event +> containing only a comment (a bit of a hack). -=-=(Psergey - Sun, 16 Aug 2009, 00:02)=-=- Dependency created: 39 now depends on 47 DESCRIPTION: Store in binlog (and show in mysqlbinlog output) texts of statements that caused RBR events This is needed for (list from Monty): - Easier to understand why updates happened - Would make it easier to find out where in application things went wrong (as you can search for exact strings) - Allow one to filter things based on comments in the statement. The cost of this can be that the binlog will be approximately 2x in size (especially insert of big blob's would be a bit painful), so this should be an optional feature. HIGH-LEVEL SPECIFICATION: First suggestion:
I think for this we would actually need a new binlog event type (Comment_log_event?). Unless we want to log an empty statement Query_log_event containing only a comment (a bit of a hack).
New server option ~~~~~~~~~~~~~~~~~ --binlog-annotate-row-events Setting this option makes RBR (row-) events in the binary log to be preceded by Annotate rows events (see below). The corresponding 'binlog_annotate_row_events' system variable is dynamic and has both global and session values. Default global value is OFF. Note. Session values are usefull to make it possible to annotate only some selected statements: ... SET SESSION binlog_annotate_row_events=ON; ... statements to be annotated ... SET SESSION binlog_annotate_row_events=OFF; ... statements not to be annotated ... New binlog event type ~~~~~~~~~~~~~~~~~~~~~ Annotate_rows_log_event [ ANNOTATE_ROWS_EVENT ] Describes the query which caused the corresponding row event. In binary log, precedes each Table_map_log_event. Contains empty post-header and the query text in its data part. The numeric code for this event must be assigned carefully. It should be coordinated with MySQL/Sun, otherwise we can get into a situation where MySQL uses the same numeric code for one event that MariaDB uses for ANNOTATE_ROWS_EVENT, which would make merging the two impossible. Example: ... ************************ ANNOTATE_ROWS_EVENT [51] ************************ 000000C7 | 54 1B 12 4B | time_when = 1259477844 000000CB | 33 | event_type = 51 000000CC | 64 00 00 00 | server_id = 100 000000D0 | 2C 00 00 00 | event_len = 44 000000D4 | F3 00 00 00 | log_pos = 000000F3 000000D8 | 00 00 | flags = <none> ------------------------ 000000DA | 69 6E 73 65 | query = "insert into t1 values (1)" 000000DE | 72 74 20 69 | 000000E2 | 6E 74 6F 20 | 000000E6 | 74 31 20 76 | 000000EA | 61 6C 75 65 | 000000EE | 73 20 28 31 | 000000F2 | 29 | ************************ TABLE_MAP_EVENT [19] ************************ 000000F3 | 54 1B 12 4B | time_when = 1259477844 000000F7 | 13 | event_type = 19 000000F8 | 64 00 00 00 | server_id = 100 000000FC | 29 00 00 00 | event_len = 41 00000100 | 1C 01 00 00 | log_pos = 0000011C 00000104 | 00 00 | flags = <none> ------------------------ ... ************************ WRITE_ROWS_EVENT [23] ************************ 0000011C | 54 1B 12 4B | time_when = 1259477844 00000120 | 17 | event_type = 23 00000121 | 64 00 00 00 | server_id = 100 00000125 | 22 00 00 00 | event_len = 34 00000129 | 3E 01 00 00 | log_pos = 0000013E 0000012D | 10 00 | flags = LOG_EVENT_UPDATE_TABLE_MAP_VERSION_F ------------------------ 0000012F | 0F 00 00 00 | table_id = 15 ... mysqlbinlog output ~~~~~~~~~~~~~~~~~~ Something like this: ... # at 199 # at 243 # at 284 #091129 9:57:24 server id 100 end_log_pos 243 Query: `insert into t1 values (1)` #091129 9:57:24 server id 100 end_log_pos 284 Table_map: `test`.`t1` mapped to number 15 #091129 9:57:24 server id 100 end_log_pos 318 Write_rows: table id 15 flags: STMT_END_F BINLOG ' VBsSSzNkAAAALAAAAPMAAAAAAGluc2VydCBpbnRvIHQxIHZhbHVlcyAoMSk= VBsSSxNkAAAAKQAAABwBAAAAAA8AAAAAAAAABHRlc3QAAnQxAAEDAAE= VBsSSxdkAAAAIgAAAD4BAAAQAA8AAAAAAAEAAf/+AQAAAA== '/*!*/; ### INSERT INTO test.t1 ### SET ### @1=1 /* INT meta=0 nullable=1 is_null=0 */ ... When master sends Annotate rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 1. Master always sends Annotate_rows events to mysqlbinlog (in remote case). 2. Master sends Annotate_rows events to a slave only if the slave has both log-slave-updates and binlog-annotate-row-events options set. LOW-LEVEL DESIGN: mysql_binlog_send() [sql/sql_repl.cc] ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 1. When sending events to a slave, master should simply skip Annotate_rows events (they are not needed for replication). [ ??? Multi-master - currently not clear ] 2. When sending events to mysqlbinlog (remote case), master must send Annotate_rows events as well. ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)