Selecting wrong pos with SHOW BINLOG EVENTS causes a potentially misleading message in the server error log
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
MySQL Server |
Unknown
|
Unknown
|
|||
Percona Server moved to https://jira.percona.com/projects/PS |
Fix Released
|
Medium
|
Sergei Glushchenko | ||
5.1 |
Won't Fix
|
Undecided
|
Unassigned | ||
5.5 |
Fix Released
|
Medium
|
Sergei Glushchenko | ||
5.6 |
Fix Released
|
Medium
|
Sergei Glushchenko |
Bug Description
While selecting wrong pos with SHOW BINLOG EVENTS, it fails and does give error to client and log to error log
mysql> show global variables like 'binlog_format%';
+------
| Variable_name | Value |
+------
| binlog_format | ROW |
+------
1 row in set (0.00 sec)
mysql> show global variables like 'max_allowed_
+------
| Variable_name | Value |
+------
| max_allowed_packet | 1073741824 |
+------
1 row in set (0.00 sec)
mysql> create table nil (id int, name varchar(10), city varchar(10), phone int);
Query OK, 0 rows affected (0.01 sec)
mysql> insert into nil values (1, 'nilnandan'
Query OK, 1 row affected, 1 warning (0.01 sec)
mysql> select * from nil;
+------
| id | name | city | phone |
+------
| 1 | nilnandan | ahmedabad | 2147483647 |
+------
1 row in set (0.00 sec)
mysql> insert into nil select * from nil;
Query OK, 1 row affected (0.01 sec)
Records: 1 Duplicates: 0 Warnings: 0
mysql> insert into nil select * from nil;
Query OK, 2 rows affected (0.00 sec)
Records: 2 Duplicates: 0 Warnings: 0
..
.
mysql> insert into nil select * from nil;
Query OK, 8388608 rows affected (37.83 sec)
Records: 8388608 Duplicates: 0 Warnings: 0
mysql> insert into nil select * from nil limit 2000000;
Query OK, 2000000 rows affected, 1 warning (8.36 sec)
Records: 2000000 Duplicates: 0 Warnings: 1
mysql> insert into nil select * from nil limit 2000000;
Query OK, 2000000 rows affected, 1 warning (7.66 sec)
Records: 2000000 Duplicates: 0 Warnings: 1
mysql> insert into nil select * from nil limit 3000000;
Query OK, 3000000 rows affected, 1 warning (11.86 sec)
Records: 3000000 Duplicates: 0 Warnings: 1
mysql> quit
Bye
nilnandan@
nilnandan@
total 1.4G
drwx------ 2 nilnandan nilnandan 4.0K Jan 12 13:58 ./
drwx------ 5 nilnandan nilnandan 4.0K Jan 12 13:54 ../
-rw-rw---- 1 nilnandan nilnandan 8.5K Jan 12 13:58 nil.frm
-rw-rw---- 1 nilnandan nilnandan 1.4G Jan 12 14:28 nil.ibd
nilnandan@
-- Create outfile to load the data
mysql> SELECT * INTO OUTFILE '/tmp/nil_
-> FIELDS TERMINATED BY ',' OPTIONALLY ENCLOSED BY '"'
-> LINES TERMINATED BY '\n'
-> FROM nil;
Query OK, 23777216 rows affected (20.00 sec)
nilnandan@
-rw-rw-rw- 1 nilnandan nilnandan 840M Jan 12 14:36 nil_table.txt
nilnandan@
-- Create new table and load the data
mysql> create table nil_new (id int, name varchar(10), city varchar(10), phone int);
Query OK, 0 rows affected (0.01 sec)
mysql> LOAD DATA INFILE '/tmp/nil_
-> INTO TABLE nil_new
-> FIELDS TERMINATED BY ',' OPTIONALLY ENCLOSED BY '"'
-> LINES TERMINATED BY '\n';
Query OK, 23777216 rows affected (1 min 34.75 sec)
Records: 23777216 Deleted: 0 Skipped: 0 Warnings: 0
mysql> show master status \G
*******
File: mysql-bin.000004
Position: 692490956
Binlog_Do_DB:
Binlog_Ignore_DB:
Executed_Gtid_Set: 2c827228-
1 row in set (0.00 sec)
mysql> SHOW BINLOG EVENTS IN 'mysql-bin.000004' FROM 692490800;
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error
mysql>
nilnandan@
2015-01-12 14:38:17 11087 [Note] InnoDB: Percona XtraDB (http://
2015-01-12 14:38:17 11087 [Note] RSA private key file not found: /home/nilnandan
2015-01-12 14:38:17 11087 [Note] RSA public key file not found: /home/nilnandan
2015-01-12 14:38:17 11087 [Note] Server hostname (bind-address): '127.0.0.1'; port: 20886
2015-01-12 14:38:17 11087 [Note] - '127.0.0.1' resolves to '127.0.0.1';
2015-01-12 14:38:17 11087 [Note] Server socket created on IP: '127.0.0.1'.
2015-01-12 14:38:17 11087 [Note] Event Scheduler: Loaded 0 events
2015-01-12 14:38:17 11087 [Note] /home/nilnandan
Version: '5.6.21-70.1-log' socket: '/tmp/mysql_
2015-01-12 14:45:49 11087 [ERROR] Error in Log_event:
summary: |
- SHOW BINLOG EVENTS fails if binlog has event size of close or more than + SHOW BINLOG EVENTS fails if binlog has event size of more than max_allowed_packet |
tags: | added: i49776 |
tags: | added: upstream |
summary: |
- SHOW BINLOG EVENTS fails if binlog has event size of more than - max_allowed_packet + While selecting wrong pos with SHOW BINLOG EVENTS, it fails and does + give error to client and log to error log: |
summary: |
While selecting wrong pos with SHOW BINLOG EVENTS, it fails and does - give error to client and log to error log: + give error to client and log to error log |
summary: |
- While selecting wrong pos with SHOW BINLOG EVENTS, it fails and does - give error to client and log to error log + Selecting wrong pos with SHOW BINLOG EVENTS causes a potentially + misleading message in the error log |
summary: |
Selecting wrong pos with SHOW BINLOG EVENTS causes a potentially - misleading message in the error log + misleading message in the server error log |
Yet another simple way to reproduce these scary messages (with nonsense even type) in the error log is like this:
[openxs@centos bzr2]$ mysql -uroot -P3314 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 4
Server version: 5.6.22-71.0-log Percona Server (GPL), Release 71.0, Revision 726
Copyright (c) 2009-2014 Percona LLC and/or its affiliates
Copyright (c) 2000, 2014, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> show master status; ------- ------+ ------- ---+--- ------- ----+-- ------- ------- --+---- ------- ------- -+ ------- ------+ ------- ---+--- ------- ----+-- ------- ------- --+---- ------- ------- -+ ------- ------+ ------- ---+--- ------- ----+-- ------- ------- --+---- ------- ------- -+
+------
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------
| centos-bin.000022 | 4271 | | | |
+------
1 row in set (0.00 sec)
mysql> show binlog events in 'centos-bin.000022' from 117;
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error
mysql> exit
Bye
[openxs@centos bzr2]$ su
Password:
[root@centos bzr2]# tail /var/log/mysqld.log
...
2015-01-13 12:47:52 2721 [ERROR] Error in Log_event: :read_log_ event() : 'Event too big', data_len: 1744830464, event_type: -36
So, whenever one uses some "wrong" offset this statement writes to the error log, while the error is just in one statement and replication continues to work.