On Tue, 2008-12-23 at 13:55 +0100, Kern Sibbald wrote: > 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. > >
Run Restore job JobName: RestoreFiles Bootstrap: /opt/bacula/var/bacula/working/troll-dir.restore.28.bsr Where: /bacula-restores Replace: always FileSet: Full Set Backup Client: leodolter-fd Restore Client: leodolter-fd Storage: Tape When: 2008-12-23 14:14:38 Catalog: MyCatalog Priority: 10 Plugin Options: *None* OK to run? (yes/mod/no): no Job not run. [r...@troll ~]# cat /opt/bacula/var/bacula/working/troll-dir.restore.28.bsr Volume="BACU.003" MediaType="LTO-4" Device="OVERLAND" Slot=22 VolSessionId=30 VolSessionTime=1229852609 VolAddr=1-15499 FileIndex=1-77667 Count=77667 Volume="BACU.003" MediaType="LTO-4" Device="OVERLAND" Slot=22 VolSessionId=30 VolSessionTime=1229852609 VolAddr=4294967296-4294982795 FileIndex=77667-183761 FileIndex=183763-184144 FileIndex=184146-207239 Count=129571 Volume="BACU.003" MediaType="LTO-4" Device="OVERLAND" Slot=22 VolSessionId=30 VolSessionTime=1229852609 VolAddr=8589934592-8589950091 FileIndex=207239-207626 Count=388 Volume="BACU.003" MediaType="LTO-4" Device="OVERLAND" Slot=22 VolSessionId=30 VolSessionTime=1229852609 VolAddr=12884901888-12884917387 FileIndex=207626-207694 Count=69 Volume="BACU.003" MediaType="LTO-4" Device="OVERLAND" Slot=22 VolSessionId=30 VolSessionTime=1229852609 VolAddr=17179869184-17179877816 FileIndex=207694-208346 Count=653 > > > > 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. > > -- Ulrich Leodolter <[email protected]> OBVSG ------------------------------------------------------------------------------ _______________________________________________ Bacula-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-devel
