| Bug #50458 | Backup logs show wrong stop time when restore is performed. | ||
|---|---|---|---|
| Submitted: | 19 Jan 2010 21:36 | Modified: | 2 Mar 2010 2:18 |
| Reporter: | Hema Sridharan | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Backup | Severity: | S2 (Serious) |
| Version: | 5.6.0, 6.0.14 | OS: | Any |
| Assigned to: | Rafal Somla | CPU Architecture: | Any |
[19 Jan 2010 22:28]
Sveta Smirnova
Thank you for the report. Verified as described.
[21 Jan 2010 19:21]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/97771 2936 Rafal Somla 2010-01-21 Bug#50458 - Backup logs show wrong stop time when restore is performed. Due to error in the program logic, RESTORE operation reported in backup logs stop time read from backup image, that is the saved time of when BACKUP operation has ended. This patch fixes the logic so that stop time of RESTORE operation is reported instead. @ mysql-test/suite/backup/t/backup_logs.test - Ensure that RESTORE operation runs at least 1 second, so that stop time is bigger than start time. - Add check that stop time is bigger than start time. @ sql/backup/kernel.cc When reporting stop time to backup logs, take the time which is stored in m_catalog only in case of BACKUP operation. For RESTORE report the actual time when the operation has ended.
[22 Jan 2010 10:13]
Rafal Somla
Patch queued into mysql-6.0-backup tree. revid:rafal.somla@sun.com-20100121192059-4bysvwlc3sltg9q9
[20 Feb 2010 9:17]
Bugs System
Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100122221225-ccgkfpesvrttdlc1) (merge vers: 6.0.14-alpha) (pib:16)
[2 Mar 2010 2:18]
Paul DuBois
Noted in 6.0.14 changelog. The stop time for RESTORE operations was logged incorrectly.

Description: Create database, tables and load some data in tables. Execute backup and restore operations. Check the backup history logs for start time and stop time of backup and restore. You will notice that stop time is same for backup as well as restore. Therefore, start time for restore shows later time than stop time in backup logs. How to repeat: Create database db2; create table db2.t1(id int); Insert into db2.t1 values(1),(2),(3),(4); Backup database db2 to 'db2.bak'; Drop database db2; Restore from 'db2.bak'; Check the backup history logs for start and stop time. The logs show the same stop time for backup as well as restore. See below for an example. mysql> create database db; Query OK, 1 row affected (0.00 sec) mysql> use db; Database changed mysql> create table db.t1(id int); Query OK, 0 rows affected (0.04 sec) mysql> insert into db.t1 values(1),(2),(3),(4),(5); Query OK, 5 rows affected (0.00 sec) Records: 5 Duplicates: 0 Warnings: 0 mysql> backup database db to 'dba.bak'; +-----------+ | backup_id | +-----------+ | 276 | +-----------+ 1 row in set (0.49 sec) mysql> drop database db; Query OK, 1 row affected (0.00 sec) Perform restore after 1min mysql> restore from 'dba.bak'; +-----------+ | backup_id | +-----------+ | 277 | +-----------+ 1 row in set (0.06 sec) mysql> select * from mysql.backup_history\G *************************** 1. row *************************** backup_id: 276 process_id: 0 binlog_start_pos: 0 binlog_file: backup_state: complete operation: backup error_num: 0 num_objects: 2 total_bytes: 1617 validity_point_time: 2010-01-19 21:22:39 start_time: 2010-01-19 21:22:39 stop_time: 2010-01-19 21:22:39 host_or_server_name: localhost username: root backup_file: dba.bak ... .... *************************** 2. row *************************** backup_id: 277 process_id: 0 binlog_start_pos: 0 binlog_file: backup_state: complete operation: restore error_num: 0 num_objects: 2 total_bytes: 1617 validity_point_time: 2010-01-19 21:22:39 start_time: 2010-01-19 21:24:03 stop_time: 2010-01-19 21:22:39 ==> Restore has same stop_time as backup host_or_server_name: localhost username: root backup_file: dba.bak .. .. The above table shows that stop_time for both backup and restore are the same which is incorrect.