Bug #76046 MEB exits with completly wrong error message
Submitted: 25 Feb 2015 12:44 Modified: 26 Feb 2015 7:57
Reporter: Oli Sennhauser Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Enterprise Backup Severity:S3 (Non-critical)
Version:3.11.1 OS:Linux (ubuntu 14.04)
Assigned to: CPU Architecture:Any
Tags: Enterprise Backup, error message, log file, meb

[25 Feb 2015 12:44] Oli Sennhauser
Description:
MySQL Enterprise Backup terminates with wrong and unusable error message:

write(2, " mysqlbackup: ERROR: Error while"..., 107 mysqlbackup: ERROR: Error while getting current log file from server in initialization for online backup.) = 107

How to repeat:
Slave was stopped and SHOW SLAVE STATUS did not show any information. Bug on datadir there was still some relay-log stuff (files and index) from earlier tests

These confused MEB and lead to wrong error message:

ptrace ./mysqlbackup --defaults-file=$datadir/my.cnf --user=root --backup-dir=/tmp/backup/full backup

...
write(2, "150225 13:29:26 mysqlbackup: INF"..., 72150225 13:29:26 mysqlbackup: INFO: Starting to copy all innodb files...) = 72
sendto(3, "\36\0\0\0\3SELECT @@GLOBAL.log_bin_ind"..., 34, 0, NULL, 0) = 34
recvfrom(3, "\1\0\0\1\1,\0\0\2\3def\0\0\0\26@@GLOBAL.log_bi"..., 16384, 0, NULL, NULL) = 121
sendto(3, " \0\0\0\3SELECT @@GLOBAL.relay_log_i"..., 36, 0, NULL, 0) = 36
recvfrom(3, "\1\0\0\1\1.\0\0\2\3def\0\0\0\30@@GLOBAL.relay_"..., 16384, 0, NULL, NULL) = 78

| relay_log_index           |                |
| relay_log_info_file       | relay-log.info |
| relay_log_info_repository | FILE           |

uname({sys="Linux", node="laptop4", ...}) = 0
stat("/home/mysql/data/mysql-5.6.22//laptop4-relay-bin.index", {st_mode=S_IFREG|0660, st_size=189, ...}) = 0
open("/home/mysql/data/mysql-5.6.22//laptop4-relay-bin.index", O_RDONLY) = 6
sendto(3, "\1\0\0\0\16", 5, 0, NULL, 0) = 5
recvfrom(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384, 0, NULL, NULL) = 11
sendto(3, "\22\0\0\0\3SHOW SLAVE STATUS", 22, 0, NULL, 0) = 22

root@localhost [(none)]> show slave status\G
Empty set (0.00 sec)

recvfrom(3, "\1\0\0\0016$\0\0\2\3def\0\0\0\16Slave_IO_State\0"..., 16384, 0, NULL, NULL) = 2315
write(2, " mysqlbackup: ERROR: Error while"..., 107 mysqlbackup: ERROR: Error while getting current log file from server in initialization for online backup.) = 107

This did NOT help:

show slave status\G
reset slave;

With this sequence the problem was solved:

  601  ll relay-log.info 
  602  cat relay-log.info 
  603  ll laptop4-relay-bin.*
  609  stop
  610  rm -rf laptop4-relay-bin.*
  613  start

Suggested fix:
do proper error messages
[25 Feb 2015 12:45] Oli Sennhauser
Found the original error message without trace:

150225 13:12:47 mysqlbackup: INFO: Starting to copy all innodb files...
 mysqlbackup: ERROR: Error while getting current log file from server in initialization for online backup.
mysqlbackup failed with errors!
[26 Feb 2015 7:57] MySQL Verification Team
Hello Oli Sennhauser,

Thank you for the report.
This is most likely duplicate of Bug #75074, please see Bug #75074 for more details.

Thanks,
Umesh