On Tuesday 23 December 2008 12:00:13 Ulrich Leodolter wrote: > Hello, > > I am running the very latest svn version 2.5.26 (21 December 2008). > > Today i tried to restore full copy job from tape. > Restore job finished OK, but took very long time. > After a few minutes disk write activity was done, > but tape read was active at 75MB/s for 1h52min. > Bacula reads the whole tape (496.6GB). > I would expect bacula to stop reading tape after > tape file 4 (see JobMedia entries below) > > ( 496GB * 1024 ) / (75MB/s) = 6772 seconds = 1 hour 52 min > > Maybe this is related to latest changes in match_bsr.c.
This is possible because we were concentrating mostly on disk restore, but I suspect it is due to the previous code (see below). > > Restore was done by selecting jobid 10086. > Below are job, media and restore log infos. There are still a few conditions under which Bacula could read the full Volume. Could you send us the bootstrap file that was produced? You can do so by re-running the restore command, then when it asks: yes/mod/no? Copy or list the bootstrap file (the location is printed just above) and then answer "no" unless you really want to re-do the restore. > > Regards > Ulrich > > > mysql> select * from Job where JobId=10086 \G > *************************** 1. row *************************** > JobId: 10086 > Job: Backup-leodolter.2008-12-22_08.01.50.57 > Name: Backup-leodolter > Type: C > Level: F > ClientId: 3 > JobStatus: T > SchedTime: 2008-12-22 08:01:50 > StartTime: 2008-12-21 22:05:00 > EndTime: 2008-12-21 22:32:41 > RealEndTime: 2008-12-22 08:04:04 > JobTDate: 1229895161 > VolSessionId: 30 > VolSessionTime: 1229852609 > JobFiles: 208346 > JobBytes: 4546422690 > JobErrors: 0 > JobMissingFiles: 0 > PoolId: 4 > FileSetId: 9 > PriorJobId: 10056 > PurgedFiles: 0 > HasBase: 0 > 1 row in set (0.00 sec) > > > mysql> select * from JobMedia where JobId=10086 order by VolIndex; > +------------+-------+---------+------------+-----------+-----------+------ >---+------------+----------+----------+------+--------+ > > | JobMediaId | JobId | MediaId | FirstIndex | LastIndex | StartFile | > | EndFile | StartBlock | EndBlock | VolIndex | Copy | Stripe | > > +------------+-------+---------+------------+-----------+-----------+------ >---+------------+----------+----------+------+--------+ > > | 40364 | 10086 | 556 | 1 | 77667 | 0 | > | 0 | 1 | 15499 | 1 | 0 | 0 | 40365 | 10086 | > | 556 | 77667 | 207239 | 1 | 1 | 0 | > | 15499 | 2 | 0 | 0 | 40366 | 10086 | 556 | 207239 | > | 207626 | 2 | 2 | 0 | 15499 | 3 | 0 > | | 0 | 40367 | 10086 | 556 | 207626 | 207694 | 3 | > | 3 | 0 | 15499 | 4 | 0 | 0 | 40368 | > | 10086 | 556 | 207694 | 208346 | 4 | 4 | > | 0 | 8632 | 5 | 0 | 0 | > > +------------+-------+---------+------------+-----------+-----------+------ >---+------------+----------+----------+------+--------+ > > > mysql> select * from Media where MediaId=556 \G > *************************** 1. row *************************** > MediaId: 556 > VolumeName: BACU.003 > Slot: 22 > PoolId: 4 > MediaType: LTO-4 > MediaTypeId: 0 > LabelType: 0 > FirstWritten: 2008-12-22 08:01:50 > LastWritten: 2008-12-23 08:44:24 > LabelDate: 2008-12-22 08:01:50 > VolJobs: 45 > VolFiles: 531 > VolBlocks: 7815542 > VolMounts: 2 > VolBytes: 504196310016 > VolParts: 0 > VolErrors: 0 > VolWrites: 7815543 > VolCapacityBytes: 0 > VolStatus: Append > Enabled: 1 > Recycle: 1 > VolRetention: 15552000 > VolUseDuration: 604800 > MaxVolJobs: 0 > MaxVolFiles: 0 > MaxVolBytes: 0 > InChanger: 1 > StorageId: 2 > DeviceId: 0 > MediaAddressing: 0 > VolReadTime: 4467440271 > VolWriteTime: 1527164013 > EndFile: 530 > EndBlock: 243 > LocationId: 0 > RecycleCount: 0 > InitialWrite: 0000-00-00 00:00:00 > ScratchPoolId: 0 > RecyclePoolId: 0 > Comment: NULL > 1 row in set (0.01 sec) > > > 23-Dec 09:36 troll-dir JobId 10203: Start Restore Job > RestoreFiles.2008-12-23_09.36.55.24 > 23-Dec 09:42 troll-dir JobId 10203: Using Device "Drive-2" > 23-Dec 09:43 troll-sd JobId 10203: Ready to read from volume "BACU.003" > on device "Drive-2" (/dev/nst1). > 23-Dec 09:43 troll-sd JobId 10203: Forward spacing Volume "BACU.003" to > file:block 0:1. > 23-Dec 11:30 troll-sd JobId 10203: Alert: TapeAlert: OK > 23-Dec 11:30 troll-dir JobId 10203: Bacula troll-dir 2.5.26 (21Dec08): > 23-Dec-2008 11:30:30 > Build OS: i686-pc-linux-gnu redhat Enterprise release > JobId: 10203 > Job: RestoreFiles.2008-12-23_09.36.55.24 > Restore Client: troll-fd > Start time: 23-Dec-2008 09:36:57 > End time: 23-Dec-2008 11:30:30 > Files Expected: 208,344 > Files Restored: 208,344 > Bytes Restored: 7,184,419,981 > Rate: 1054.5 KB/s > FD Errors: 0 > FD termination status: OK > SD termination status: OK > Termination: Restore OK > > 23-Dec 11:30 troll-dir JobId 10203: Begin pruning Jobs. > 23-Dec 11:30 troll-dir JobId 10203: No Jobs found to prune. > 23-Dec 11:30 troll-dir JobId 10203: Begin pruning Files. > 23-Dec 11:30 troll-dir JobId 10203: No Files found to prune. > 23-Dec 11:30 troll-dir JobId 10203: End auto prune. ------------------------------------------------------------------------------ _______________________________________________ Bacula-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-devel
