Bacula-users

Re: [Bacula-users] Problems with Verify

2009-03-12 07:23:26
Subject: Re: [Bacula-users] Problems with Verify
From: Ralf Gross <Ralf-Lists AT ralfgross DOT de>
To: bacula-users AT lists.sourceforge DOT net
Date: Thu, 12 Mar 2009 12:10:47 +0100
Alex Bremer schrieb:
> 2009/3/12, Ralf Gross <Ralf-Lists AT ralfgross DOT de>:
> > The verify is done in the fd, so I would addd the debug option there
> > too. And also to the sd, because if bacula complains about a file that
> > is missing on the volume, you might find the answer there.
> 
> Yes, I did this, but at least the fd logfile does not seem to contain
> any usefull information. This is the log from one of the files which
> is reported as missing:
> 
> ###############################
> FD.linus: verify_vol.c:219-0 bfiled>bdird: MD5 len=38: msg=887 3
> HdJ+ZfT9vmMPbM/6qa+mxQ *MD5-887*
> FD.linus: verify_vol.c:102-0 Got hdr: FilInx=888 Stream=1.
> FD.linus: verify_vol.c:115-0 Got stream data, len=125
> FD.linus: verify_vol.c:149-0 Got Attr: FilInx=888 type=3
> FD.linus: verify_vol.c:102-0 Got hdr: FilInx=888 Stream=4.
> FD.linus: verify_vol.c:115-0 Got stream data, len=93
> FD.linus: verify_vol.c:102-0 Got hdr: FilInx=888 Stream=15.
> FD.linus: verify_vol.c:115-0 Got stream data, len=33
> FD.linus: verify_vol.c:102-0 Got hdr: FilInx=888 Stream=3.
> FD.linus: verify_vol.c:115-0 Got stream data, len=16
> ###############################
> 
> So it seems like the fd could find the file on the storage deamon.
> 
> The SD log doesn't show any errors, too:
> 
> ################################
> SD.xen: dev.c:485-0 open disk: mode=OPEN_READ_ONLY
> open(/local/var/backup/volumes/VOL-DAILY-0005, 0x0, 0640)
> SD.xen: dev.c:500-0 open dev: disk fd=6 opened, part=0/0, part_size=199775722
> SD.xen: dev.c:317-0 preserve=0x0 fd=6
> SD.xen: acquire.c:210-0 opened dev "DEV.FileStorage"
> (/local/var/backup/volumes) OK
> SD.xen: acquire.c:213-0 calling read-vol-label
> SD.xen: label.c:81-0 Enter read_volume_label res=1
> device="DEV.FileStorage" (/local/var/backup/volumes)
> vol=VOL-DAILY-0005 dev_Vol=*NULL*
> SD.xen: reserve.c:313-0 jid=30 reserve_volume VOL-DAILY-0005
> SD.xen: reserve.c:238-0 jid=30 new Vol=VOL-DAILY-0005 at 6855e8
> dev="DEV.FileStorage" (/local/var/backup/volumes)
> SD.xen: reserve.c:181-0 jid=30 List from end new volume:
> VOL-DAILY-0005 at 6855e8 on device "DEV.FileStorage"
> (/local/var/backup/volumes)
> 
> Volume Label:
> Id                : Bacula 1.0 immortal
> VerNo             : 11
> VolName           : VOL-DAILY-0005
> PrevVolName       :
> VolFile           : 0
> LabelType         : VOL_LABEL
> LabelSize         : 161
> PoolName          : POOL.Daily
> MediaType         : File
> PoolType          : Backup
> HostName          : xen
> Date label written: 09-Mär-2009 17:54
> SD.xen: jcr.c:603-0 OnEntry JobStatus=R set=R
> SD.xen: jcr.c:623-0 OnExit JobStatus=R set=R
> SD.xen: acquire.c:293-0 Dec reserve=0 dev="DEV.FileStorage"
> (/local/var/backup/volumes)
> SD.xen: dev.c:1568-0 ===== lseek to 21425
> SD.xen: mount.c:627-0 NumReadVolumes=1 CurReadVolume=1
> SD.xen: mount.c:640-0 End of Device reached.
> SD.xen: acquire.c:498-0 release_device device "DEV.FileStorage"
> (/local/var/backup/volumes) is disk
> SD.xen: acquire.c:509-0 dir_update_vol_info. Release0
> SD.xen: askdir.c:341-0 Update cat VolFiles=0
> SD.xen: askdir.c:364-0 >dird CatReq
> Job=JOB.Verify.linus.sts.2009-03-11_23.05.10 UpdateMedia
> VolName=VOL-DAILY-0005 VolJobs=6 VolFiles=0 VolBlocks=3101
> VolBytes=199775722 VolMounts=6 VolErrors=0 VolWrites=3102
> MaxVolBytes=0 EndTime=1236809195 VolStatus=Append Slot=0 relabel=0
> InChanger=0 VolReadTime=177463 VolWriteTime=2909031 VolFirstWritten=0
> VolParts=0
> SD.xen: askdir.c:182-0 <dird 1000 OK VolName=VOL-DAILY-0005 VolJobs=6
> VolFiles=0 VolBlocks=3101 VolBytes=199775722 VolMounts=6 VolErrors=0
> VolWrites=3102 MaxVolBytes=0 VolCapacityBytes=0 VolStatus=Append
> Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=177463
> VolWriteTime=2909031 EndFile=0 EndBlock=199775721 VolParts=0
> LabelType=0 MediaId=15
> SD.xen: askdir.c:205-0 do_reqest_vol_info return true slot=0
> Volume=VOL-DAILY-0005
> SD.xen: dev.c:1836-0 close_dev "DEV.FileStorage" (/local/var/backup/volumes)
> SD.xen: dev.c:1826-0 Clear volhdr vol=VOL-DAILY-0005
> SD.xen: acquire.c:581-0 JobId=30 broadcast wait_device_release
> SD.xen: reserve.c:493-0 jid=30 free_volume VOL-DAILY-0005
> dev="DEV.FileStorage" (/local/var/backup/volumes)
> SD.xen: acquire.c:596-0 ===== Device "DEV.FileStorage"
> (/local/var/backup/volumes) released by JobId=30
> SD.xen: read.c:96-0 Done reading.
> ##########################
> 
> If I understand those logfiles correctly it seems that the SD reads
> the data properly, the FD even finds the files which are reported to
> be missing, but the DIR thinks there is an error and reports it.
> Anything else I can do to find the culprit?

I can't see anything obvious. 

Is the number of files in the job output of your first mail correct?
Do the 70,966 match the number of files in the backup job report?

Files Expected:         70,966                                                  
                                                             
Files Examined:         70,966     

Ralf

------------------------------------------------------------------------------
Apps built with the Adobe(R) Flex(R) framework and Flex Builder(TM) are
powering Web 2.0 with engaging, cross-platform capabilities. Quickly and
easily build your RIAs with Flex Builder, the Eclipse(TM)based development
software that enables intelligent coding and step-through debugging.
Download the free 60 day trial. http://p.sf.net/sfu/www-adobe-com
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users