Bacula-users

Re: [Bacula-users] Could not reserve volume "TestVolume1" for append (during btape fill)

2014-07-16 10:17:46
Subject: Re: [Bacula-users] Could not reserve volume "TestVolume1" for append (during btape fill)
From: Brian Debelius <bdebelius AT intelesyscorp DOT com>
To: Bacula Users <bacula-users AT lists.sourceforge DOT net>
Date: Wed, 16 Jul 2014 10:11:43 -0400
I turned debug 100 on, and here is the output.

btape: block_util.c:667-0 dir_update_volume_info max file size -- OK
Wrote block=6240000, file,blk=311,277 VolBytes=812,642,074,624 rate=67.50 MB/s
20:13:14 Flush block, write EOF
15-Jul 20:13 btape JobId 0: End of Volume "TestVolume1" at 311:4851 on device "Tape" (/dev/nst0). Write of 131072 bytes got -1.
btape: block.c:270-0 ==== Write error. fd=3 size=131072 rtn=-1 dev_blk=4851 blk_blk=6244574 errno=28: ERR=No space left on device
btape: block.c:273-0 Calling terminate_writing_volume
btape: block_util.c:570-0 Set VolCatStatus Full size=813241597952 vol=TestVolume1
btape: tape_dev.c:702-0 bsf
btape: tape_dev.c:803-0 bsr_dev
15-Jul 20:13 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2711-0 Last block at: 311:4850 this_dev_block_num=4851
btape: btape.c:2746-0 End of tape 311:0. Volume Bytes=813,241,597,952. Write rate = 67.43 MB/s
btape: btape.c:2316-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
btape: btape.c:2385-0 Wrote state file last_block_num1=4850 last_block_num2=0
btape: btape.c:2400-0

20:13:34 Done filling tape at 311:0. Now beginning re-read of tape ...
btape: btape.c:2481-0 Enter do_unfill
btape: dev.c:549-0 close_dev vol=TestVolume1 fd=3 dev=228e218 dev="Tape" (/dev/nst0)
btape: dev.c:656-0 Enter unmount
btape: dev.c:537-0 Clear volhdr vol=TestVolume1
btape: acquire.c:55-0 dcr=228ed58 dev=228e218
btape: acquire.c:56-0 MediaType dcr= dev=Tape
btape: acquire.c:89-0 Want Vol=TestVolume1 Slot=1
btape: acquire.c:103-0 MediaType dcr= dev=Tape
btape: acquire.c:180-0 MediaType dcr= dev=Tape
btape: acquire.c:197-0 dir_get_volume_info vol=TestVolume1
btape: btape.c:3017-0 Enter dir_get_volume_info
btape: mount.c:614-0 No swap_dev set. dev->vol=228f3f8
btape: mount.c:571-0 Must load dev="Tape" (/dev/nst0)
btape: autochanger.c:102-0 Device "Tape" (/dev/nst0) is not an autochanger
btape: acquire.c:228-0 open vol=TestVolume1
btape: tape_dev.c:81-0 Open dev: device is tape
btape: tape_dev.c:96-0 Try open "Tape" (/dev/nst0) mode=OPEN_READ_ONLY
btape: tape_dev.c:118-0 Rewind after open
btape: os.c:55-0 In set_os_device_parameters
btape: os.c:77-0 MTSETDRVBUFFER
btape: tape_dev.c:170-0 open dev: tape 3 opened
btape: dev.c:403-0 preserve=0x0 fd=3
btape: dev.c:406-0 open dev: fd=3 dev=228e5a6 dcr=228e218 vol= type=2 dev_name="Tape" (/dev/nst0) mode=OPEN_READ_ONLY
btape: acquire.c:236-0 opened dev "Tape" (/dev/nst0) OK
btape: acquire.c:239-0 calling read-vol-label
btape: label.c:72-0 Enter read_volume_label res=0 device="Tape" (/dev/nst0) vol=TestVolume1 dev_Vol=*NULL*
btape: label.c:885-0 reclen=172 recdata=Bacula 1.0 immortal

btape: label.c:887-0 reclen=172 recdata=Bacula 1.0 immortal


Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : TestVolume1
PrevVolName       :
VolFile           : 0
LabelType         : PRE_LABEL
LabelSize         : 172
PoolName          : Default
MediaType         : Tape
PoolType          : Backup
HostName          : backup.intelesys.local
Date label written: 15-Jul-2014 16:52

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : TestVolume1
PrevVolName       :
VolFile           : 0
LabelType         : PRE_LABEL
LabelSize         : 172
PoolName          : Default
MediaType         : Tape
PoolType          : Backup
HostName          : backup.intelesys.local
Date label written: 15-Jul-2014 16:52
btape: label.c:229-0 Call reserve_volume=TestVolume1
btape: acquire.c:263-0 Vol name=TestVolume1 want=TestVolume1 drv="Tape" (/dev/nst0).
btape: dev.c:549-0 close_dev vol=TestVolume1 fd=3 dev=228e218 dev="Tape" (/dev/nst0)
btape: dev.c:656-0 Enter unmount
btape: dev.c:537-0 Clear volhdr vol=TestVolume1
15-Jul 20:14 btape JobId 0: Warning: acquire.c:276 Read acquire: vol_mgr.c:382 Could not reserve volume "TestVolume1" for append, because it will be read.
btape: acquire.c:278-0 default path
btape: acquire.c:293-0 calling autoload Vol=TestVolume1 Slot=1
btape: autochanger.c:102-0 Device "Tape" (/dev/nst0) is not an autochanger
btape: acquire.c:302-0 calling dir_ask_sysop
btape: btape.c:3038-0 Enter dir_ask_sysop_to_mount_volume
block.c:443 Read zero bytes Vol= at -1 on device "Tape" (/dev/nst0).
Mount Volume "TestVolume1" on device "Tape" (/dev/nst0) and press return when ready: btape: dev.c:549-0 close_dev vol= fd=-1 dev=228e218 dev="Tape" (/dev/nst0)



On 07/11/2014 05:41 PM, Brian Debelius wrote:
It looks like even though I chose the (s)ingle tape fill, it is still running a (m)ultiple tape fill?

btape: btape.c:2316-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...



On 07/11/2014 01:56 PM, Brian Debelius wrote:
Just added Minimum Block Size = 262144 with the same result.  Trying a different block size now.

On 07/11/2014 10:19 AM, Brian Debelius wrote:
Centos 7 x86_64
Bacula 7.0.4
Tape HP Ultrium LTO-4

Hello,

I am testing out CentOS 7 and bacula 7.0.4.  Btape Test completes without error.  Btape Fill completes without error, but on its attempt to rewind and read the tape label it responds 'Could not reserve volume "TestVolume1" for append, because it will be read.'. Has anyone else seen this?

Wrote block=3120000, file,blk=156,138 VolBytes=812,641,943,552 rate=72.92 MB/s
10-Jul 19:01 btape JobId 0: End of Volume "TestVolume1" at 156:3366 on device "Tape" (/dev/nst0). Write of 262144 bytes got -1.
10-Jul 19:01 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2711-0 Last block at: 156:3365 this_dev_block_num=3366
btape: btape.c:2746-0 End of tape 156:0. Volume Bytes=813,488,144,384. Write rate = 72.84 MB/s
btape: btape.c:2316-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
btape: btape.c:2385-0 Wrote state file last_block_num1=3365 last_block_num2=0
btape: btape.c:2400-0

19:01:59 Done filling tape at 156:0. Now beginning re-read of tape ...
btape: btape.c:2481-0 Enter do_unfill
10-Jul 19:02 btape JobId 0: Warning: acquire.c:276 Read acquire: vol_mgr.c:382 Could not reserve volume "TestVolume1" for append, because it will be read.
block.c:443 Read zero bytes Vol= at -1 on device "Tape" (/dev/nst0).
Mount Volume "TestVolume1" on device "Tape" (/dev/nst0) and press return when ready:

Bacula-sd.conf:

Device {
  Name = Tape
  Drive Index = 0
  Device Type = Tape
  Archive Device = /dev/nst0
  Automatic Mount = yes
  Removable Media = yes
  Random Access = no
  Media Type = Tape
  Autochanger = no
  Auto Select = yes
  Always Open = yes
  Maximum Block Size = 262144
  Maximum File Size = 4G
  Maximum Spool Size = 100G
  Maximum Job Spool Size = 20G
  Maximum Network Buffer Size = 65536
  Spool Directory = /tank/bacula-spool
}




------------------------------------------------------------------------------
Want fast and easy access to all the code in your enterprise? Index and
search up to 200,000 lines of code with a free copy of Black Duck
Code Sight - the same software that powers the world's largest code
search on Ohloh, the Black Duck Open Hub! Try it now.
http://p.sf.net/sfu/bds
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users