MySQL Bugs: #75875: Mysqlbackup checksum error

Bug #75875	Mysqlbackup checksum error
Submitted:	12 Feb 2015 10:23	Modified:	14 Aug 2015 12:50
Reporter:	Anton V	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Enterprise Backup	Severity:	S2 (Serious)
Version:	3.11.1	OS:	Linux
Assigned to:		CPU Architecture:	Any

Description:
Description:
During creation of incremental backup using mysqlbackup and backup-to-image option
Last binary log is created with an error check sum "Checksum mis-match"
(We are uploading images to remote server using Symantec Netbackup)

mysqlbackup: ERROR: Checksum mis-match found on the file datadir/binary.000026.
mysqlbackup failed with errors!

This backup can not be restored, while at the creation is successful
Error can be traced only during test with the validate option
The error related only to incremental backup

In short log below you can see how error is reproduced 
But I've cut some data from log (it was too large ), full log you can find in attach

Mon Feb  9 04:56:38 MSK 2015
MySQL Enterprise Backup version 3.11.1 Linux-2.6.39-400.17.1.el6uek.x86_64-x86_64 [2014/11/04] 
Copyright (c) 2003, 2014, Oracle and/or its affiliates. All Rights Reserved.

 mysqlbackup: INFO: Starting with following command line ...
 /opt/mysql/meb-3.11/bin/mysqlbackup --login-path=backup --user=backup 
        --incremental 
        --incremental-base=dir:/swdb/netbackup/last_incr_backup_prev.meta 
        --protocol=socket --socket=/var/lib/mysql/mysql.sock 
        --backup-image=sbt:INCR.2015.02.09-04:56 
        --sbt-lib-path=/usr/openv/netbackup/bin/libobk.so64 
        --sbt-environment=                 NB_ORA_SERV=vm-nbmas-01.dc.company.ru,                 NB_ORA_CLIENT=dc02-app-swdb-backup.dc.company.ru,                 NB_ORA_POLICY=dc02_mysql_swdb,                 ORACLE_HOME=/swdb/mysql          
        --incremental-backup-dir=/swdb/netbackup/last_incr_backup.meta 
        --backup-dir=/swdb/netbackup/tmp --skip-relaylog backup-to-image 

 mysqlbackup: INFO: 
 mysqlbackup: INFO: MySQL server version is '5.6.21-enterprise-commercial-advanced-log'.
 mysqlbackup: INFO: Got some server configuration information from running server.

 mysqlbackup: INFO: sbt-environment: '                 NB_ORA_SERV=vm-nbmas-01.dc.company.ru,                 NB_ORA_CLIENT=dc02-app-swdb-backup.dc.company.ru,                 NB_ORA_POLICY=dc02_mysql_swdb,                 ORACLE_HOME=/swdb/mysql         '
IMPORTANT: Please check that mysqlbackup run completes successfully.
           At the end of a successful 'backup-to-image' run mysqlbackup
           prints "mysqlbackup completed OK!".

150209 04:56:38 mysqlbackup: INFO: MEB logfile created at /swdb/netbackup/tmp/meta/MEB_2015-02-09.04-56-38_inc_img_backup.log

150209 04:56:38 mysqlbackup: INFO: Using start_lsn=12293477805, calculated from backup_variables.txt file of incremental-base backup.
--------------------------------------------------------------------
                       Server Repository Options:
--------------------------------------------------------------------
  datadir = /swdb/mysql/
  innodb_data_home_dir = 
  innodb_data_file_path = ibdata1:12M:autoextend
  innodb_log_group_home_dir = /swdb/mysql/
  innodb_log_files_in_group = 2
  innodb_log_file_size = 536870912
  innodb_page_size = 16384
  innodb_checksum_algorithm = innodb
  innodb_undo_directory = /swdb/mysql/
  innodb_undo_tablespaces = 0
  innodb_undo_logs = 128

--------------------------------------------------------------------
                       Backup Config Options:
--------------------------------------------------------------------
  datadir = /swdb/netbackup/tmp/datadir
  innodb_data_home_dir = /swdb/netbackup/tmp/datadir
  innodb_data_file_path = ibdata1:12M:autoextend
  innodb_log_group_home_dir = /swdb/netbackup/tmp/datadir
  innodb_log_files_in_group = 2
  innodb_log_file_size = 536870912
  innodb_page_size = 16384
  innodb_checksum_algorithm = innodb
  innodb_undo_directory = /swdb/netbackup/tmp/datadir
  innodb_undo_tablespaces = 0
  innodb_undo_logs = 128

Backup Image Path = INCR.2015.02.09-04:56
...
150209 04:56:55 mysqlbackup: INFO: MySQL binlog position: filename binary.000026, position 44653040

-------------------------------------------------------------
   Parameters Summary         
-------------------------------------------------------------
   Start LSN                  : 12293477806
   End LSN                    : 12294268834
-------------------------------------------------------------
mysqlbackup completed OK!

MySQL Enterprise Backup version 3.11.1 Linux-2.6.39-400.17.1.el6uek.x86_64-x86_64 [2014/11/04] 
Copyright (c) 2003, 2014, Oracle and/or its affiliates. All Rights Reserved.

 mysqlbackup: INFO: Starting with following command line ...
 /opt/mysql/meb-3.11/bin/mysqlbackup --protocol=socket 
        --socket=/var/lib/mysql/mysql.sock 
        --backup-image=sbt:INCR.2015.02.09-04:56 
        --sbt-lib-path=/usr/openv/netbackup/bin/libobk.so64 
        --sbt-environment=                 	NB_ORA_SERV=vm-nbmas-01.dc.company.ru,                 	NB_ORA_CLIENT=dc02-app-swdb-backup.dc.company.ru,                 	NB_ORA_POLICY=dc02_mysql_swdb,                 	ORACLE_HOME=/swdb/mysql         	 
        validate 
...
 150209 04:57:00 mysqlbackup: INFO: Validate: [Dir]: datadir/sys
 mysqlbackup: ERROR: Checksum mis-match found on the file datadir/binary.000026.

mysqlbackup failed with errors!

----------------------------------------------------------------

How to repeat:
Create  full backup with  backup-to-image
Add some changes to database to increase binary log size
Create incremental backup with  backup-to-image
Validate last incremental backup

Suggested fix:
I found a temporary solution, how to avoid this error
If before creating an incremental backup to reset the log (flush logs), then the backup and validation are successful.

I've changed severity to serious

Thank you for the report.

I cannot repeat described behavior. Do you perform load on server while taking incremental backup? Please send us your backup_content.xml file, then extract image and send output of:

ls -l binary.0000XX

And CRC32 of this log. You can do it with PHP, for example:

php -r 'var_dump(crc32(file_get_contents("datadir/binary.0000XX")));'

Hi Sveta , 

Thanks for the answer. 
I've the same situation, the error is reproduced not always , but often . 

Yep , database works during incremental backup and  load exists .

Pro:tmp anton$ cat meta/backup_content.xml | grep -i -n3 binary.000207
99-                    <file>
100:                        <name>datadir/binary.000207</name>
101-                        <size>30029681</size>
102-                        <check_sum>2660997968</check_sum>
103-                    </file>

Pro:tmp anton$ php -r 'var_dump(crc32(file_get_contents("datadir/binary.000207")));'
int(2660997968)

Pro:tmp anton$ ll datadir/binary.000207 
-rw-r--r--  1 anton  staff  30029681  3 мар 14:22 datadir/binary.000207

Hello, 

We are still getting the same error during incremental backup to image at different type of files .
I've attached maximum detailed log ( with trace 3 ) for the problem  is appeared at  innodb data file, myisam data file, binaly log . 
Please, check these files. 

The most frightfully that these backups are  finished successfully,  but this is impossible restore from these backups. And we  can find errors during validation only .

Backups were configured as recommended here
https://www.mysql.com/why-mysql/white-papers/mysql-enterprise-backup-and-symantec-netbackup/

The problem disappeared in MEB 3.12 version

Hello Anton,

Thank you for your feedback.

Thanks,
Chiranjeevi.