Bacula-users

[Bacula-users] one system always failing backup -- logs, SD debug, config files

2008-12-15 18:06:26
Subject: [Bacula-users] one system always failing backup -- logs, SD debug, config files
From: Jo Rhett <jrhett AT netconsonance DOT com>
To: bacula-users Net <bacula-users AT lists.sourceforge DOT net>
Date: Mon, 15 Dec 2008 15:03:36 -0800
We have a dozen systems backed up to a single host, on-disk backup.   
We just rebuilt the host.  One of the systems had periodically failed  
backups (once every week or so) but all other systems were fine.

Now this same system won't back up at all.  This is private Gigabit  
flat network. (no routers, no firewalls even on the hosts).  Version  
2.4.3 built straight from freebsd ports with no changes.

Included below are the log and the sd debug log.   The configurations  
are at the very end, but straightforward, right out of the  
documentation.

The log always looks the same:

15-Dec 13:02 backup0-dir JobId 104: No prior Full backup Job record  
found.
15-Dec 13:02 backup0-dir JobId 104: No prior or suitable Full backup  
found in catalog. Doing FULL backup.
15-Dec 13:02 backup0-dir JobId 104: Start Backup JobId 104, Job=arran. 
2008-12-15_13.02.52
15-Dec 13:02 backup0-dir JobId 104: Using Device "Disk_SVcolo"
15-Dec 13:02 backup0-sd JobId 104: Volume "Daily-0022" previously  
written, moving to end of data.
15-Dec 13:02 backup0-sd JobId 104: Ready to append to end of Volume  
"Daily-0022" size=8402085728
arran.sc-fd JobId 104:      /dev is a different filesystem. Will not  
descend from / into /dev
arran.sc-fd JobId 104:      /d is a different filesystem. Will not  
descend from / into /d
15-Dec 13:33 arran.sc-fd JobId 104: Fatal error: backup.c:892 Network  
send error to SD. ERR=Broken pipe
15-Dec 13:33 backup0-sd JobId 104: Job arran.2008-12-15_13.02.52  
marked to be canceled.
15-Dec 13:33 backup0-sd JobId 104: Fatal error: append.c:259 Network  
error on data channel. ERR=Connection reset by peer
15-Dec 13:33 backup0-sd JobId 104: Job write elapsed time = 00:30:09,  
Transfer rate = 3.409 M bytes/second
15-Dec 13:33 backup0-sd JobId 104: Error: bsock.c:444 Read error from  
client:10.64.244.8:36643: ERR=Connection reset by peer
15-Dec 13:33 backup0-dir JobId 104: Error: Bacula backup0-dir 2.4.3  
(10Oct08): 15-Dec-2008 13:33:04
  Build OS:               i386-portbld-freebsd6.3 freebsd 6.3-RELEASE-p6
  JobId:                  104
  Job:                    arran.2008-12-15_13.02.52
  Backup Level:           Full (upgraded from Incremental)
  Client:                 "arran-fd" 2.4.3 (10Oct08) i386-portbld- 
freebsd6.3,freebsd,6.3-RELEASE-p6
  FileSet:                "Fileset_SVcolo" 2008-12-04 08:56:32
  Pool:                   "Daily" (From Job resource)
  Storage:                "Disk_SVcolo" (From Job resource)
  Scheduled time:         15-Dec-2008 13:02:50
  Start time:             15-Dec-2008 13:02:54
  End time:               15-Dec-2008 13:33:04
  Elapsed time:           30 mins 10 secs
  Priority:               10
  FD Files Written:       69,765
  SD Files Written:       69,765
  FD Bytes Written:       6,156,748,783 (6.156 GB)
  SD Bytes Written:       6,166,924,763 (6.166 GB)
  Rate:                   3401.5 KB/s
  Software Compression:   None
  VSS:                    no
  Storage Encryption:     no
  Volume name(s):         Daily-0022
  Volume Session Id:      1
  Volume Session Time:    1229374963
  Last Volume Bytes:      14,575,732,845 (14.57 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  Error
  SD termination status:  Canceled
  Termination:            *** Backup Error ***

Here is the SD Log.  In the middle of the log I have marked where the  
failure occurs:

[root@backup0 ~]# bacula-sd -d100 -f
bacula-sd: stored_conf.c:672-0 Inserting device res: Disk_Clients
backup0-sd: jcr.c:135-0 read_last_jobs seek to 188
backup0-sd: jcr.c:142-0 Read num_items=10
backup0-sd: stored.c:480-0 calling init_dev /bacula/svcolo
backup0-sd: dev.c:261-0 init_dev: tape=0 dev_name=/bacula/svcolo
backup0-sd: stored.c:482-0 SD init done /bacula/svcolo
backup0-sd: stored.c:480-0 calling init_dev /bacula/clients
backup0-sd: dev.c:261-0 init_dev: tape=0 dev_name=/bacula/clients
backup0-sd: stored.c:482-0 SD init done /bacula/clients
backup0-sd: bnet_server.c:96-0 Addresses host[ipv4:0.0.0.0:9103]
backup0-sd: bnet.c:667-0 who=client host=10.64.244.1 port=36643
backup0-sd: cram-md5.c:73-0 send: auth cram-md5  
<393748147.1229374973@backup0-sd> ssl=0
backup0-sd: cram-md5.c:133-0 cram-get received: auth cram-md5  
<561319632.1229374973@backup0-dir> ssl=0
backup0-sd: cram-md5.c:152-0 sending resp to challenge: 8n/1F+VLX4crp+/ 
ayQduFD
backup0-sd: dircmd.c:210-0 Message channel init completed.
backup0-sd: job.c:92-0 <dird: JobId=104 job=arran.2008-12-15_13.02.52  
job_name=arran client_name=arran-fd type=66 level=70  
FileSet=Fileset_SVcolo NoAttr=0 SpoolAttr=0  
FileSetMD5=p90ZM6+Dw6IVK5Bl/+QBrA SpoolData=0 WritePartAfterJob=1  
PreferMountedVols=1
backup0-sd: job.c:156-0 >dird jid=104: 3000 OK Job SDid=1  
SDtime=1229374963 Authorization=OPMO-DBJJ-AEKC-LBEH-HOMB-CIKG-PGGN-HIJB
backup0-sd: reserve.c:695-0 jid=104 <dird: use storage=Disk_SVcolo  
media_type=File_SVcolo pool_name=Daily pool_type=Backup append=1  
copy=0 stripe=0
backup0-sd: reserve.c:724-0 jid=104 <dird device: use device=Disk_SVcolo
backup0-sd: reserve.c:741-0 jid=104 Storage=Disk_SVcolo  
media_type=File_SVcolo pool=Daily pool_type=Backup append=1
backup0-sd: reserve.c:743-0 jid=104     Device=Disk_SVcolo
backup0-sd: reserve.c:919-0 jid=104 PrefMnt=1 exact=1 suitable=0  
chgronly=0
backup0-sd: reserve.c:1084-0 jid=104 search res for Disk_SVcolo
backup0-sd: reserve.c:1121-0 jid=104 Try match res=Disk_SVcolo
backup0-sd: reserve.c:1161-0 jid=104 chk MediaType device=File_SVcolo  
request=File_SVcolo
backup0-sd: reserve.c:1184-0 try reserve Disk_SVcolo
backup0-sd: reserve.c:1198-0 jid=104 have_vol=0 vol=
backup0-sd: reserve.c:1381-0 jid=104 reserve_append device is  
"Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:1459-0 jid=104 PrefMnt=1 exact=1 suitable=1  
chgronly=0 any=0
backup0-sd: reserve.c:1430-0 MaxJobs=0 Jobs=0 reserves=0 Status= Vol=
backup0-sd: reserve.c:1566-0 jid=104 OK Dev avail reserved  
"Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:481-0 Inc reserve=0 dev="Disk_SVcolo" (/bacula/ 
svcolo)
backup0-sd: reserve.c:1208-0 jid=104 Reserved=1 dev_name=Disk_SVcolo  
mediatype=File_SVcolo pool=Daily ok=1
backup0-sd: askdir.c:276-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
FindMedia=1 pool_name=Daily media_type=File_SVcolo
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=3  
VolFiles=1 VolBlocks=130242 VolBytes=8402085728 VolMounts=3  
VolErrors=0 VolWrites=130243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=900695983 EndFile=1 EndBlock=4107118431  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: reserve.c:472-0 jid=104 find_vol=Daily-0022 found=0
backup0-sd: reserve.c:635-0 jid=104 Vol=Daily-0022 not in use.
backup0-sd: askdir.c:285-0 Call reserve_volume. Vol=Daily-0022
backup0-sd: reserve.c:316-0 jid=104 enter reserve_volume=Daily-0022  
drive="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:236-0 jid=104 new Vol=Daily-0022 at 80bdf58  
dev="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:418-0 jid=104 === set in_use. vol=Daily-0022  
dev="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:189-0 jid=104 List end new volume: Daily-0022  
in_use=1 on device "Disk_SVcolo" (/bacula/svcolo)
backup0-sd: askdir.c:292-0 dir_find_next_appendable_volume return  
true. vol=Daily-0022
backup0-sd: reserve.c:1220-0 jid=104 looking for Volume=Daily-0022
backup0-sd: reserve.c:1279-0 jid=104 >dird changer: 3000 OK use device  
device=Disk_SVcolo
backup0-sd: reserve.c:1132-0 jid=104 Device Disk_SVcolo reserved=1 for  
append.
backup0-sd: reserve.c:1053-0 jid=104 available device found=Disk_SVcolo
backup0-sd: reserve.c:1068-0 OK dev found. Vol=Daily-0022
backup0-sd: job.c:190-0 arran.2008-12-15_13.02.52 waiting 1800 sec for  
FD to contact SD key=OPMO-DBJJ-AEKC-LBEH-HOMB-CIKG-PGGN-HIJB
backup0-sd: bnet.c:667-0 who=client host=10.64.244.8 port=36643
backup0-sd: cram-md5.c:73-0 send: auth cram-md5  
<1991098890.1229374974@backup0-sd> ssl=0
backup0-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<1688385209.1229374974 AT arran DOT sc-fd 
 > ssl=0
backup0-sd: cram-md5.c:152-0 sending resp to challenge: k5cqL6/ 
XD5+agGQRm9xA/B
backup0-sd: job.c:209-0 Running job arran.2008-12-15_13.02.52
backup0-sd: append.c:73-0 Start append data. res=1
backup0-sd: acquire.c:346-0 acquire_append device is disk
backup0-sd: askdir.c:230-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
GetVolInfo VolName=Daily-0022 write=1
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=3  
VolFiles=1 VolBlocks=130242 VolBytes=8402085728 VolMounts=3  
VolErrors=0 VolWrites=130243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=900695983 EndFile=1 EndBlock=4107118431  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: autochanger.c:121-0 Device "Disk_SVcolo" (/bacula/svcolo)  
is not an autochanger
backup0-sd: dev.c:303-0 open dev: type=1 dev_name="Disk_SVcolo" (/ 
bacula/svcolo) vol=Daily-0022 mode=OPEN_READ_WRITE
backup0-sd: dev.c:312-0 call open_file_device mode=OPEN_READ_WRITE
backup0-sd: dev.c:484-0 open disk: mode=OPEN_READ_WRITE open(/bacula/ 
svcolo/Daily-0022, 0x2, 0640)
backup0-sd: dev.c:499-0 open dev: disk fd=7 opened, part=0/0,  
part_size=0
backup0-sd: dev.c:316-0 preserve=0x0 fd=7
backup0-sd: label.c:81-0 Enter read_volume_label res=1  
device="Disk_SVcolo" (/bacula/svcolo) vol=Daily-0022 dev_Vol=*NULL*

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Daily-0022
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 170
PoolName          : Daily
MediaType         : File_SVcolo
PoolType          : Backup
HostName          : backup0.sv
Date label written: 15-Dec-2008 11:37
backup0-sd: label.c:257-0 Call reserve_volume=Daily-0022
backup0-sd: reserve.c:316-0 jid=104 enter reserve_volume=Daily-0022  
drive="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:189-0 jid=104 List begin reserve_volume:  
Daily-0022 in_use=1 on device "Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:331-0 jid=104 Vol attached=Daily-0022,  
newvol=Daily-0022 volinuse=1 on "Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:339-0 jid=104 === set reserved vol=Daily-0022  
dev="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:418-0 jid=104 === set in_use. vol=Daily-0022  
dev="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: reserve.c:189-0 jid=104 List end new volume: Daily-0022  
in_use=1 on device "Disk_SVcolo" (/bacula/svcolo)
backup0-sd: dev.c:837-0 eod
backup0-sd: askdir.c:345-0 Update cat VolFiles=1
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=3 VolFiles=1 VolBlocks=130242  
VolBytes=8402085728 VolMounts=4 VolErrors=0 VolWrites=130243  
MaxVolBytes=0 EndTime=1229374974 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=900695983 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=3  
VolFiles=1 VolBlocks=130242 VolBytes=8402085728 VolMounts=4  
VolErrors=0 VolWrites=130243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=900695983 EndFile=1 EndBlock=4107118431  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: askdir.c:345-0 Update cat VolFiles=1
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=1 VolBlocks=130242  
VolBytes=8402085728 VolMounts=4 VolErrors=0 VolWrites=130243  
MaxVolBytes=0 EndTime=1229374974 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=900695983 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=1 VolBlocks=130242 VolBytes=8402085728 VolMounts=4  
VolErrors=0 VolWrites=130243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=900695983 EndFile=1 EndBlock=4107118431  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: reserve.c:490-0 Dec reserve=0 dev="Disk_SVcolo" (/bacula/ 
svcolo)
backup0-sd: append.c:96-0 Begin append device="Disk_SVcolo" (/bacula/ 
svcolo)
backup0-sd: append.c:101-0 Just after acquire_device_for_append
backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=1 LastIndex=50384 StartFile=1 EndFile=2  
StartBlock=4107118432 EndBlock=812086979 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=2
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=2 VolBlocks=145742  
VolBytes=9402021572 VolMounts=4 VolErrors=0 VolWrites=145743  
MaxVolBytes=0 EndTime=1229375277 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=999837569 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=2 VolBlocks=145742 VolBytes=9402021572 VolMounts=4  
VolErrors=0 VolWrites=145743 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=999837569 EndFile=2 EndBlock=812086979  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: block.c:811-0 dir_update_volume_info max file size -- OK
backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=50384 LastIndex=66857 StartFile=2 EndFile=2  
StartBlock=812086980 EndBlock=1812022933 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=2
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=2 VolBlocks=161242  
VolBytes=10401957526 VolMounts=4 VolErrors=0 VolWrites=161243  
MaxVolBytes=0 EndTime=1229375533 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=1153396480 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=2 VolBlocks=161242 VolBytes=10401957526 VolMounts=4  
VolErrors=0 VolWrites=161243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=1153396480 EndFile=2 EndBlock=1812022933  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: block.c:811-0 dir_update_volume_info max file size -- OK
backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=66857 LastIndex=67850 StartFile=2 EndFile=2  
StartBlock=1812022934 EndBlock=2811958933 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=2
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=2 VolBlocks=176742  
VolBytes=11401893526 VolMounts=4 VolErrors=0 VolWrites=176743  
MaxVolBytes=0 EndTime=1229375810 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=1304231650 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=2 VolBlocks=176742 VolBytes=11401893526 VolMounts=4  
VolErrors=0 VolWrites=176743 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=1304231650 EndFile=2 EndBlock=2811958933  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: block.c:811-0 dir_update_volume_info max file size -- OK
backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=67850 LastIndex=68682 StartFile=2 EndFile=2  
StartBlock=2811958934 EndBlock=3811894933 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=2
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=2 VolBlocks=192242  
VolBytes=12401829526 VolMounts=4 VolErrors=0 VolWrites=192243  
MaxVolBytes=0 EndTime=1229376094 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=1453774914 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=2 VolBlocks=192242 VolBytes=12401829526 VolMounts=4  
VolErrors=0 VolWrites=192243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=1453774914 EndFile=2 EndBlock=3811894933  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: block.c:811-0 dir_update_volume_info max file size -- OK
backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=68682 LastIndex=69642 StartFile=2 EndFile=3  
StartBlock=3811894934 EndBlock=516863625 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=3
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=3 VolBlocks=207742  
VolBytes=13401765514 VolMounts=4 VolErrors=0 VolWrites=207743  
MaxVolBytes=0 EndTime=1229376381 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=1606296123 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=3 VolBlocks=207742 VolBytes=13401765514 VolMounts=4  
VolErrors=0 VolWrites=207743 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=1606296123 EndFile=3 EndBlock=516863625  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: block.c:811-0 dir_update_volume_info max file size -- OK

**** FAILURE HAPPENED HERE ****

backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=69642 LastIndex=69747 StartFile=3 EndFile=3  
StartBlock=516863626 EndBlock=1516799608 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=3
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=3 VolBlocks=223242  
VolBytes=14401701497 VolMounts=4 VolErrors=0 VolWrites=223243  
MaxVolBytes=0 EndTime=1229376650 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=1761034365 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=3 VolBlocks=223242 VolBytes=14401701497 VolMounts=4  
VolErrors=0 VolWrites=223243 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=1761034365 EndFile=3 EndBlock=1516799608  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: block.c:811-0 dir_update_volume_info max file size -- OK
backup0-sd: bnet.c:667-0 who=client host=10.64.244.1 port=36643
backup0-sd: cram-md5.c:73-0 send: auth cram-md5  
<1830147926.1229376783@backup0-sd> ssl=0
backup0-sd: cram-md5.c:133-0 cram-get received: auth cram-md5  
<1207711240.1229376783@backup0-dir> ssl=0
backup0-sd: cram-md5.c:152-0 sending resp to challenge: TCpqinILx/+SPS/ 
1N9/E+A
backup0-sd: dircmd.c:210-0 Message channel init completed.
backup0-sd: append.c:301-0 back from write_end_session_label()
backup0-sd: acquire.c:427-0 release_device device "Disk_SVcolo" (/ 
bacula/svcolo) is disk
backup0-sd: acquire.c:449-0 There are 0 writers in release_device
backup0-sd: askdir.c:412-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
CreateJobMedia FirstIndex=69747 LastIndex=69765 StartFile=3 EndFile=3  
StartBlock=1516799609 EndBlock=1690830956 Copy=0 Strip=0 MediaId=22
backup0-sd: askdir.c:419-0 <dird 1000 OK CreateJobMedia
backup0-sd: askdir.c:345-0 Update cat VolFiles=3
backup0-sd: askdir.c:368-0 >dird CatReq Job=arran.2008-12-15_13.02.52  
UpdateMedia VolName=Daily-0022 VolJobs=4 VolFiles=3 VolBlocks=225940  
VolBytes=14575732845 VolMounts=4 VolErrors=0 VolWrites=225941  
MaxVolBytes=0 EndTime=1229376784 VolStatus=Append Slot=0 relabel=0  
InChanger=0 VolReadTime=0 VolWriteTime=1787234051 VolFirstWritten=0  
VolParts=0
backup0-sd: askdir.c:182-0 <dird 1000 OK VolName=Daily-0022 VolJobs=4  
VolFiles=3 VolBlocks=225940 VolBytes=14575732845 VolMounts=4  
VolErrors=0 VolWrites=225941 MaxVolBytes=0 VolCapacityBytes=0  
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0  
VolReadTime=0 VolWriteTime=1787234051 EndFile=3 EndBlock=1690830956  
VolParts=0 LabelType=0 MediaId=22
backup0-sd: askdir.c:205-0 do_reqest_vol_info return true slot=0  
Volume=Daily-0022
backup0-sd: reserve.c:553-0 jid=104 === set not reserved  
vol=Daily-0022 num_writers=0 dev_reserved=0 dev="Disk_SVcolo" (/bacula/ 
svcolo)
backup0-sd: reserve.c:554-0 === clear in_use vol=Daily-0022
backup0-sd: reserve.c:582-0 === clear in_use vol=Daily-0022
backup0-sd: reserve.c:585-0 jid=104 === remove volume Daily-0022  
dev="Disk_SVcolo" (/bacula/svcolo)
backup0-sd: acquire.c:484-0 0 writers, 0 reserve, dev="Disk_SVcolo" (/ 
bacula/svcolo)
backup0-sd: dev.c:1858-0 close_dev "Disk_SVcolo" (/bacula/svcolo)
backup0-sd: dev.c:1848-0 Clear volhdr vol=Daily-0022
backup0-sd: acquire.c:522-0 JobId=104 broadcast wait_device_release at  
15-Dec-2008 13:33:04
backup0-sd: acquire.c:537-0 ===== Device "Disk_SVcolo" (/bacula/ 
svcolo) released by JobId=104
backup0-sd: append.c:341-0 return from do_append_data() ok=0


SD config:

Storage {                             # definition of myself
        Name = backup0-sd
        SDPort = 9103                  # Director's port
        WorkingDirectory = "/var/db/bacula"
        Pid Directory = "/var/run"
        Maximum Concurrent Jobs = 20
        Heartbeat Interval = 20 min
}

Director {
        Name = backup0-dir
        Password = <snip>
}

Device {
        Name = Disk_SVcolo
        Media Type = File_SVcolo
        Archive Device = /bacula/svcolo
        LabelMedia = yes;                   # lets Bacula label  
unlabeled media
        Random Access = Yes;
        AutomaticMount = yes;               # when device opened, read  
it
        RemovableMedia = no;
        AlwaysOpen = no;
}

FD config

Director {
  Name = backup0-dir
  Password = <snip>
}

FileDaemon {                          # this is me
        Name = arran.sc-fd
        WorkingDirectory = /var/db/bacula
        Pid Directory = /var/run
        Maximum Concurrent Jobs = 4
        FDAddress = 10.64.244.8
        FDport = 9102                  # where we listen for the  
director
        Heartbeat Interval = 5 min
        SD Connect Timeout = 5 min
}

# Send all messages except skipped files back to Director
Messages {
  Name = Standard
  director = backup0-dir = all, !skipped
}

DIR config:

Director {                            # define myself
  Name = backup0-dir
  DIRport = 9101                # where we listen for UA connections
  QueryFile = "/usr/local/share/bacula/query.sql"
  WorkingDirectory = "/var/db/bacula"
  PidDirectory = "/var/run"
  Maximum Concurrent Jobs = 3
  Password = <snip>
  Messages = Daemon
}

Storage {
  Name = Disk_SVcolo
  Device = Disk_SVcolo
  Media Type = File_SVcolo
  Address = 10.64.244.1
  SDPort = 9103
  Password = <snip>
}

Pool {
  Name = Daily
  Pool Type = Backup
  Recycle = yes                   # Bacula can automatically recycle  
Volumes
  Recycle Oldest Volume = yes
  AutoPrune = yes                 # Prune expired volumes
  Volume Retention = 30 days      # one month
  Volume Use Duration = 24h
# Accept Any Volume = yes         # write on any volume in the pool
  LabelFormat = "Daily-"
  Maximum Volumes = 32
}

# Jobs
JobDefs {
  Name = "SVcolo_Job"
  Type = Backup
  Level = Incremental
  Client = backup0-fd
  FileSet = "Fileset_SVcolo"
  Schedule = "WeeklyFull"
  Storage = Disk_SVcolo
  Pool = Daily
  Messages = Standard
  Priority = 10
}

Job {
  Name = "arran"
  Client = arran-fd
  JobDefs = "SVcolo_Job"
  Write Bootstrap = "/var/db/bacula/arran.bsr"
}
Client {
  Name = arran-fd
  Address = 10.64.244.8
  FDPort = 9102
  Catalog = General_Catalog
  Password = <snip>
  File Retention = 30 days            # 30 days
  Job Retention = 6 months            # six months
  AutoPrune = yes                     # Prune expired Jobs/Files
}

-- 
Jo Rhett
senior geek

Silicon Valley Colocation
Support Phone: 408-400-0550
-- 
Jo Rhett
Net Consonance : consonant endings by net philanthropy, open source  
and other randomness



------------------------------------------------------------------------------
SF.Net email is Sponsored by MIX09, March 18-20, 2009 in Las Vegas, Nevada.
The future of the web can't happen without you.  Join us at MIX09 to help
pave the way to the Next Web now. Learn more and register at
http://ad.doubleclick.net/clk;208669438;13503038;i?http://2009.visitmix.com/
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users