[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Bacula-devel] restore problem: bacula 2.5.26 reads 469GB from tape to restore 7GB job


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.

[root@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 <ulrich.leodolter@xxxxxxxx>
OBVSG


------------------------------------------------------------------------------
_______________________________________________
Bacula-devel mailing list
Bacula-devel@xxxxxxxxxxxxxxxxxxxxx
https://lists.sourceforge.net/lists/listinfo/bacula-devel


This mailing list archive is a service of Copilotco.