fs0-sd: autochanger.c:99-0 Device "TapeStorageLTO5" (/dev/nst0) is not an autochanger fs0-sd: mount.c:144-0 autoload_dev returns 0 fs0-sd: mount.c:175-0 want vol=WeeklyData-LTO5-0001 devvol= dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: dev.c:536-0 open dev: type=2 dev_name="TapeStorageLTO5" (/dev/nst0) vol=WeeklyData-LTO5-0001 mode=OPEN_READ_WRITE fs0-sd: dev.c:540-0 call open_device mode=OPEN_READ_WRITE fs0-sd: dev.c:941-0 Enter mount fs0-sd: generic_tape_device.c:48-0 Open dev: device is tape fs0-sd: generic_tape_device.c:59-0 Try open "TapeStorageLTO5" (/dev/nst0) mode=OPEN_READ_WRITE fs0-sd: generic_tape_device.c:87-0 Rewind after open fs0-sd: generic_tape_device.c:985-0 In set_os_device_parameters fs0-sd: generic_tape_device.c:143-0 open dev: tape 6 opened fs0-sd: dev.c:544-0 preserve=0x0 fd=6 fs0-sd: dev.c:486-0 setting minblocksize to 64512, maxblocksize to label_block_size=64512, on device "TapeStorageLTO5" (/dev/nst0) fs0-sd: block.c:130-0 created new block of blocksize 64512 (dev->max_block_size) fs0-sd: dev.c:499-0 created new block of buf_len: 64512 on device "TapeStorageLTO5" (/dev/nst0) fs0-sd: label.c:82-0 Enter read_volume_label res=1 device="TapeStorageLTO5" (/dev/nst0) vol=WeeklyData-LTO5-0001 dev_Vol=*NULL* max_blocksize=64512 fs0-sd: scsicrypto-sd.c:467-0 scsicrypto-sd: Not clearing crypto key because encryption is currently not enabled on drive fs0-sd: label.c:146-0 Big if statement in read_volume_label fs0-sd: label.c:909-0 unser_vol_label Volume Label: Id : Bacula 1.0 immortal VerNo : 11 VolName : WeeklyData-LTO5-0001 PrevVolName : VolFile : 0 LabelType : VOL_LABEL LabelSize : 184 PoolName : WeeklyData MediaType : LTO5 PoolType : Backup HostName : fs0.terreactive.ch Date label written: 13-Feb-2015 09:32 fs0-sd: label.c:219-0 Compare Vol names: VolName=WeeklyData-LTO5-0001 hdr=WeeklyData-LTO5-0001 Volume Label: Id : Bacula 1.0 immortal VerNo : 11 VolName : WeeklyData-LTO5-0001 PrevVolName : VolFile : 0 LabelType : VOL_LABEL LabelSize : 184 PoolName : WeeklyData MediaType : LTO5 PoolType : Backup HostName : fs0.terreactive.ch Date label written: 13-Feb-2015 09:32 fs0-sd: label.c:240-0 Leave read_volume_label() VOL_OK fs0-sd: label.c:257-0 Call reserve_volume=WeeklyData-LTO5-0001 fs0-sd: vol_mgr.c:373-0 enter reserve_volume=WeeklyData-LTO5-0001 drive="TapeStorageLTO5" (/dev/nst0) fs0-sd: vol_mgr.c:571-0 Inc walk_start use_count=2 volname=WeeklyData-LTO5-0001 fs0-sd: vol_mgr.c:219-0 List begin reserve_volume: WeeklyData-LTO5-0001 in_use=1 swap=0 on device "TapeStorageLTO5" (/dev/nst0) fs0-sd: vol_mgr.c:400-0 Vol attached=WeeklyData-LTO5-0001, newvol=WeeklyData-LTO5-0001 volinuse=1 on "TapeStorageLTO5" (/dev/nst0) fs0-sd: vol_mgr.c:408-0 === set reserved vol=WeeklyData-LTO5-0001 dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: vol_mgr.c:533-0 === set in_use. vol=WeeklyData-LTO5-0001 dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: vol_mgr.c:571-0 Inc walk_start use_count=2 volname=WeeklyData-LTO5-0001 fs0-sd: vol_mgr.c:219-0 List end new volume: WeeklyData-LTO5-0001 in_use=1 swap=0 on device "TapeStorageLTO5" (/dev/nst0) fs0-sd: askdir.c:246-0 >dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 GetVolInfo VolName=WeeklyData-LTO5-0001 write=0 fs0-sd: askdir.c:175-0 VolMinBlocksize(0) to vol.VolMinBlocksize(0) fs0-sd: askdir.c:215-0 setting dcr->VolMaxBlocksize(0) to vol.VolMaxBlocksize(0) fs0-sd: scsicrypto-sd.c:401-0 scsicrypto-sd: Loading new crypto key fs0-sd: dev.c:416-0 Device "TapeStorageLTO5" (/dev/nst0) has dev->device->max_block_size of 1048576 and dev->max_block_size of 64512, dcr->VolMaxBlocksize is 0 fs0-sd: dev.c:421-0 setting dev->max_block_size to dev->device->max_block_size=1048576 on device "TapeStorageLTO5" (/dev/nst0) because dcr->VolMaxBlocksize is 0 fs0-sd: dev.c:458-0 set minblocksize to 0, maxblocksize to 1048576 on device "TapeStorageLTO5" (/dev/nst0) fs0-sd: dev.c:467-0 created new block of buf_len: 1048576 on device "TapeStorageLTO5" (/dev/nst0) fs0-sd: block.c:130-0 created new block of blocksize 1048576 (dev->max_block_size) fs0-sd: dev.c:471-0 created new block of buf_len: 1048576 on device "TapeStorageLTO5" (/dev/nst0), freeing block fs0-sd: mount.c:392-0 Want dirVol=WeeklyData-LTO5-0001 dirStat=Append fs0-sd: mount.c:400-0 Vol OK name=WeeklyData-LTO5-0001 fs0-sd: mount.c:283-0 Device previously written, moving to end of data. Expect 734245140480 bytes fs0-sd: generic_tape_device.c:168-0 Enter eod fs0-sd: generic_tape_device.c:202-0 Using EOM for EOM fs0-sd: generic_tape_device.c:225-0 EOD file=37 fs0-sd: generic_tape_device.c:289-0 EOD dev->file=37 fs0-sd: mount.c:301-0 update volinfo mounts=12 fs0-sd: askdir.c:353-0 Update cat VolBytes=734245140480 fs0-sd: askdir.c:375-0 >dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 UpdateMedia VolName=WeeklyData-LTO5-0001 VolJobs=1 VolFiles=37 VolBlocks=700231 VolBytes=734245140480 VolMounts=12 VolErrors=0 VolWrites=112 fs0-sd: askdir.c:175-0 VolMinBlocksize(0) to vol.VolMinBlocksize(0) fs0-sd: askdir.c:215-0 setting dcr->VolMaxBlocksize(0) to vol.VolMaxBlocksize(0) fs0-sd: mount.c:311-0 set APPEND, normal return from mount_next_write_volume. dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: acquire.c:417-0 Output pos=37:0 fs0-sd: acquire.c:428-0 === nwriters=1 nres=1 vcatjob=2 dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: askdir.c:353-0 Update cat VolBytes=734245140480 fs0-sd: askdir.c:375-0 >dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 UpdateMedia VolName=WeeklyData-LTO5-0001 VolJobs=2 VolFiles=37 VolBlocks=700231 VolBytes=734245140480 VolMounts=12 VolErrors=0 VolWrites=112 fs0-sd: askdir.c:175-0 VolMinBlocksize(0) to vol.VolMinBlocksize(0) fs0-sd: askdir.c:215-0 setting dcr->VolMaxBlocksize(0) to vol.VolMaxBlocksize(0) fs0-sd: reserve.c:134-0 Dec reserve=0 dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: append.c:89-0 Begin append device="TapeStorageLTO5" (/dev/nst0) fs0-sd: append.c:100-0 Just after acquire_device_for_append ### HERE THE ERROR OCCURS: fs0-sd: label.c:799-0 session_label record=fc007c80 fs0-sd: label.c:844-0 Write sesson_label record JobId=79 FI=SOS_LABEL SessId=6 Strm=79 len=162 remainder=0 fs0-sd: label.c:848-0 Leave write_session_label Block=0d File=37d fs0-sd: block.c:591-0 ===== write retry=1 status=-1 errno=16: ERR=Device or resource busy fs0-sd: block.c:591-0 ===== write retry=2 status=-1 errno=16: ERR=Device or resource busy fs0-sd: block.c:591-0 ===== write retry=3 status=-1 errno=16: ERR=Device or resource busy fs0-sd: block.c:660-0 === Write error. fd=6 size=1048576 rtn=-1 dev_blk=0 blk_blk=0 errno=16: ERR=Device or resource busy fs0-sd: generic_tape_device.c:357-0 === weof_dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: askdir.c:353-0 Update cat VolBytes=734245140480 fs0-sd: askdir.c:375-0 >dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 UpdateMedia VolName=WeeklyData-LTO5-0001 VolJobs=2 VolFiles=38 VolBlocks=700231 VolBytes=734245140480 VolMounts=12 VolErrors=1 VolWrites=112 fs0-sd: askdir.c:175-0 VolMinBlocksize(0) to vol.VolMinBlocksize(0) fs0-sd: askdir.c:215-0 setting dcr->VolMaxBlocksize(0) to vol.VolMaxBlocksize(0) fs0-sd: block.c:840-0 dir_update_volume_info terminate writing -- OK fs0-sd: block.c:868-0 *** Leave terminate_writing_volume -- OK fs0-sd: generic_tape_device.c:597-0 bsf fs0-sd: generic_tape_device.c:703-0 bsr_dev fs0-sd: device.c:90-0 === Enter fixup_device_block_write_error fs0-sd: block.c:130-0 created new block of blocksize 1048576 (dev->max_block_size) fs0-sd: device.c:116-0 set_unload dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: mount.c:71-0 Enter mount_next_volume(release=1) dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: mount.c:84-0 mount_next_vol retry=0 fs0-sd: scsicrypto-sd.c:457-0 scsicrypto-sd: Clearing crypto key fs0-sd: mount.c:542-0 must_unload release "TapeStorageLTO5" (/dev/nst0) fs0-sd: scsicrypto-sd.c:467-0 scsicrypto-sd: Not clearing crypto key because encryption is currently not enabled on drive fs0-sd: vol_mgr.c:738-0 === clear in_use vol=WeeklyData-LTO5-0001 fs0-sd: vol_mgr.c:743-0 === remove volume WeeklyData-LTO5-0001 dev="TapeStorageLTO5" (/dev/nst0) fs0-sd: dev.c:872-0 Clear volhdr vol=WeeklyData-LTO5-0001 fs0-sd: dev.c:883-0 close_dev "TapeStorageLTO5" (/dev/nst0) fs0-sd: dev.c:978-0 Enter unmount fs0-sd: dev.c:872-0 Clear volhdr vol= fs0-sd: mount.c:834-0 release_volume fs0-sd: mount.c:604-0 No swap_dev set fs0-sd: mount.c:346-0 Before dir_find_next_appendable_volume. fs0-sd: askdir.c:271-0 dir_find_next_appendable_volume: reserved=0 Vol= fs0-sd: askdir.c:288-0 >dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0 dird CatReq Job=DataBackup.2015-03-22_23.30.00_21 FindMedia=1 pool_name=WeeklyData media_type=LTO5 fs0-sd: askdir.c:175-0