Environment: RHEL 7、MySQL 5.7.31、MEB 4.1.4
Symptom：Although the online mysqlbackup successfully, but in fact some datafiles were corrupted！
So I have the two following questions about this phenomenon:
- Why the procdure and result of the mysqlbackup were all normal and successful？
- Why such phenomenon is random and unexpected, even happened in the same DB！
201207 19:01:13 RDR1 INFO: Completed the copy of binlog files...
201207 19:01:13 RDR1 INFO: Opening backup source directory '/app/mysql/13306/data'
201207 19:01:13 RDR1 INFO: Starting to backup all non-innodb files in
subdirectories of '/app/mysql/13306/data'
201207 19:01:13 WTR1 INFO: Adding database directory: datadir/lyl_nbudb
201207 19:01:13 WTR1 INFO: Adding database directory: datadir/memory_db_test
201207 19:01:13 WTR1 INFO: Adding database directory: datadir/mysql
201207 19:01:15 WTR1 INFO: Adding database directory: datadir/performance_schema
201207 19:01:15 WTR1 INFO: Adding database directory: datadir/s6000test
201207 19:01:22 WTR1 INFO: Adding database directory: datadir/sbtest
201207 19:01:22 WTR1 INFO: Adding database directory: datadir/sys
201207 19:01:24 RDR1 INFO: Completing the copy of all non-innodb files.
201207 19:01:24 RDR1 INFO: Requesting completion of redo log copy. Rapid: 0
201207 19:01:24 RLR1 INFO: Signaled '1' to complete log copy.
201207 19:01:24 RLR1 INFO: Signaled '1' to complete log copy.
201207 19:01:24 RLR1 INFO: Signaled '1' to complete log copy.
201207 19:01:24 RLR1 INFO: Redo log reader waited = 620270.00 ms for logs to generate.
201207 19:01:24 RLW1 INFO: A copied database page was modified at 13814514863.
(This is the highest lsn found on page)
Scanned log up to lsn 13814515144.
Was able to parse the log up to lsn 13814515144.
201207 19:01:25 RDR1 INFO: All tables unlocked
201207 19:01:25 RDR1 INFO: All MySQL tables were locked for 22.277 seconds.
201207 19:01:25 RDR1 INFO: Setting server system variable 'old_alter_table' back to '0'.
201207 19:01:25 RDR1 INFO: Reading all global variables from the server.
201207 19:01:25 RDR1 INFO: Completed reading of all global variables from the server.
201207 19:01:25 RDR1 INFO: Writing config file for server '5.7.31-log'.
201207 19:01:25 RDR1 INFO: Creating server config files server-my.cnf and server-all.cnf in /data/meb_bak/2020-12-07_18-50-54
201207 19:01:25 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/meta/backup_variables.txt.
201207 19:01:25 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/datadir/ibbackup_logfile.
201207 19:01:25 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/server-all.cnf.
201207 19:01:25 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/server-my.cnf.
201207 19:01:25 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/meta/backup_gtid_executed.sql.
201207 19:01:25 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/meta/backup_content.xml.
201207 19:01:26 RDR1 INFO: Copying meta file /data/meb_bak/2020-12-07_18-50-54/meta/image_files.xml.
201207 19:01:26 MAIN INFO: Full Image Backup operation completed successfully.
201207 19:01:26 MAIN INFO: Backup image created successfully.
201207 19:01:26 MAIN INFO: Image Path = /data/meb_bak/2020-12-07_18-50-54/app2_full_backup.mebimg
201207 19:01:26 MAIN INFO: MySQL binlog position: filename mysql13306-bin.000001, position 259327026
201207 19:01:26 MAIN INFO: GTID_EXECUTED is 7560c4f1-e6ab-11ea-bf0b-fa163e4713f6:1-114441
-------------------------------------------------------------
Parameters Summary
-------------------------------------------------------------
Start LSN : 13814514688
End LSN : 13814515144
-------------------------------------------------------------
mysqlbackup completed OK!
-bash-4.2$
-bash-4.2$
IMPORTANT: Please check that mysqlbackup run completes successfully.
At the end of a successful 'validate' run mysqlbackup
prints "mysqlbackup completed OK!".
201216 10:47:32 MAIN INFO: Backup Image MEB version string: 4.1.4 [2020/01/21 11:31:37]
201216 10:47:32 MAIN INFO: MySQL server version is '5.7.31'
201216 10:47:32 MAIN INFO: TDE Keyring service initialized.
201216 10:47:32 MAIN INFO: Creating 14 buffers each of size 16777216.
201216 10:47:32 MAIN INFO: Validate operation starts with following threads
1 read-threads 6 process-threads
201216 10:47:32 MAIN INFO: Validating image ... /data/meb_bak/2020-12-07_18-50-54/app2_full_backup.mebimg
201216 10:47:32 PCR1 INFO: A thread created with Id '140132717340416'
201216 10:47:32 PCR4 INFO: A thread created with Id '140132700555008'
201216 10:47:32 RDR1 INFO: A thread created with Id '140132725733120'
201216 10:47:32 PCR1 INFO: Validate: [Dir]: meta
201216 10:47:32 PCR5 INFO: A thread created with Id '140132692162304'
201216 10:47:32 PCR6 INFO: A thread created with Id '140132683769600'
201216 10:47:32 PCR3 INFO: A thread created with Id '140132566337280'
201216 10:47:32 PCR2 INFO: A thread created with Id '140132708947712'
201216 10:47:35 PCR4 INFO: Validate: [Dir]: datadir/lyl_nbudb
201216 10:47:35 PCR4 INFO: Validate: [Dir]: datadir/memory_db_test
201216 10:47:35 PCR6 INFO: Validate: [Dir]: datadir/mysql
201216 10:47:35 PCR3 INFO: Validate: [Dir]: datadir/performance_schema
201216 10:47:35 PCR3 INFO: Validate: [Dir]: datadir/s6000test
201216 10:47:37 RDR1 Progress in MB: 200 400
201216 10:47:44 PCR5 INFO: Validate: [Dir]: datadir/sbtest
201216 10:47:47 RDR1 Progress in MB: 600 800 1000
201216 10:47:57 PCR5 ERROR: datadir/sbtest/sbtest1.ibd has corrupt data file page 43008 page number from page header: 0
201216 10:47:58 RDR1 Progress in MB: 1200 1400 1600
201216 10:48:09 PCR3 ERROR: Checksum mis-match found on the file datadir/sbtest/sbtest1.ibd.
mysqlbackup failed with errors!
-bash-4.2$
-bash-4.2$