Bug #16765 SHOW BINLOG EVENTS output differs between server versions
Submitted: 25 Jan 2006 2:00 Modified: 26 Jan 2006 0:50
Reporter: Hartmut Holzgraefe Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:4.1, 5.0 OS:Linux (linux)
Assigned to: Guilhem Bichot CPU Architecture:Any

[25 Jan 2006 2:00] Hartmut Holzgraefe
Description:
SHOW BINLOG EVENTS output differs between server versions
although no such change seems to be listed in the changelogs?

How to repeat:
mysql-5.0> show binlog events in 'linux-bin.000002' from 207 limit 1\G
*************************** 1. row ***************************
Log_name: linux-bin.000002
Pos: 207
Event_type: Query
Server_id: 1
End_log_pos: 299
Info: use `test`; insert into t select * from i

mysql-4.1>  show binlog events in 'linux-bin.000002' from 207 limit 1\G
*************************** 1. row ***************************
Log_name: linux-bin.000002
Pos: 207
Event_type: Query
Server_id: 1
Orig_log_pos: 299
Info: use `test`; insert into t select * from i

Suggested fix:
Looks as if just the column name changed from Orig_log_pos to End_log_pos,
so it is maybe just a documentation issue?
[25 Jan 2006 13:45] Valeriy Kravchuk
Thank you for a bug report. Verified just as described with latest -BK builds of both 5.0.x and 4.1.x:

[openxs@Fedora 5.0]$ bin/mysqld_safe --log-bin &
[1] 32278
[openxs@Fedora 5.0]$ Starting mysqld daemon with databases from /home/openxs/dbs/5.0/var

[openxs@Fedora 5.0]$ bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 5.0.19-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> insert into test select * from test;
ERROR 1062 (23000): Duplicate entry '1' for key 1

mysql> show binlog events in 'Fedora-bin.000001' from 1 limit 1\G
*************************** 1. row ***************************
   Log_name: Fedora-bin.000001
        Pos: 4
 Event_type: Format_desc
  Server_id: 1
End_log_pos: 98
       Info: Server ver: 5.0.19-log, Binlog ver: 4
1 row in set (0.00 sec)

But in 4.1:

[openxs@Fedora 5.0]$ cd ../4.1/
[openxs@Fedora 4.1]$ bin/mysqld_safe --log-bin &
[1] 32372
[openxs@Fedora 4.1]$ Starting mysqld daemon with databases from /home/openxs/dbs/4.1/var

[openxs@Fedora 4.1]$ bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 4.1.18-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> insert into test select * from test;
Query OK, 1 row affected (0.02 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> show binlog events in 'Fedora-bin.000002' from 1 limit 1\G
*************************** 1. row ***************************
    Log_name: Fedora-bin.000002
         Pos: 4
  Event_type: Start
   Server_id: 1
Orig_log_pos: 4
        Info: Server ver: 4.1.18-log, Binlog ver: 3
1 row in set (0.00 sec)

So, it is End_log_pos in 5.0.x and Orig_logPos in 4.1.x in the output.
[25 Jan 2006 13:58] Guilhem Bichot
In 4.0 (since 4.0.15) and in 4.1 (since 4.1.1), Orig_log_pos means "the offset of the first byte of the event, in this server's binary log". In 5.0 (since 5.0.0), this is replaced by End_log_pos, "the offset of the last byte of the event, in this server's binary log, plus 1".
See, in your example:
mysql-5.0> show binlog events in 'linux-bin.000002' from 207 limit 1\G
*************************** 1. row ***************************
Log_name: linux-bin.000002
Pos: 207
Event_type: Query
Server_id: 1
End_log_pos: 299
Info: use `test`; insert into t select * from i
the event starts at 207 and ends at 299.
In your example of 4.1, however, I don't understand why Orig_log_pos is 299. I would expect it to be 207. Question: which version generated the binlog used by the two examples (I guess it's the same binlog, or it would be real luck that the same event comes at position 207 in both versions).
[25 Jan 2006 19:52] Guilhem Bichot
Hello Docs team,
Could you please write in the manual (changelog?) that starting from MySQL 5.0.0,
in SHOW BINLOG EVENTS, the column Orig_log_pos, which was, in 4.0 (>=4.0.15) and 4.1 (>=4.1.1) "the offset of the first byte of the event, in this server's binary log", has been renamed to End_log_pos and changed to "the offset of the last byte of the event, in this server's binary log, plus 1" ?
[26 Jan 2006 0:50] Mike Hillyer
Added to the 5.0.0 functionality change section:

<listitem>
        <para>
          The output of the <literal>SHOW BINLOG EVENTS</literal>
          statement has been modified. The
          <literal>Orig_log_pos</literal> column has been renamed to
          <literal>End_log_pos</literal> and now represents the offset
          of the last byte of the event, plus one.
        </para>
      </listitem>