------- 8< ---------------------

pc-backup2-sd: label.c:822-0 unser_vol_label

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-22-2
PrevVolName       : 
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 189
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 22-Jul-2015 04:00
pc-backup2-sd: label.c:200-0 Compare Vol names: VolName=Binlog-Full-2015-07-22-2 hdr=Binlog-Full-2015-07-22-2

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-22-2
PrevVolName       : 
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 189
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 22-Jul-2015 04:00
pc-backup2-sd: label.c:221-0 Leave read_volume_label() VOL_OK
pc-backup2-sd: dev.c:591-0 rewind res=5 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:234-0 Call reserve_volume=Binlog-Full-2015-07-22-2
pc-backup2-sd: vol_mgr.c:349-0 enter reserve_volume=Binlog-Full-2015-07-22-2 drive="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List begin reserve_volume: Binlog-Full-2015-07-22-2 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:364-0 Vol attached=Binlog-Full-2015-07-22-2, newvol=Binlog-Full-2015-07-22-2 volinuse=1 on "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:372-0 === set reserved vol=Binlog-Full-2015-07-22-2 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:467-0 === set in_use. vol=Binlog-Full-2015-07-22-2 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List end new volume: Binlog-Full-2015-07-22-2 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: mount.c:385-0 Want dirVol=Binlog-Full-2015-07-22-2 dirStat=Append
pc-backup2-sd: mount.c:393-0 Vol OK name=Binlog-Full-2015-07-22-2
pc-backup2-sd: mount.c:246-0 Do not have volcatinfo
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-bi-db1-2-MysqlBinlog.2015-07-23_04.00.00_52 GetVolInfo VolName=Binlog-Full-2015-07-22-2 write=1
pc-backup2-sd: fd_cmds.c:156-0 <filed: append open session
pc-backup2-sd: fd_cmds.c:239-0 Append open session: append open session
pc-backup2-sd: fd_cmds.c:250-0 >filed: 3000 OK open ticket = 560
pc-backup2-sd: fd_cmds.c:156-0 <filed: append data 560
pc-backup2-sd: fd_cmds.c:199-0 Append data: append data 560
pc-backup2-sd: fd_cmds.c:201-0 <bfiled: append data 560
pc-backup2-sd: append.c:77-0 Start append data. res=5
pc-backup2-sd: fd_cmds.c:156-0 <filed: append open session
pc-backup2-sd: fd_cmds.c:239-0 Append open session: append open session
pc-backup2-sd: fd_cmds.c:250-0 >filed: 3000 OK open ticket = 561
pc-backup2-sd: fd_cmds.c:156-0 <filed: append open session
pc-backup2-sd: fd_cmds.c:239-0 Append open session: append open session
pc-backup2-sd: fd_cmds.c:156-0 <filed: append data 561
pc-backup2-sd: fd_cmds.c:199-0 Append data: append data 561
pc-backup2-sd: fd_cmds.c:201-0 <bfiled: append data 561
pc-backup2-sd: append.c:77-0 Start append data. res=5
pc-backup2-sd: fd_cmds.c:250-0 >filed: 3000 OK open ticket = 559
pc-backup2-sd: fd_cmds.c:156-0 <filed: append data 559
pc-backup2-sd: fd_cmds.c:199-0 Append data: append data 559
pc-backup2-sd: fd_cmds.c:201-0 <bfiled: append data 559
pc-backup2-sd: append.c:77-0 Start append data. res=5
pc-backup2-sd: fd_cmds.c:156-0 <filed: append open session
pc-backup2-sd: fd_cmds.c:239-0 Append open session: append open session
pc-backup2-sd: fd_cmds.c:250-0 >filed: 3000 OK open ticket = 563
pc-backup2-sd: askdir.c:182-0 <dird 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: askdir.c:195-0 Bad response from Dir fields=-1, len=94: 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-bi-db1-2-MysqlBinlog.2015-07-23_04.00.00_52 GetVolInfo VolName=Binlog-Full-2015-07-22-2 write=1
pc-backup2-sd: fd_cmds.c:156-0 <filed: append data 563
pc-backup2-sd: fd_cmds.c:199-0 Append data: append data 563
pc-backup2-sd: fd_cmds.c:201-0 <bfiled: append data 563
pc-backup2-sd: append.c:77-0 Start append data. res=5
pc-backup2-sd: askdir.c:182-0 <dird 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: askdir.c:195-0 Bad response from Dir fields=-1, len=94: 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: mount.c:341-0 Before dir_find_next_appendable_volume.
pc-backup2-sd: askdir.c:260-0 dir_find_next_appendable_volume: reserved=1 Vol=Binlog-Full-2015-07-22-2
pc-backup2-sd: askdir.c:277-0 >dird CatReq Job=pc-bi-db1-2-MysqlBinlog.2015-07-23_04.00.00_52 FindMedia=1 pool_name=Binlog-Full media_type=binlog
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-2 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2622
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-2
pc-backup2-sd: vol_mgr.c:542-0 find_read_vol: read_vol_list empty.
pc-backup2-sd: vol_mgr.c:525-0 find_vol=Binlog-Full-2015-07-23-2 found=0
pc-backup2-sd: vol_mgr.c:208-0 List find_volume: Binlog-Full-2015-07-22-2 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:723-0 Vol=Binlog-Full-2015-07-23-2 not in use.
pc-backup2-sd: askdir.c:286-0 Call reserve_volume. Vol=Binlog-Full-2015-07-23-2
pc-backup2-sd: vol_mgr.c:349-0 enter reserve_volume=Binlog-Full-2015-07-23-2 drive="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List begin reserve_volume: Binlog-Full-2015-07-22-2 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:364-0 Vol attached=Binlog-Full-2015-07-22-2, newvol=Binlog-Full-2015-07-23-2 volinuse=1 on "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:381-0 reserve_vol free vol=Binlog-Full-2015-07-22-2 at 7f393c0470d8
pc-backup2-sd: vol_mgr.c:384-0 set_unload
pc-backup2-sd: vol_mgr.c:621-0 === clear in_use vol=Binlog-Full-2015-07-22-2
pc-backup2-sd: vol_mgr.c:624-0 === remove volume Binlog-Full-2015-07-22-2 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:265-0 new Vol=Binlog-Full-2015-07-23-2 at 1464ce8 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:467-0 === set in_use. vol=Binlog-Full-2015-07-23-2 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List end new volume: Binlog-Full-2015-07-23-2 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: askdir.c:293-0 dir_find_next_appendable_volume return true. vol=Binlog-Full-2015-07-23-2
pc-backup2-sd: mount.c:279-0 Device previously written, moving to end of data. Expect 0 bytes
pc-backup2-sd: dev.c:709-0 Enter eod
pc-backup2-sd: dev.c:722-0 ====== Seek to 26778472175
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=26778472175
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-bi-db1-2-MysqlBinlog.2015-07-23_04.00.00_52 UpdateMedia VolName=Binlog-Full-2015-07-23-2 VolJobs=0 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Append Slot=0 relabel=0 InChanger=0 VolReadTime=0 VolWriteTime=0 VolFirstWritten=0 VolParts=0
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-2 VolJobs=0 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2622
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-2
pc-backup2-sd: mount.c:297-0 update volinfo mounts=1
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=26778472175
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-bi-db1-2-MysqlBinlog.2015-07-23_04.00.00_52 UpdateMedia VolName=Binlog-Full-2015-07-23-2 VolJobs=0 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Append Slot=0 relabel=0 InChanger=0 VolReadTime=0 VolWriteTime=0 VolFirstWritten=0 VolParts=0
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-2 VolJobs=0 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2622
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-2
pc-backup2-sd: mount.c:307-0 set APPEND, normal return from mount_next_write_volume. dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: acquire.c:432-0 Output pos=6:1008668399
pc-backup2-sd: lock.c:267-0 unblock BST_DOING_ACQUIRE from acquire.c:434
pc-backup2-sd: sd_plugins.c:111-0 No bplugin_list: generate_plugin_event ignored.
pc-backup2-sd: acquire.c:449-0 === nwriters=1 nres=5 vcatjob=1 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=26778472175
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-bi-db1-2-MysqlBinlog.2015-07-23_04.00.00_52 UpdateMedia VolName=Binlog-Full-2015-07-23-2 VolJobs=1 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Append Slot=0 relabel=0 InChanger=0 VolReadTime=0 VolWriteTime=0 VolFirstWritten=0 VolParts=0
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-2 VolJobs=1 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2622
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-2
pc-backup2-sd: reserve.c:136-0 Dec reserve=4 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: acquire.c:383-0 acquire_append device is disk
pc-backup2-sd: append.c:98-0 Begin append device="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 GetVolInfo VolName=Binlog-Full-2015-07-22-2 write=1
pc-backup2-sd: append.c:103-0 Just after acquire_device_for_append
pc-backup2-sd: label.c:711-0 session_label record=ee1110
pc-backup2-sd: label.c:756-0 Write sesson_label record JobId=36276 FI=SOS_LABEL SessId=562 Strm=36276 len=202 remainder=0
pc-backup2-sd: label.c:760-0 Leave write_session_label Block=1008668399d File=6d
pc-backup2-sd: askdir.c:182-0 <dird 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: askdir.c:195-0 Bad response from Dir fields=-1, len=94: 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: lock.c:257-0 set blocked=BST_DOING_ACQUIRE from acquire.c:417
pc-backup2-sd: acquire.c:419-0 jid=36273 Do mount_next_write_vol
pc-backup2-sd: mount.c:77-0 Enter mount_next_volume(release=0) dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: mount.c:89-0 mount_next_vol retry=0
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 GetVolInfo VolName=Binlog-Full-2015-07-22-2 write=1
pc-backup2-sd: askdir.c:182-0 <dird 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: askdir.c:195-0 Bad response from Dir fields=-1, len=94: 1998 Volume "Binlog-Full-2015-07-22-2" catalog status is Used, volume has recycling disabled.
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 GetVolInfo VolName=Binlog-Full-2015-07-23-2 write=1
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-2 VolJobs=1 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2622
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-2
pc-backup2-sd: mount.c:124-0 After find_next_append. Vol=Binlog-Full-2015-07-23-2 Slot=0 Parts=0
pc-backup2-sd: autochanger.c:120-0 Device "binlog" (/mnt/space2/bacula/storage/) is not an autochanger
pc-backup2-sd: mount.c:146-0 autoload_dev returns 0
pc-backup2-sd: mount.c:159-0 (2)Ask=0
pc-backup2-sd: mount.c:162-0 Ask=0 autochanger=0
pc-backup2-sd: mount.c:177-0 want vol=Binlog-Full-2015-07-23-2 devvol=Binlog-Full-2015-07-22-2 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:79-0 Enter read_volume_label res=4 device="binlog" (/mnt/space2/bacula/storage/) vol=Binlog-Full-2015-07-23-2 dev_Vol=Binlog-Full-2015-07-22-2
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:128-0 Big if statement in read_volume_label
pc-backup2-sd: block.c:955-0 Full read in read_block_from_device() len=64512
pc-backup2-sd: block.c:1009-0 Read device got 64512 bytes at 0:0
pc-backup2-sd: block.c:298-0 unser_block_header block_len=225
pc-backup2-sd: block.c:309-0 Read binbuf = 201 24 block_len=225
pc-backup2-sd: block.c:1145-0 At end of read block
pc-backup2-sd: block.c:1149-0 Current lseek pos=64512
pc-backup2-sd: block.c:1154-0 Did lseek pos=225 blk_size=225 rdlen=64512
pc-backup2-sd: block.c:1159-0 Exit read_block read_len=64512 block_len=225
pc-backup2-sd: label.c:822-0 unser_vol_label

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-22-2
PrevVolName       : 
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 189
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 22-Jul-2015 04:00
pc-backup2-sd: label.c:200-0 Compare Vol names: VolName=Binlog-Full-2015-07-23-2 hdr=Binlog-Full-2015-07-22-2
pc-backup2-sd: label.c:204-0 Wrong Volume mounted on device "binlog" (/mnt/space2/bacula/storage/): Wanted Binlog-Full-2015-07-23-2 have Binlog-Full-2015-07-22-2
pc-backup2-sd: label.c:212-0 return VOL_NAME_ERROR
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:249-0 return 5
pc-backup2-sd: mount.c:385-0 Want dirVol=Binlog-Full-2015-07-23-2 dirStat=Append
pc-backup2-sd: mount.c:400-0 Vol NAME Error Have=Binlog-Full-2015-07-22-2, want=Binlog-Full-2015-07-23-2
pc-backup2-sd: mount.c:748-0 dir_update_vol_info. Set Error.
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=26778472175
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 UpdateMedia VolName=Binlog-Full-2015-07-23-2 VolJobs=1 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Error Slot=0 relabel=0 InChanger=0 VolReadTime=0 VolWriteTime=0 VolFirstWritten=0 VolParts=0
pc-backup2-sd: lock.c:230-0 r_dlock blked=BST_DOING_ACQUIRE no_wait=7f394a25c700 me=7f3948a59700
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-2 VolJobs=1 VolFiles=6 VolBlocks=0 VolBytes=26778472175 VolMounts=1 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Error Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2622
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-2
pc-backup2-sd: vol_mgr.c:591-0 === set not reserved vol=Binlog-Full-2015-07-23-2 num_writers=1 dev_reserved=4 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:592-0 === clear in_use vol=Binlog-Full-2015-07-23-2
pc-backup2-sd: vol_mgr.c:621-0 === clear in_use vol=Binlog-Full-2015-07-23-2
pc-backup2-sd: vol_mgr.c:624-0 === remove volume Binlog-Full-2015-07-23-2 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: mount.c:751-0 set_unload
pc-backup2-sd: mount.c:231-0 set_unload
pc-backup2-sd: mount.c:233-0 goto mount_next_vol
pc-backup2-sd: mount.c:89-0 mount_next_vol retry=1
pc-backup2-sd: mount.c:535-0 must_unload release "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:615-0 No vol on dev "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: dev.c:1726-0 Clear volhdr vol=Binlog-Full-2015-07-22-2
pc-backup2-sd: dev.c:1737-0 close_dev "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: dev.c:1929-0 Enter unmount
pc-backup2-sd: dev.c:1726-0 Clear volhdr vol=
pc-backup2-sd: mount.c:806-0 release_volume
pc-backup2-sd: mount.c:341-0 Before dir_find_next_appendable_volume.
pc-backup2-sd: askdir.c:260-0 dir_find_next_appendable_volume: reserved=1 Vol=
pc-backup2-sd: askdir.c:277-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 FindMedia=1 pool_name=Binlog-Full media_type=binlog
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-3 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2623
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: vol_mgr.c:542-0 find_read_vol: read_vol_list empty.
pc-backup2-sd: vol_mgr.c:723-0 Vol=Binlog-Full-2015-07-23-3 not in use.
pc-backup2-sd: askdir.c:286-0 Call reserve_volume. Vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: vol_mgr.c:349-0 enter reserve_volume=Binlog-Full-2015-07-23-3 drive="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:265-0 new Vol=Binlog-Full-2015-07-23-3 at 7f3940002ca8 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:467-0 === set in_use. vol=Binlog-Full-2015-07-23-3 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List end new volume: Binlog-Full-2015-07-23-3 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: askdir.c:293-0 dir_find_next_appendable_volume return true. vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: mount.c:124-0 After find_next_append. Vol=Binlog-Full-2015-07-23-3 Slot=0 Parts=0
pc-backup2-sd: autochanger.c:120-0 Device "binlog" (/mnt/space2/bacula/storage/) is not an autochanger
pc-backup2-sd: mount.c:146-0 autoload_dev returns 0
pc-backup2-sd: mount.c:159-0 (2)Ask=0
pc-backup2-sd: mount.c:162-0 Ask=0 autochanger=0
pc-backup2-sd: mount.c:177-0 want vol=Binlog-Full-2015-07-23-3 devvol= dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: dev.c:376-0 open dev: type=1 dev_name="binlog" (/mnt/space2/bacula/storage/) vol=Binlog-Full-2015-07-23-3 mode=OPEN_READ_WRITE
pc-backup2-sd: dev.c:385-0 call open_file_device mode=OPEN_READ_WRITE
pc-backup2-sd: dev.c:1896-0 Enter mount
pc-backup2-sd: dev.c:562-0 open disk: mode=OPEN_READ_WRITE open(/mnt/space2/bacula/storage/Binlog-Full-2015-07-23-3, 0x2, 0640)
pc-backup2-sd: dev.c:569-0 open failed: dev.c:568 Could not open: /mnt/space2/bacula/storage/Binlog-Full-2015-07-23-3, ERR=No such file or directory
pc-backup2-sd: dev.c:577-0 open dev: disk fd=-1 opened, part=0/0, part_size=1525160343
pc-backup2-sd: dev.c:389-0 preserve=0x0 fd=-1
pc-backup2-sd: mount.c:703-0 Create volume label
pc-backup2-sd: label.c:303-0 write_volume_label()
pc-backup2-sd: label.c:324-0 New VolName=Binlog-Full-2015-07-23-3
pc-backup2-sd: dev.c:376-0 open dev: type=1 dev_name="binlog" (/mnt/space2/bacula/storage/) vol=Binlog-Full-2015-07-23-3 mode=OPEN_READ_WRITE
pc-backup2-sd: dev.c:385-0 call open_file_device mode=OPEN_READ_WRITE
pc-backup2-sd: dev.c:1896-0 Enter mount
pc-backup2-sd: dev.c:562-0 open disk: mode=OPEN_READ_WRITE open(/mnt/space2/bacula/storage/Binlog-Full-2015-07-23-3, 0x2, 0640)
pc-backup2-sd: dev.c:569-0 open failed: dev.c:568 Could not open: /mnt/space2/bacula/storage/Binlog-Full-2015-07-23-3, ERR=No such file or directory
pc-backup2-sd: dev.c:577-0 open dev: disk fd=-1 opened, part=0/0, part_size=1525160343
pc-backup2-sd: dev.c:389-0 preserve=0x0 fd=-1
pc-backup2-sd: dev.c:376-0 open dev: type=1 dev_name="binlog" (/mnt/space2/bacula/storage/) vol=Binlog-Full-2015-07-23-3 mode=CREATE_READ_WRITE
pc-backup2-sd: dev.c:385-0 call open_file_device mode=CREATE_READ_WRITE
pc-backup2-sd: dev.c:1896-0 Enter mount
pc-backup2-sd: dev.c:562-0 open disk: mode=CREATE_READ_WRITE open(/mnt/space2/bacula/storage/Binlog-Full-2015-07-23-3, 0x42, 0640)
pc-backup2-sd: dev.c:577-0 open dev: disk fd=13 opened, part=0/0, part_size=1525160343
pc-backup2-sd: dev.c:389-0 preserve=0x0 fd=13
pc-backup2-sd: label.c:333-0 Label type=0
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:608-0 Start create_volume_label()
pc-backup2-sd: dev.c:1726-0 Clear volhdr vol=

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-23-3
PrevVolName       : 
VolFile           : 0
LabelType         : PRE_LABEL
LabelSize         : 0
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 23-Jul-2015 04:00
pc-backup2-sd: label.c:596-0 Created Vol label rec: FI=PRE_LABEL len=189
pc-backup2-sd: label.c:369-0 Wrote label of 189 bytes to "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:372-0 Call write_block_to_dev()
pc-backup2-sd: block.c:454-0 binbuf=225 buf_len=64512
pc-backup2-sd: label.c:387-0  Wrote block to device
pc-backup2-sd: dev.c:1524-0 === weof_dev="binlog" (/mnt/space2/bacula/storage/)

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-23-3
PrevVolName       : 
VolFile           : 0
LabelType         : PRE_LABEL
LabelSize         : 0
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 23-Jul-2015 04:00
pc-backup2-sd: label.c:397-0 Call reserve_volume
pc-backup2-sd: vol_mgr.c:349-0 enter reserve_volume=Binlog-Full-2015-07-23-3 drive="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List begin reserve_volume: Binlog-Full-2015-07-23-3 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:364-0 Vol attached=Binlog-Full-2015-07-23-3, newvol=Binlog-Full-2015-07-23-3 volinuse=1 on "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:372-0 === set reserved vol=Binlog-Full-2015-07-23-3 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:467-0 === set in_use. vol=Binlog-Full-2015-07-23-3 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List end new volume: Binlog-Full-2015-07-23-3 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: mount.c:714-0 dir_update_vol_info. Set Append
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=0
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 UpdateMedia VolName=Binlog-Full-2015-07-23-3 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Append Slot=0 relabel=1 InChanger=0 VolReadTime=0 VolWriteTime=0 VolFirstWritten=0 VolParts=0
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-3 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2623
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: dev.c:366-0 Close fd for mode change.
pc-backup2-sd: dev.c:376-0 open dev: type=1 dev_name="binlog" (/mnt/space2/bacula/storage/) vol=Binlog-Full-2015-07-23-3 mode=OPEN_READ_WRITE
pc-backup2-sd: dev.c:385-0 call open_file_device mode=OPEN_READ_WRITE
pc-backup2-sd: dev.c:1896-0 Enter mount
pc-backup2-sd: dev.c:562-0 open disk: mode=OPEN_READ_WRITE open(/mnt/space2/bacula/storage/Binlog-Full-2015-07-23-3, 0x2, 0640)
pc-backup2-sd: dev.c:577-0 open dev: disk fd=13 opened, part=0/0, part_size=1525160568
pc-backup2-sd: dev.c:389-0 preserve=0x40 fd=13
pc-backup2-sd: label.c:79-0 Enter read_volume_label res=4 device="binlog" (/mnt/space2/bacula/storage/) vol=Binlog-Full-2015-07-23-3 dev_Vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:128-0 Big if statement in read_volume_label
pc-backup2-sd: block.c:955-0 Full read in read_block_from_device() len=64512
pc-backup2-sd: block.c:1009-0 Read device got 225 bytes at 0:0
pc-backup2-sd: block.c:298-0 unser_block_header block_len=225
pc-backup2-sd: block.c:309-0 Read binbuf = 201 24 block_len=225
pc-backup2-sd: block.c:1145-0 At end of read block
pc-backup2-sd: block.c:1159-0 Exit read_block read_len=225 block_len=225
pc-backup2-sd: label.c:822-0 unser_vol_label

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-23-3
PrevVolName       : 
VolFile           : 0
LabelType         : PRE_LABEL
LabelSize         : 189
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 23-Jul-2015 04:00
pc-backup2-sd: label.c:200-0 Compare Vol names: VolName=Binlog-Full-2015-07-23-3 hdr=Binlog-Full-2015-07-23-3

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : Binlog-Full-2015-07-23-3
PrevVolName       : 
VolFile           : 0
LabelType         : PRE_LABEL
LabelSize         : 189
PoolName          : Binlog-Full
MediaType         : binlog
PoolType          : Backup
HostName          : pc-backup2
Date label written: 23-Jul-2015 04:00
pc-backup2-sd: label.c:221-0 Leave read_volume_label() VOL_OK
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:234-0 Call reserve_volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: vol_mgr.c:349-0 enter reserve_volume=Binlog-Full-2015-07-23-3 drive="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List begin reserve_volume: Binlog-Full-2015-07-23-3 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:364-0 Vol attached=Binlog-Full-2015-07-23-3, newvol=Binlog-Full-2015-07-23-3 volinuse=1 on "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:372-0 === set reserved vol=Binlog-Full-2015-07-23-3 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:467-0 === set in_use. vol=Binlog-Full-2015-07-23-3 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: vol_mgr.c:208-0 List end new volume: Binlog-Full-2015-07-23-3 in_use=1 on device "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: mount.c:385-0 Want dirVol=Binlog-Full-2015-07-23-3 dirStat=Append
pc-backup2-sd: mount.c:393-0 Vol OK name=Binlog-Full-2015-07-23-3
pc-backup2-sd: mount.c:246-0 Do not have volcatinfo
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 GetVolInfo VolName=Binlog-Full-2015-07-23-3 write=1
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-3 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2623
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: label.c:433-0 set append found freshly labeled volume. fd=13 dev=eab418
pc-backup2-sd: label.c:266-0 write Label in write_volume_label_to_block()
pc-backup2-sd: label.c:596-0 Created Vol label rec: FI=VOL_LABEL len=189
pc-backup2-sd: label.c:281-0 Wrote label of 189 bytes to block. Vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: label.c:440-0 wrote vol label to block. Vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: dev.c:591-0 rewind res=4 fd=13 "binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: label.c:489-0 Attempt to write to device fd=13.
pc-backup2-sd: block.c:454-0 binbuf=225 buf_len=64512
pc-backup2-sd: label.c:514-0 dir_update_vol_info. Set Append vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=225
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 UpdateMedia VolName=Binlog-Full-2015-07-23-3 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=225 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Append Slot=0 relabel=1 InChanger=0 VolReadTime=0 VolWriteTime=5 VolFirstWritten=1437616801 VolParts=0
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-3 VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=225 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=5 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2623
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: label.c:532-0 OK from rewrite vol label. Vol=Binlog-Full-2015-07-23-3
pc-backup2-sd: mount.c:307-0 set APPEND, normal return from mount_next_write_volume. dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: acquire.c:432-0 Output pos=0:224
pc-backup2-sd: lock.c:267-0 unblock BST_DOING_ACQUIRE from acquire.c:434
pc-backup2-sd: sd_plugins.c:111-0 No bplugin_list: generate_plugin_event ignored.
pc-backup2-sd: acquire.c:449-0 === nwriters=2 nres=4 vcatjob=1 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: askdir.c:346-0 Update cat VolBytes=225
pc-backup2-sd: askdir.c:369-0 >dird CatReq Job=pc-db13-2-MysqlBinlog.2015-07-23_04.00.00_49 UpdateMedia VolName=Binlog-Full-2015-07-23-3 VolJobs=1 VolFiles=0 VolBlocks=0 VolBytes=225 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=26843545600 EndTime=1437616801 VolStatus=Append Slot=0 relabel=0 InChanger=0 VolReadTime=0 VolWriteTime=5 VolFirstWritten=0 VolParts=0
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-3 VolJobs=1 VolFiles=0 VolBlocks=0 VolBytes=225 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=5 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2623
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: reserve.c:136-0 Dec reserve=3 dev="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: append.c:98-0 Begin append device="binlog" (/mnt/space2/bacula/storage/)
pc-backup2-sd: append.c:103-0 Just after acquire_device_for_append
pc-backup2-sd: label.c:711-0 session_label record=400f0150
pc-backup2-sd: label.c:756-0 Write sesson_label record JobId=36273 FI=SOS_LABEL SessId=560 Strm=36273 len=196 remainder=0
pc-backup2-sd: label.c:760-0 Leave write_session_label Block=224d File=0d
pc-backup2-sd: acquire.c:383-0 acquire_append device is disk
pc-backup2-sd: askdir.c:231-0 >dird CatReq Job=pc-db12-2-MysqlBinlog.2015-07-23_04.00.00_50 GetVolInfo VolName=Binlog-Full-2015-07-23-3 write=1
pc-backup2-sd: askdir.c:182-0 <dird 1000 OK VolName=Binlog-Full-2015-07-23-3 VolJobs=1 VolFiles=0 VolBlocks=0 VolBytes=225 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=26843545600 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=5 EndFile=0 EndBlock=0 VolParts=0 LabelType=0 MediaId=2623
pc-backup2-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 Volume=Binlog-Full-2015-07-23-3
pc-backup2-sd: acquire.c:403-0 device already in append.

------- 8< ---------------------