← Back to team overview

maria-developers team mailing list archive

  1. maria-developers team
  2. Mailing list archive
  3. Message #01588

Updated (by Alexi): Store in binlog text of statements that caused RBR events (47)

  Thread Previous • Date Previous • • Thread Next 
-----------------------------------------------------------------------
                              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 - 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. 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 */
  ...


ESTIMATED WORK TIME

ESTIMATED COMPLETION DATE
-----------------------------------------------------------------------
WorkLog (v3.5.9)
  Thread Previous • Date Previous • • Thread Next