MySQL Bugs: #18337: mysqlbinlog not displaying BINLOG statements when called with --short-form

Bug #18337	mysqlbinlog not displaying BINLOG statements when called with --short-form
Submitted:	18 Mar 2006 21:55	Modified:	16 Nov 2017 7:47
Reporter:	Giuseppe Maxia	Email Updates:
Status:	Won't fix	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.1.7,5.1.8	OS:	Linux (Linux)
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	Contribution

Description:
When using row-based replication, mysqlbinlog does not display BINLOG commands if invoked with --short-form option

How to repeat:
use test;
reset master;
drop table if exists t2;
create table t2 (i int, c char(10));
SET binlog_format = 'ROW';
insert into t2 values (1,'abc');
flush logs;
exit;

$ mysqlbinlog --short-form mysql-bin-000001 

Suggested fix:
waiting for a bugfix, either don't use the -s option, or filter mysqlbinlog's output. 
e.g.:
$ mysqlbinlog --short-form mysql-bin-000001  | perl -ne 'print unless /^#/'

===== log_event.cc 1.268 vs edited =====
--- 1.268/sql/log_event.cc      
+++ edited/log_event.cc 
@@ -750,7 +750,6 @@
   LOG_EVENT_MINIMAL_HEADER_LEN (we just want to read the event's length).

 */
-
 int Log_event::read_log_event(IO_CACHE* file, String* packet,
                              pthread_mutex_t* log_lock)
 {
@@ -6409,15 +6408,15 @@
 {
   IO_CACHE *const head= &print_event_info->head_cache;
   IO_CACHE *const body= &print_event_info->body_cache;
+  bool const last_stmt_event= get_flags(STMT_END_F);
   if (!print_event_info->short_form)
   {
-    bool const last_stmt_event= get_flags(STMT_END_F);
     print_header(head, print_event_info, !last_stmt_event);
     my_b_printf(head, "\t%s: table id %lu\n", name, m_table_id);
-    print_base64(body, print_event_info, !last_stmt_event);
   }
+  print_base64(body, print_event_info, !last_stmt_event);

-  if (get_flags(STMT_END_F))
+  if (last_stmt_event)
   {
     copy_event_cache_to_file_and_reinit(head, file);
     copy_event_cache_to_file_and_reinit(body, file);

I moved the "print_base64 ..." out of the "short_form" condition.It can work,but it hardly to know the accurate log's meanings with "--short-form" option in mysqlbinlog.More other ,in row base binlog_format like "insert into t1 select * from t2" statement will create very long log messages.

From: 	  terry.tao@greatopensource.com
	Subject: 	[PATCH]  for Bug #18337
	Date: 	29 October 2007 05:37:44 GMT-04:00
	To: 	  internals@lists.mysql.com

===== log_event.cc 1.307 vs edited =====
--- 1.307/sql/log_event.cc      2007-10-29 17:15:03 +08:00
+++ edited/log_event.cc 2007-10-29 17:14:48 +08:00
@@ -6427,17 +6427,18 @@
{
  IO_CACHE *const head= &print_event_info->head_cache;
  IO_CACHE *const body= &print_event_info->body_cache;
+
+  bool const last_stmt_event= get_flags(STMT_END_F);
  if (!print_event_info->short_form)
  {
-    bool const last_stmt_event= get_flags(STMT_END_F);
    print_header(head, print_event_info, !last_stmt_event);
    my_b_printf(head, "\t%s: table id %lu%s\n",
                name, m_table_id,
                last_stmt_event ? " flags: STMT_END_F" : "");
-    print_base64(body, print_event_info, !last_stmt_event);
  }
+  print_base64(body, print_event_info, !last_stmt_event);

-  if (get_flags(STMT_END_F))
+  if (last_stmt_event)
  {
    copy_event_cache_to_file_and_reinit(head, file);
    copy_event_cache_to_file_and_reinit(body, file);
@@ -6954,8 +6955,8 @@
    my_b_printf(&print_event_info->head_cache,
                "\tTable_map: `%s`.`%s` mapped to number %lu\n",
                m_dbnam, m_tblnam, m_table_id);
-    print_base64(&print_event_info->body_cache, print_event_info, TRUE);
  }
+  print_base64(&print_event_info->body_cache, print_event_info, TRUE);
}
#endif

the patch is for http://bugs.mysql.com/bug.php?id=18337.

moved the code "print_base64( ..." out of the "short_form" condition in Rows_log_event::print_helper() and Table_map_log_event::print(). It can work,but it hardly to know the accurate meanings with "--short-form" option in mysqlbinlog. Furthermore in row base binlog_format, like "insert into t1 select * from t2" statement will create very long log messages,it conflicts with the short-form's meanings.

the result:
create table t1(a int);
insert into t1 values(1);
set binlog_format = 'row';
insert into t1 values(2),(3);

$ mysqlbinlog mysql-bin-000001 # at 192
#071029 15:35:26 server id 1  end_log_pos 277   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1193643326/*!*/;
create table t1(a int)/*!*/;
# at 277
#071029 15:35:26 server id 1  end_log_pos 364   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1193643326/*!*/;
insert into t1 values(1)/*!*/;
# at 364
# at 405
#071029 15:35:26 server id 1  end_log_pos 405   Table_map: `test`.`t1` mapped to number 16
#071029 15:35:26 server id 1  end_log_pos 444   Write_rows: table id 16 flags: STMT_END_F

BINLOG '
Po0lRxMBAAAAKQAAAJUBAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
Po0lRxcBAAAAJwAAALwBAAAQABAAAAAAAAEAAf/+AgAAAP4DAAAA
'/*!*/;
DELIMITER ;

$ mysqlbinlog --short-form mysql-bin-000001

create table t1(a int)/*!*/;
SET TIMESTAMP=1193643326/*!*/;
insert into t1 values(1)/*!*/;

BINLOG '
Po0lRxMBAAAAKQAAAJUBAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
Po0lRxcBAAAAJwAAALwBAAAQABAAAAAAAAEAAf/+AgAAAP4DAAAA
'/*!*/;

DELIMITER ;

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/41183

ChangeSet@1.2508, 2008-01-23 19:01:13-05:00, cmiller@zippy.cornsilk.net +4 -0
  Bug#18337: mysqlbinlog not displaying BINLOG statements when called \
  	with --short-form
  
  Bug fix contributed by Terry Tao.  No CLA needed for this size.
  
  The code to print BINLOG data should be outside the test for 
  whether we are asking for the short-form.

On Thu, Feb 14, 2008 at 07:25:43PM +0200, Andrei Elkin wrote 
(edited by Lars):
> It appeared (to Sven, whom I discussed with, and me) that BINLOG
> statements should not be displayed with the option.
>
> The option is defined [8.11 `mysqlbinlog' -- Utility for Processing
> Binary Log Files]
>
>    *  `--short-form', `-s'
>
>      Display only the statements contained in the log, without any
>      extra information.
>
> However, de-facto its aim has been to provide deterministic
> output from mysqlbinlog when invoced by mysql-test program.
>
> BINLOG can contain results of calculation of non-deterministic
> functions.
>
> In my opinion the problem of this bug is actually a misleading name
> of the option.

SUGGESTED SOLUTION:
A) Change the documentation:
   1) to reflect that this option is used only to get deterministic
      output from mysqlbinlog.
   2) explicitly state in documentation that row-based events are
      *not* included in the output.
B) Do not change the source code, unless someone has a very good use
   case for it.

I don't see any usefulness of having mysqlbinlog output depleted of some queries. Since binlog_format is a session variable, there can be row-based queries everywhere.
The purpose of "short-form" should be to print only the queries, skipping comments. Since row-based queries can be sent to the server like any other query, they should be in mysqlbinlog output.
IMO, either the "short-form" option does what the user expects, or it should be removed altogether.
If anyone has a need for a crippled list of queries, then a separate option should be introduced.

I think we should output the BINLOG statement as well,  when we use SBR, the output of --short-form will be enough to replay the changes in the binlog file,  if we don't output BINLOG statement, we can not do this when using RBR, which is not consistent. 

The defacto aim of option --short-form is a misuse of this option, if we do need this behaviour, we could add another option --ignore-binlog or something like this, then the combination of --short-form and --ignore-binlog will do what --short-form currently do.

Posted by developer:

[19 Sep 2017 15:25] Luis Soares 

--short-form is deprecated in 8.0. Closing as won't fix.