I'm not sure if this is a configuration problem or not.  The problem recurred 
later in the day when the pool filled up.

> On Sep 6, 2015, at 11:16 AM, Dan Langille <d...@langille.org 
> <mailto:d...@langille.org>> wrote:
> 
> 
>> On Sep 6, 2015, at 9:51 AM, Dan Langille <d...@langille.org 
>> <mailto:d...@langille.org>> wrote:
>> 
>> This is a long post but contains details which might hint at the cause of 
>> the problem.
>> 
>> The backups have resumed, but the underlying problem persists.
>> 
>> 
>>> On Sep 4, 2015, at 3:34 PM, Dan Langille <d...@langille.org 
>>> <mailto:d...@langille.org>> wrote:
>>> 
>>> 
>>>> On Sep 3, 2015, at 12:26 AM, Ana Emília M. Arruda <emiliaarr...@gmail.com 
>>>> <mailto:emiliaarr...@gmail.com>> wrote:
>>>> 
>>>> Hello Dan,
>>>> 
>>>> On Wed, Sep 2, 2015 at 11:06 PM, Dan Langille <d...@langille.org 
>>>> <mailto:d...@langille.org>> wrote:
>>>> 
>>>>> On Aug 25, 2015, at 6:55 PM, Ana Emília M. Arruda <emiliaarr...@gmail.com 
>>>>> <mailto:emiliaarr...@gmail.com>> wrote:
>>>>> 
>>>>> Hello Dan,
>>>>> 
>>>>> Heitor is right :)
>>>> 
>>>> Thank you.
>>>> 
>>>> Ana: what are you using to quickly test these configurations?  I suspect a 
>>>> VM or similar.
>>>> 
>>>> ​You're welcome. Yes, I have VMs for testing purposes :).​ 
>>>> 
>>>>> 
>>>>> I run tests with exactly your configuration and had the same issue. The 
>>>>> drive index 0 must exist and belongs to the autochanger resource. You 
>>>>> have an Index 0 drive in your configuration: vRestore. But it is not in 
>>>>> the Autochanger definition. If you put it there, it will work:
>>>>> 
>>>>> Autochanger {
>>>>>   Name = VirtualDisk
>>>>> 
>>>>>   Changer Device  = /dev/null
>>>>>   Changer Command = /dev/null
>>>>> 
>>>>>   Device          = vRestore, vDrive-1, vDrive-2, vDrive-3, vDrive-4, 
>>>>> vDrive-5
>>>>> }
>>>>> 
>>>>> I tried defining the vRestore drive with "autoselect = no" (this work for 
>>>>> physical autochangers). But it seems to make no sense when dealing with 
>>>>> virtual disk autochangers.
>>>> 
>>>> Do we need vRestore in there?  Instead, I renumbered my Drive Index fields 
>>>> from zero.
>>>> 
>>>> ​No, I just added it to the device list because vRestore was configured as 
>>>> an autochanger drive with index 0. I think your solution is better, since 
>>>> we cannot select a specific drive for restores in the case of virtual 
>>>> autochangers.
>>>>  
>>>> 
>>>> Autochanger {
>>>>   Name = VirtualDisk
>>>> 
>>>>   Changer Device  = /dev/null
>>>>   Changer Command = /dev/null
>>>> 
>>>>   Device          = vDrive-1, vDrive-2, vDrive-3, vDrive-4, vDrive-5
>>>> }
>>> 
>>> 
>>> FYI, I made a change.  I now use vDrive-0 .. vDrive-4
>>> 
>>> I renamed the devices to match the drive indexes. There is no technical 
>>> reason for this.  I did it because I like the matching numbers.
>>> 
>>>> 
>>>> Device {
>>>>   Name           = vDrive-1
>>>>   Media Type     = File
>>>>   Archive Device = /usr/local/bacula/volumes
>>>>   LabelMedia     = yes
>>>>   Random Access  = yes
>>>>   AutomaticMount = yes
>>>>   RemovableMedia = no
>>>>   AlwaysOpen     = no
>>>> 
>>>>   Autochanger    = yes
>>>>   Drive Index    = 0
>>>> 
>>>>   Maximum Concurrent Jobs = 1
>>>>   Volume Poll Interval    = 15
>>>> }
>>>> 
>>>> Device {
>>>>   Name           = vDrive-2
>>>> ...same as above
>>>>   Autochanger    = yes
>>>>   Drive Index    = 1
>>>> 
>>>>   Maximum Concurrent Jobs = 1
>>>>   Volume Poll Interval    = 15
>>>> }
>>>> 
>>>> Device {
>>>>   Name           = vDrive-3
>>>> ...same as above
>>>>   Autochanger    = yes
>>>>   Drive Index    = 2
>>>> 
>>>>   Maximum Concurrent Jobs = 1
>>>>   Volume Poll Interval    = 15
>>>> }
>>>> 
>>>> Device {
>>>>   Name           = vDrive-4
>>>> ...same as above
>>>>   Autochanger    = yes
>>>>   Drive Index    = 3
>>>> 
>>>>   Maximum Concurrent Jobs = 1
>>>>   Volume Poll Interval    = 15
>>>> }
>>>> 
>>>> Device {
>>>>   Name           = vDrive-5
>>>> ...same as above
>>>>   Autochanger    = yes
>>>>   Drive Index    = 4
>>>> 
>>>>   Maximum Concurrent Jobs = 25
>>>>   Volume Poll Interval    = 15
>>>> }
>>>> 
>>>> 
>>>>> 
>>>>> Having a single drive for restores worked for me. I was able to restore 
>>>>> files from jobs/volumes that used the autochanger for backup.
>>>>>  
>>>>> ​​Device {
>>>>>   Name           = Restore​-Drive​
>>>>>   Media Type     = File
>>>>>   Archive Device = /usr/local/bacula/volumes
>>>>>   LabelMedia     = yes
>>>>>   Random Access  = yes
>>>>>   AutomaticMount = yes
>>>>>   RemovableMedia = yes
>>>>>   AlwaysOpen     = yes​​
>>>>> }
>>>> 
>>>> I have this in my bacula-sd.conf:
>>>> 
>>>> Device {
>>>>   Name           = Restore-Drive
>>>>   Media Type     = File
>>>>   Archive Device = /usr/local/bacula/volumes
>>>>   LabelMedia     = yes
>>>>   Random Access  = yes
>>>>   AutomaticMount = yes
>>>>   RemovableMedia = no
>>>>   AlwaysOpen     = no
>>>> 
>>>>   Maximum Concurrent Jobs = 1
>>>>   Volume Poll Interval    = 15
>>>> }
>>>> 
>>>> When I run a restore job, it selects vDrive-1 automatically.
>>>> 
>>>> ​Yes, if you select the virtual autochanger storage for restore, the drive 
>>>> index 0 will be selected for the restore.​
>>>>  
>>>> 
>>>> How did you get the restore to use Restore-Drive?
>>>> 
>>>> I configured the Restore-Drive as a storage in bacula-dir.conf (both 
>>>> Restore-Drive and VirtualDisk drives configured with the same archive 
>>>> device). This way we can choose the Restore-Drive for restoring files that 
>>>> are in volumes in the same mount point as the virtual autochanger.
>>>> 
>>> 
>>> That is what I suspected, but I wanted to make sure I did not 
>>> misunderstand.  I've done the same and can restore from the Restore-Drive.
>>> 
>> 
>> Today, being the first Sunday of the month, full backups are underway.  The 
>> original problem has returned.
>> 
>> 06-Sep 07:05 crey-sd JobId 216727: New volume "FullAuto-3234" mounted on 
>> device "vDrive-2" (/usr/local/bacula/volumes) at 06-Sep-2015 07:05.
>> 06-Sep 07:09 crey-sd JobId 216721: End of medium on Volume "FullAuto-3233" 
>> Bytes=5,368,688,700 Blocks=83,220 at 06-Sep-2015 07:09.
>> 06-Sep 07:09 bacula-dir JobId 216721: There are no more Jobs associated with 
>> Volume "FullAuto-3235". Marking it purged.
>> 06-Sep 07:09 bacula-dir JobId 216721: All records pruned from Volume 
>> "FullAuto-3235"; marking it "Purged"
>> 06-Sep 07:09 bacula-dir JobId 216721: Recycled volume "FullAuto-3235"
>> 06-Sep 07:09 crey-sd JobId 216721: Recycled volume "FullAuto-3235" on file 
>> device "vDrive-3" (/usr/local/bacula/volumes), all previous data lost.
>> 06-Sep 07:09 crey-sd JobId 216721: New volume "FullAuto-3235" mounted on 
>> device "vDrive-3" (/usr/local/bacula/volumes) at 06-Sep-2015 07:09.
>> 06-Sep 07:13 crey-sd JobId 216727: End of medium on Volume "FullAuto-3234" 
>> Bytes=5,368,688,757 Blocks=83,220 at 06-Sep-2015 07:13.
>> 06-Sep 07:14 crey-sd JobId 216727: Job 
>> zuul_jail_snapshots.2015-09-06_03.05.47_33 is waiting. Cannot find any 
>> appendable volumes.
>> Please use the "label" command to create a new Volume for:
>>     Storage:      "vDrive-2" (/usr/local/bacula/volumes)
>>     Pool:         FullFile
>>     Media type:   File
>> 06-Sep 07:19 crey-sd JobId 216721: End of medium on Volume "FullAuto-3235" 
>> Bytes=5,368,688,722 Blocks=83,220 at 06-Sep-2015 07:19.
>> 06-Sep 07:20 crey-sd JobId 216721: Job 
>> slocum_jail_snapshots.2015-09-06_03.05.17_27 is waiting. Cannot find any 
>> appendable volumes.
>> Please use the "label" command to create a new Volume for:
>>     Storage:      "vDrive-3" (/usr/local/bacula/volumes)
>>     Pool:         FullFile
>>     Media type:   File
>> 
>> ...
>> 
>> I amended the pool definition, increasing 'Maximum Volumes'.  In bconsole, I 
>> issued a reload and:
>> 
>>  $ bconsole 
>> Connecting to Director bacula.int.unixathome.org 
>> <http://bacula.int.unixathome.org/>:9101
>> 1000 OK: 1 bacula-dir Version: 7.0.5 (28 July 2014)
>> Enter a period to cancel a command.
>> *m
>> You have no messages.
>> *reload
>> *m
>> You have no messages.
>> *mount
>> Automatically selected Catalog: MyCatalog
>> Using Catalog "MyCatalog"
>> The defined Storage resources are:
>>      1: CreyFile
>>      2: CreyFileRestore
>>      3: CompaqStorageWorksTapeLibrary
>> Select Storage resource (1-3): 1
>> Connecting to Storage daemon CreyFile at crey.int.unixathome.org 
>> <http://crey.int.unixathome.org/>:9103 ...
>> Enter autochanger drive[0]: 
>> Enter autochanger slot: 
>> 3906 File device ""vDrive-0" (/usr/local/bacula/volumes)" is always mounted.
>> *m
>> You have no messages.
>> 
>> *m
>> 06-Sep 11:54 bacula-dir JobId 216721: Created new Volume="FullAuto-4875", 
>> Pool="FullFile", MediaType="File" in catalog.
>> 06-Sep 11:54 bacula-dir JobId 0: Max configured use duration=86,400 sec. 
>> exceeded. Marking Volume "TwoHourly-4395" as Used.
>> 06-Sep 11:54 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
>> "vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4875" failed: 
>> ERR=file_dev.c:172 Could not 
>> open(/usr/local/bacula/volumes/FullAuto-4875,OPEN_READ_WRITE,0640): ERR=No 
>> such file or directory
>> 
>> 06-Sep 11:54 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
>> "vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4875" failed: 
>> ERR=file_dev.c:172 Could not 
>> open(/usr/local/bacula/volumes/FullAuto-4875,OPEN_READ_WRITE,0640): ERR=No 
>> such file or directory
>> 
>> 06-Sep 11:54 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
>> "vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4875" failed: 
>> ERR=file_dev.c:172 Could not 
>> open(/usr/local/bacula/volumes/FullAuto-4875,OPEN_READ_WRITE,0640): ERR=No 
>> such file or directory
>> 
>> 06-Sep 11:54 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
>> "vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4875" failed: 
>> ERR=file_dev.c:172 Could not 
>> open(/usr/local/bacula/volumes/FullAuto-4875,OPEN_READ_WRITE,0640): ERR=No 
>> such file or directory
>> 
>> It is having a similar problem with another volume creation:
>> 
>> 06-Sep 11:00 crey-sd JobId 216727: Job 
>> zuul_jail_snapshots.2015-09-06_03.05.47_33 is waiting. Cannot find any 
>> appendable volumes.
>> Please use the "label" command to create a new Volume for:
>>     Storage:      "vDrive-2" (/usr/local/bacula/volumes)
>>     Pool:         FullFile
>>     Media type:   File
>> 06-Sep 11:55 bacula-dir JobId 216727: Created new Volume="FullAuto-4876", 
>> Pool="FullFile", MediaType="File" in catalog.
>> 06-Sep 11:55 crey-sd JobId 216727: Warning: mount.c:212 Open of file device 
>> "vDrive-2" (/usr/local/bacula/volumes) Volume "FullAuto-4876" failed: 
>> ERR=file_dev.c:172 Could not 
>> open(/usr/local/bacula/volumes/FullAuto-4876,OPEN_READ_WRITE,0640): ERR=No 
>> such file or directory
>> 
>> 
>> 
>> 
>> I have confirmed the Catalog contains the Volume: 
>> 
>> bacula=# select mediaid, mediatype from media where volumename = 
>> 'FullAuto-4875';
>>  mediaid | mediatype 
>> ---------+-----------
>>     4875 | File
>> (1 row)
>> 
>> However, it is not on disk: 
>> 
>> [dan@crey:~] $ ls -ld /usr/local/bacula/volumes
>> drwxr-xr-x  3 bacula  bacula  2706 Aug 30 11:22 /usr/local/bacula/volumes
>> [dan@crey:~] $
>> 
>> $ ls -ld /usr/local/bacula/volumes/FullAuto-487*
>> ls: /usr/local/bacula/volumes/FullAuto-487*: No such file or directory
>> 
>> 
>> Disk space seems to not be the cause:
>> 
>> [dan@crey:~] $ df -h
>> Filesystem               Size    Used   Avail Capacity  Mounted on
>> system/usr/jails/crey    3.8T    820M    3.8T     0%    /
>> 
>> 
>> 
>> 
>> 
>> Then I tried another mount, this time, with incorrect values:
>> 
>> *mount
>> Automatically selected Catalog: MyCatalog
>> Using Catalog "MyCatalog"
>> The defined Storage resources are:
>>      1: CreyFile
>>      2: CreyFileRestore
>>      3: CompaqStorageWorksTapeLibrary
>> Select Storage resource (1-3): 1
>> Enter autochanger drive[0]: 2
>> Enter autochanger slot: 2
>> 3001 OK mount requested. Specified slot ignored. Device="vDrive-2" 
>> (/usr/local/bacula/volumes)
>> You have messages.
>> *m
>> 06-Sep 13:03 crey-sd JobId 216727: Labeled new Volume "FullAuto-4876" on 
>> file device "vDrive-2" (/usr/local/bacula/volumes).
>> 06-Sep 13:03 crey-sd JobId 216727: Wrote label to prelabeled Volume 
>> "FullAuto-4876" on file device "vDrive-2" (/usr/local/bacula/volumes)
>> 06-Sep 13:03 crey-sd JobId 216727: New volume "FullAuto-4876" mounted on 
>> device "vDrive-2" (/usr/local/bacula/volumes) at 06-Sep-2015 13:03.
>> *
>> 
>> But it continued to have trouble with FullAuto-4875
>> 
>> So I tried this, which failed:
>> 
>> *mount
>> The defined Storage resources are:
>>      1: CreyFile
>>      2: CreyFileRestore
>>      3: CompaqStorageWorksTapeLibrary
>> Select Storage resource (1-3): 1
>> Enter autochanger drive[0]: 2
>> Enter autochanger slot: 2
>> 3906 File device ""vDrive-2" (/usr/local/bacula/volumes)" is always mounted.
>> *m
>> 06-Sep 13:39 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
>> "vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4875" failed: 
>> ERR=file_dev.c:172 Could not 
>> open(/usr/local/bacula/volumes/FullAuto-4875,OPEN_READ_WRITE,0640): ERR=No 
>> such file or directory
>> 
>> 
>> Try a different approach:
>> 
>> *mount
>> The defined Storage resources are:
>>      1: CreyFile
>>      2: CreyFileRestore
>>      3: CompaqStorageWorksTapeLibrary
>> Select Storage resource (1-3): 2
>> 3906 File device ""Restore-Drive" (/usr/local/bacula/volumes)" is always 
>> mounted.
>> 
>> 
>> No, that didn't mount.
>> 
>> 
>> 
>> BUT THEN THIS WORKED:
>> 
>> *mount
>> The defined Storage resources are:
>>      1: CreyFile
>>      2: CreyFileRestore
>>      3: CompaqStorageWorksTapeLibrary
>> Select Storage resource (1-3): 1
>> Enter autochanger drive[0]: 3
>> Enter autochanger slot: 2
>> 3001 OK mount requested. Specified slot ignored. Device="vDrive-3" 
>> (/usr/local/bacula/volumes)
>> *m
>> You have no messages.
>> *m
>> You have no messages.
>> *m
>> 06-Sep 13:39 crey-sd JobId 216721: Labeled new Volume "FullAuto-4875" on 
>> file device "vDrive-3" (/usr/local/bacula/volumes).
>> 06-Sep 13:39 crey-sd JobId 216721: Wrote label to prelabeled Volume 
>> "FullAuto-4875" on file device "vDrive-3" (/usr/local/bacula/volumes)
>> 06-Sep 13:39 crey-sd JobId 216721: New volume "FullAuto-4875" mounted on 
>> device "vDrive-3" (/usr/local/bacula/volumes) at 06-Sep-2015 13:39.
>> *
> 
> FYI, later in the day, things worked OK:
> 
> 06-Sep 15:03 crey-sd JobId 216721: End of medium on Volume "FullAuto-4879" 
> Bytes=5,368,688,700 Blocks=83,220 at 06-Sep-2015 15:03.
> 06-Sep 15:03 bacula-dir JobId 216721: Created new Volume="FullAuto-4880", 
> Pool="FullFile", MediaType="File" in catalog.
> 06-Sep 15:04 crey-sd JobId 216721: Labeled new Volume "FullAuto-4880" on file 
> device "vDrive-3" (/usr/local/bacula/volumes).
> 06-Sep 15:04 crey-sd JobId 216721: Wrote label to prelabeled Volume 
> "FullAuto-4880" on file device "vDrive-3" (/usr/local/bacula/volumes)
> 06-Sep 15:04 crey-sd JobId 216721: New volume "FullAuto-4880" mounted on 
> device "vDrive-3" (/usr/local/bacula/volumes) at 06-Sep-2015 15:04.
> 
> It seems that once you run out of Volumes, things get confused.... but once 
> it picks up again, all is OK.
> 
> 
>> 
>> 
>> In that case, I specified 'autochanger drive' 3 and slot 2.
>> 
>> 
>> More of the above can be found at 
>> https://gist.github.com/dlangille/35ff347d0ad37e799015 
>> <https://gist.github.com/dlangille/35ff347d0ad37e799015>
>> 
>> 
>> Configuration:
>> 
>> Storage {                             # definition of myself
>>   Name = crey-sd
>>   WorkingDirectory = "/usr/local/bacula/working"
>>   Pid Directory = "/var/run"
>>   Maximum Concurrent Jobs = 20
>> 
>>   TLS Enable      = yes
>>   TLS Verify Peer = yes
>> 
>>   TLS CA Certificate File = /usr/local/etc/ssl/ca.pem
>> 
>>   TLS Certificate = /usr/local/etc/ssl/crey.int.unixathome.org.crt
>>   TLS Key         = /usr/local/etc/ssl/crey.int.unixathome.org.nopassword.key
>> 
>> }
>> 
>> #
>> # List Directors who are permitted to contact Storage daemon
>> #
>> Director {
>>   Name = bacula-dir
>>   Password = "redacted"
>> }
>> 
>> 
>> Device {
>>   Name           = Restore-Drive
>>   Media Type     = File
>>   Archive Device = /usr/local/bacula/volumes
>>   LabelMedia     = yes
>>   Random Access  = yes
>>   AutomaticMount = yes
>>   RemovableMedia = no
>>   AlwaysOpen     = no
>> 
>>   Maximum Concurrent Jobs = 2
>>   Volume Poll Interval    = 15
>> }
>> 
>> Autochanger {
>>   Name = VirtualDisk
>> 
>>   Changer Device  = /dev/null
>>   Changer Command = /dev/null
>> 
>>   Device          = vDrive-0, vDrive-1, vDrive-2, vDrive-3, vDrive-4
>> }
>> 
>> Device {
>>   Name           = vDrive-0
>>   Media Type     = File
>>   Archive Device = /usr/local/bacula/volumes
>>   LabelMedia     = yes
>>   Random Access  = yes
>>   AutomaticMount = yes
>>   RemovableMedia = no
>>   AlwaysOpen     = no
>> 
>>   Autochanger    = yes
>>   Drive Index    = 0
>> 
>>   Maximum Concurrent Jobs = 1
>>   Volume Poll Interval    = 15
>> }
>> 
>> Device {
>>   Name           = vDrive-1
>>   Media Type     = File
>>   Archive Device = /usr/local/bacula/volumes
>>   LabelMedia     = yes
>>   Random Access  = yes
>>   AutomaticMount = yes
>>   RemovableMedia = no
>>   AlwaysOpen     = no
>> 
>>   Autochanger    = yes
>>   Drive Index    = 1
>> 
>>   Maximum Concurrent Jobs = 1
>>   Volume Poll Interval    = 15
>> }
>> 
>> Device {
>>   Name           = vDrive-2
>>   Media Type     = File
>>   Archive Device = /usr/local/bacula/volumes
>>   LabelMedia     = yes
>>   Random Access  = yes
>>   AutomaticMount = yes
>>   RemovableMedia = no
>>   AlwaysOpen     = no
>> 
>>   Autochanger    = yes
>>   Drive Index    = 2
>> 
>>   Maximum Concurrent Jobs = 1
>>   Volume Poll Interval    = 15
>> }
>> 
>> Device {
>>   Name           = vDrive-3
>>   Media Type     = File
>>   Archive Device = /usr/local/bacula/volumes
>>   LabelMedia     = yes
>>   Random Access  = yes
>>   AutomaticMount = yes
>>   RemovableMedia = no
>>   AlwaysOpen     = no
>> 
>>   Autochanger    = yes
>>   Drive Index    = 3
>> 
>>   Maximum Concurrent Jobs = 1
>>   Volume Poll Interval    = 15
>> }
>> 
>> Device {
>>   Name           = vDrive-4
>>   Media Type     = File
>>   Archive Device = /usr/local/bacula/volumes
>>   LabelMedia     = yes
>>   Random Access  = yes
>>   AutomaticMount = yes
>>   RemovableMedia = no
>>   AlwaysOpen     = no
>> 
>>   Autochanger    = yes
>>   Drive Index    = 4
>> 
>>   Maximum Concurrent Jobs = 25
>>   Volume Poll Interval    = 15
>> }
>> 
>> Messages {
>>   Name = Standard
>>   director = bacula-dir = all
>> }
> 
> 

The problem is reproducible.

*m
06-Sep 21:40 crey-sd JobId 216721: Job 
slocum_jail_snapshots.2015-09-06_03.05.17_27 is waiting. Cannot find any 
appendable volumes.
Please use the "label" command to create a new Volume for:
    Storage:      "vDrive-3" (/usr/local/bacula/volumes)
    Pool:         FullFile
    Media type:   File
06-Sep 21:40 bacula-dir JobId 216715: Start Backup JobId 216715, 
Job=supernews.2015-09-06_03.05.15_21
06-Sep 21:41 bacula-dir JobId 216715: Using Device "vDrive-0" to write.
06-Sep 21:41 crey-sd JobId 216715: Job supernews.2015-09-06_03.05.15_21 is 
waiting. Cannot find any appendable volumes.
Please use the "label" command to create a new Volume for:
    Storage:      "vDrive-0" (/usr/local/bacula/volumes)
    Pool:         FullFile
    Media type:   File

I amended the pool to increase Max # Volumes for the pool.  Then:

*reload
*m
06-Sep 21:44 bacula-dir JobId 216715: Created new Volume="FullAuto-4905", 
Pool="FullFile", MediaType="File" in catalog.
06-Sep 21:44 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory


NOTE: it goes to try creating another Volume:


06-Sep 21:44 bacula-dir JobId 216721: Created new Volume="FullAuto-4906", 
Pool="FullFile", MediaType="File" in catalog.
06-Sep 21:44 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
"vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4906" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4906,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
"vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4906" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4906,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
"vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4906" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4906,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
"vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4906" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4906,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:44 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
"vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4906" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4906,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:45 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:45 crey-sd JobId 216721: Warning: mount.c:212 Open of file device 
"vDrive-3" (/usr/local/bacula/volumes) Volume "FullAuto-4906" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4906,OPEN_READ_WRITE,0640): ERR=No such 
file or directory


If I mount ON THE DRIVE it is looking for, it proceeds:

*mount
The defined Storage resources are:
     1: CreyFile
     2: CreyFileRestore
     3: CompaqStorageWorksTapeLibrary
Select Storage resource (1-3): 1
Connecting to Storage daemon CreyFile at crey.int.unixathome.org 
<http://crey.int.unixathome.org/>:9103 ...
Enter autochanger drive[0]: 3
Enter autochanger slot: 0
3001 OK mount requested. Device="vDrive-3" (/usr/local/bacula/volumes)
You have messages.
*m
06-Sep 21:46 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:46 crey-sd JobId 216721: Labeled new Volume "FullAuto-4906" on file 
device "vDrive-3" (/usr/local/bacula/volumes).
06-Sep 21:46 crey-sd JobId 216721: Wrote label to prelabeled Volume 
"FullAuto-4906" on file device "vDrive-3" (/usr/local/bacula/volumes)
06-Sep 21:46 crey-sd JobId 216721: New volume "FullAuto-4906" mounted on device 
"vDrive-3" (/usr/local/bacula/volumes) at 06-Sep-2015 21:46.
*

Let's try that theory again, on drive 0, which is where it's waiting:

*m
06-Sep 21:47 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

06-Sep 21:48 crey-sd JobId 216715: Warning: mount.c:212 Open of file device 
"vDrive-0" (/usr/local/bacula/volumes) Volume "FullAuto-4905" failed: 
ERR=file_dev.c:172 Could not 
open(/usr/local/bacula/volumes/FullAuto-4905,OPEN_READ_WRITE,0640): ERR=No such 
file or directory

*mount
The defined Storage resources are:
     1: CreyFile
     2: CreyFileRestore
     3: CompaqStorageWorksTapeLibrary
Select Storage resource (1-3): 1
Enter autochanger drive[0]: 0
Enter autochanger slot: 0
3001 OK mount requested. Device="vDrive-0" (/usr/local/bacula/volumes)
*m
06-Sep 21:48 crey-sd JobId 216715: Labeled new Volume "FullAuto-4905" on file 
device "vDrive-0" (/usr/local/bacula/volumes).
06-Sep 21:48 crey-sd JobId 216715: Wrote label to prelabeled Volume 
"FullAuto-4905" on file device "vDrive-0" (/usr/local/bacula/volumes)
*


It works again.



Storage status:

*st st
Automatically selected Storage: CreyFile
Connecting to Storage daemon CreyFile at crey.int.unixathome.org 
<http://crey.int.unixathome.org/>:9103

crey-sd Version: 7.0.5 (28 July 2014) amd64-portbld-freebsd10.2 freebsd 
10.2-RELEASE
Daemon started 04-Sep-15 19:21. Jobs: run=75, running=1.
 Heap: heap=0 smbytes=1,596,775 max_bytes=2,476,847 bufs=295 max_bufs=409
 Sizes: boffset_t=8 size_t=8 int32_t=4 int64_t=8 mode=0,0

Running Jobs:
Writing: Full Backup job slocum_jail_snapshots JobId=216721 
Volume="FullAuto-4906"
    pool="FullFile" device="vDrive-3" (/usr/local/bacula/volumes)
    spooling=0 despooling=0 despool_wait=0
    Files=911,814 Bytes=239,502,099,426 AveBytes/sec=5,464,380 
LastBytes/sec=5,473,595
    FDReadSeqNo=8,657,143 in_msg=6945579 out_msg=6 fd=19
Writing: Full Backup job supernews JobId=216715 Volume="FullAuto-4905"
    pool="FullFile" device="vDrive-0" (/usr/local/bacula/volumes)
    spooling=0 despooling=0 despool_wait=0
    Files=1,313 Bytes=73,874,694 AveBytes/sec=2,308,584 LastBytes/sec=2,308,584
    FDReadSeqNo=12,619 in_msg=8717 out_msg=6 fd=7
====

Jobs waiting to reserve a drive:
====

Terminated Jobs:
 JobId  Level    Files      Bytes   Status   Finished        Name 
===================================================================
216707  Full          0         0   OK       06-Sep-15 03:55 gelt_freshports_dev
216709  Full    381,907    83.27 G  OK       06-Sep-15 04:53 knew_jail_snapshots
216733  Incr        391    116.1 M  OK       06-Sep-15 12:03 mailjail_snapshot
216727  Full    497,384    126.0 G  OK       06-Sep-15 13:13 zuul_jail_snapshots
216734  Incr        191    87.04 M  OK       06-Sep-15 14:02 mailjail_snapshot
216735  Incr        261    90.91 M  OK       06-Sep-15 16:02 mailjail_snapshot
216736  Incr        111    70.74 M  OK       06-Sep-15 18:01 mailjail_snapshot
216737  Incr        177    79.18 M  OK       06-Sep-15 20:01 mailjail_snapshot
216713  Full   1,558,273    6.635 G  OK       06-Sep-15 20:54 supernews_FP_msgs
216714  Full      4,741    371.0 M  OK       06-Sep-15 21:34 supernews_basic
====

Device status:
Autochanger "VirtualDisk" with devices:
   "vDrive-0" (/usr/local/bacula/volumes)
   "vDrive-1" (/usr/local/bacula/volumes)
   "vDrive-2" (/usr/local/bacula/volumes)
   "vDrive-3" (/usr/local/bacula/volumes)
   "vDrive-4" (/usr/local/bacula/volumes)
Autochanger "Compaq Storage Works MSL5026" with devices:
   "DTL03" (/dev/nsa0)

Device "Restore-Drive" (/usr/local/bacula/volumes) is not open.
==

Device "vDrive-0" (/usr/local/bacula/volumes) is mounted with:
    Volume:      FullAuto-4905
    Pool:        FullFile
    Media type:  File
    Drive 0 is not loaded.
    Total Bytes=73,930,947 Blocks=1,146 Bytes/block=64,512
    Positioned at File=0 Block=73,930,946
==

Device "vDrive-1" (/usr/local/bacula/volumes) is not open.
    Drive 1 is not loaded.
==

Device "vDrive-2" (/usr/local/bacula/volumes) is not open.
    Drive 2 is not loaded.
==

Device "vDrive-3" (/usr/local/bacula/volumes) is mounted with:
    Volume:      FullAuto-4906
    Pool:        FullFile
    Media type:  File
    Drive 3 is not loaded.
    Total Bytes=4,499,196,004 Blocks=69,742 Bytes/block=64,512
    Positioned at File=1 Block=204,228,707
==

Device "vDrive-4" (/usr/local/bacula/volumes) is not open.
    Drive 4 is not loaded.
==

Device "DTL03" (/dev/nsa0) is mounted with:
    Volume:      FAI078
    Pool:        *unknown*
    Media type:  SDLT
    Slot 17 is loaded in drive 0.
    Total Bytes Read=0 Blocks Read=0 Bytes/block=0
    Positioned at File=0 Block=0
==
====

Used Volume status:
Reserved volume: FAI078 on tape device "DTL03" (/dev/nsa0)
    Reader=0 writers=0 reserves=0 volinuse=0
Reserved volume: FullAuto-4905 on file device "vDrive-0" 
(/usr/local/bacula/volumes)
    Reader=0 writers=1 reserves=0 volinuse=1
Reserved volume: FullAuto-4906 on file device "vDrive-3" 
(/usr/local/bacula/volumes)
    Reader=0 writers=1 reserves=0 volinuse=1
====

Attr spooling: 2 active jobs, 0 bytes; 68 total jobs, 574,172,670 max bytes.
====

*



— 
Dan Langille
http://langille <http://langille/>.org/





------------------------------------------------------------------------------
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Reply via email to