Re: [Bacula-users] label command frequently fails

2018-10-02 Thread Kern Sibbald

Hello,

I suspect that what Martin has said in the second to last paragraph is 
correct.  At the same time, Bacula really should print a reason why the 
label command did not work.


Have you already posted your complete bacula-sd.conf file?  If not, 
please do so.


Best regards,
Kern

On 09/28/2018 03:32 PM, Martin Simmons wrote:

On Thu, 27 Sep 2018 20:57:35 -0400, Gary Dale said:

On 2018-09-27 11:05 AM, Martin Simmons wrote:

On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's WorkingDirectory).

...and you can also add options=t to have timestamps in the *.trace file.


Best regards,

Bill



I was waiting for the label command to fail again. It didn't take long.
The bconsole messages were the same. The trace doesn't tell me anything
new. Hopefully you understand it better than I. Here's the output from
the trace:

#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: cH+vQ7+Fdw/6P7+9R7/jRA
bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)
bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
drive="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 7f19c8011e88 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 in_use=1 swap=0 
slot=0 on file device "FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 slot=0 writers=1 
reserves=0 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
dev="FileStorage" (/home/shares/backup)
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=

Is it still printing

3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.

when the label command fails?  If so, then the output of the "status storage"
command might give more information.

__Martin


That message always prints just before the label command fails. It makes
no sense to me because what is there to initialize? It's a folder on a
disk (/home/shares/backup).

That message means the FileStorage device is trying to "initialize", i.e. find
a volume.



I just got an example of another one:

Connecting to Storage daemon File at
molar.dentaloffice.rossland.dental:9103 ...
Sending label command for Volume "weekly-backup-pool-40" Slot 0 ...
3908 Error reserving volume: vol_mgr.c:419 Cannot free Volume
"weekly-backup-pool-37", because it is reserved by someone else.

Label command failed for Volume weekly-backup-pool-40.

You can't label a new volume while a running job is actively writing to
another volume.

Maybe that is also the cause of the original problem?  In general, you have to
either label volumes when nothing is running or label one when Bacula asks you
to.

__Martin


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





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


Re: [Bacula-users] label command frequently fails

2018-10-01 Thread Martin Simmons
> On Fri, 28 Sep 2018 14:25:51 -0400, Gary Dale said:
> 
> On 2018-09-28 09:32 AM, Martin Simmons wrote:
> >> On Thu, 27 Sep 2018 20:57:35 -0400, Gary Dale said:
> >> On 2018-09-27 11:05 AM, Martin Simmons wrote:
>  On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:
>  On 2018-09-26 11:33 AM, Bill Arlofski wrote:
> On 09/26/2018 06:22 AM, Martin Simmons wrote:
> >> Try
> >>
> >> setdebug level=150 trace=1 Storage
> >>
> >> and look for a file matching *.trace (probably in the SD's 
> >> WorkingDirectory).
> ...and you can also add options=t to have timestamps in the *.trace file.
> >
> >
> Best regards,
> >
> Bill
> >
> >
>  I was waiting for the label command to fail again. It didn't take long.
>  The bconsole messages were the same. The trace doesn't tell me anything
>  new. Hopefully you understand it better than I. Here's the output from
>  the trace:
> 
>  #cat /var/lib/bacula/bacula-sd.trace
>  bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
>  bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
>  bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
>  <56845663.1538019025@bacula-sd> ssl=0
>  bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
>  <554803286.1538019025@bacula-dir> ssl=0
>  bacula-sd: cram-md5.c:157-0 sending resp to challenge: 
>  cH+vQ7+Fdw/6P7+9R7/jRA
>  bacula-sd: dircmd.c:204-0 Message channel init completed.
>  bacula-sd: dircmd.c:806-0 Found device FileStorage
>  bacula-sd: dircmd.c:850-0 Found device FileStorage
>  bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
>  bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
>  (/home/shares/backup)
>  bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
>  bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
>  bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
>  drive="FileStorage" (/home/shares/backup)
>  bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
>  7f19c8011e88 dev="FileStorage" (/home/shares/backup)
>  bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
>  dev="FileStorage" (/home/shares/backup)
>  bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
>  volname=weekly-backup-pool-37
>  bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 
>  in_use=1 swap=0 slot=0 on file device "FileStorage" (/home/shares/backup)
>  bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
>  bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 
>  slot=0 writers=1 reserves=0 dev="FileStorage" (/home/shares/backup)
>  bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
>  bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
>  dev="FileStorage" (/home/shares/backup)
>  bacula-sd: mount.c:384-3298 Again dir_find_next_append...
>  bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
>  bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
>  bacula-sd: mount.c:384-3298 Again dir_find_next_append...
>  bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
>  bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
>  bacula-sd: mount.c:384-3298 Again dir_find_next_append...
>  bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
>  bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
> >>> Is it still printing
> >>>
> >>> 3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
> >>>
> >>> when the label command fails?  If so, then the output of the "status 
> >>> storage"
> >>> command might give more information.
> >>>
> >>> __Martin
> >>>
> >> That message always prints just before the label command fails. It makes
> >> no sense to me because what is there to initialize? It's a folder on a
> >> disk (/home/shares/backup).
> > That message means the FileStorage device is trying to "initialize", i.e. 
> > find
> > a volume.
> >
> >
> >> I just got an example of another one:
> >>
> >> Connecting to Storage daemon File at
> >> molar.dentaloffice.rossland.dental:9103 ...
> >> Sending label command for Volume "weekly-backup-pool-40" Slot 0 ...
> >> 3908 Error reserving volume: vol_mgr.c:419 Cannot free Volume
> >> "weekly-backup-pool-37", because it is reserved by someone else.
> >>
> >> Label command failed for Volume weekly-backup-pool-40.
> > You can't label a new volume while a running job is actively writing to
> > another volume.
> >
> > Maybe that is also the cause of the original problem?  In general, you have 
> > to
> > either label volumes when nothing is running or label one when Bacula asks 

Re: [Bacula-users] label command frequently fails

2018-09-29 Thread Radosław Korzeniewski
Hello,

pt., 28 wrz 2018 o 20:19 Gary Dale  napisał(a):

> Of course I restrict the volume size. That's normal for Bacula.
>

Well, it is not normal unless you want to limit storage size allocated by
your backups where you additionally define the maximum number of volumes in
pool. In any other case it is not normal.

best regards
-- 
Radosław Korzeniewski
rados...@korzeniewski.net
___
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users


Re: [Bacula-users] label command frequently fails

2018-09-28 Thread Gary Dale

On 2018-09-28 09:32 AM, Martin Simmons wrote:

On Thu, 27 Sep 2018 20:57:35 -0400, Gary Dale said:

On 2018-09-27 11:05 AM, Martin Simmons wrote:

On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's WorkingDirectory).

...and you can also add options=t to have timestamps in the *.trace file.


Best regards,

Bill



I was waiting for the label command to fail again. It didn't take long.
The bconsole messages were the same. The trace doesn't tell me anything
new. Hopefully you understand it better than I. Here's the output from
the trace:

#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: cH+vQ7+Fdw/6P7+9R7/jRA
bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)
bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
drive="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 7f19c8011e88 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 in_use=1 swap=0 
slot=0 on file device "FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 slot=0 writers=1 
reserves=0 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
dev="FileStorage" (/home/shares/backup)
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=

Is it still printing

3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.

when the label command fails?  If so, then the output of the "status storage"
command might give more information.

__Martin


That message always prints just before the label command fails. It makes
no sense to me because what is there to initialize? It's a folder on a
disk (/home/shares/backup).

That message means the FileStorage device is trying to "initialize", i.e. find
a volume.



I just got an example of another one:

Connecting to Storage daemon File at
molar.dentaloffice.rossland.dental:9103 ...
Sending label command for Volume "weekly-backup-pool-40" Slot 0 ...
3908 Error reserving volume: vol_mgr.c:419 Cannot free Volume
"weekly-backup-pool-37", because it is reserved by someone else.

Label command failed for Volume weekly-backup-pool-40.

You can't label a new volume while a running job is actively writing to
another volume.

Maybe that is also the cause of the original problem?  In general, you have to
either label volumes when nothing is running or label one when Bacula asks you
to.

__Martin

That makes sense. Unfortunately Bacula doesn't seem to want to ask me. 
It just sits there waiting for a volume that it won't let me label...


I've left myself logged in and running bconsole to see if that helps. 
Hopefully it will issue the message to the console and wait for me to 
label a new volume.



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


Re: [Bacula-users] label command frequently fails

2018-09-28 Thread Gary Dale

On 2018-09-28 06:13 AM, Kern Sibbald wrote:

Hello,

It should not take "I need a lot of new volumes to handle what amounts 
to a full backup of 160G of data" unless you are artificially 
restricting volume size.  Unless I misunderstood what you wrote, you 
should not have 40 volumes to store 160G of data. One would be 
sufficient.   In fact having so many volumes is a big disadvantage 
particularly from a performance stand point (Bacula is not very 
efficient when handling volume sets).


Best regards,
Kern


Of course I restrict the volume size. That's normal for Bacula.

The 40 volumes are for all the previous backups as well. The issue is 
that because I moved 160G of data from one machine to another, Bacula 
treats it as new data that needs a complete backup. That's why I need a 
large number of additional volumes. Presumably the older backups will 
eventually be purged so the number of volumes can be reduced over time.



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


Re: [Bacula-users] label command frequently fails

2018-09-28 Thread Martin Simmons
> On Thu, 27 Sep 2018 20:57:35 -0400, Gary Dale said:
> 
> On 2018-09-27 11:05 AM, Martin Simmons wrote:
> >> On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:
> >> On 2018-09-26 11:33 AM, Bill Arlofski wrote:
> >>> On 09/26/2018 06:22 AM, Martin Simmons wrote:
>  Try
> 
>  setdebug level=150 trace=1 Storage
> 
>  and look for a file matching *.trace (probably in the SD's 
>  WorkingDirectory).
> >>> ...and you can also add options=t to have timestamps in the *.trace file.
> >>>
> >>>
> >>> Best regards,
> >>>
> >>> Bill
> >>>
> >>>
> >> I was waiting for the label command to fail again. It didn't take long.
> >> The bconsole messages were the same. The trace doesn't tell me anything
> >> new. Hopefully you understand it better than I. Here's the output from
> >> the trace:
> >>
> >> #cat /var/lib/bacula/bacula-sd.trace
> >> bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
> >> bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
> >> bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
> >> <56845663.1538019025@bacula-sd> ssl=0
> >> bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
> >> <554803286.1538019025@bacula-dir> ssl=0
> >> bacula-sd: cram-md5.c:157-0 sending resp to challenge: 
> >> cH+vQ7+Fdw/6P7+9R7/jRA
> >> bacula-sd: dircmd.c:204-0 Message channel init completed.
> >> bacula-sd: dircmd.c:806-0 Found device FileStorage
> >> bacula-sd: dircmd.c:850-0 Found device FileStorage
> >> bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
> >> bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
> >> (/home/shares/backup)
> >> bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
> >> bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
> >> bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
> >> drive="FileStorage" (/home/shares/backup)
> >> bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
> >> 7f19c8011e88 dev="FileStorage" (/home/shares/backup)
> >> bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
> >> dev="FileStorage" (/home/shares/backup)
> >> bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
> >> volname=weekly-backup-pool-37
> >> bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 
> >> in_use=1 swap=0 slot=0 on file device "FileStorage" (/home/shares/backup)
> >> bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
> >> bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 
> >> slot=0 writers=1 reserves=0 dev="FileStorage" (/home/shares/backup)
> >> bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
> >> bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
> >> dev="FileStorage" (/home/shares/backup)
> >> bacula-sd: mount.c:384-3298 Again dir_find_next_append...
> >> bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
> >> bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
> >> bacula-sd: mount.c:384-3298 Again dir_find_next_append...
> >> bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
> >> bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
> >> bacula-sd: mount.c:384-3298 Again dir_find_next_append...
> >> bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
> >> bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
> > Is it still printing
> >
> > 3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
> >
> > when the label command fails?  If so, then the output of the "status 
> > storage"
> > command might give more information.
> >
> > __Martin
> >
> That message always prints just before the label command fails. It makes 
> no sense to me because what is there to initialize? It's a folder on a 
> disk (/home/shares/backup).

That message means the FileStorage device is trying to "initialize", i.e. find
a volume.


> I just got an example of another one:
> 
> Connecting to Storage daemon File at 
> molar.dentaloffice.rossland.dental:9103 ...
> Sending label command for Volume "weekly-backup-pool-40" Slot 0 ...
> 3908 Error reserving volume: vol_mgr.c:419 Cannot free Volume 
> "weekly-backup-pool-37", because it is reserved by someone else.
> 
> Label command failed for Volume weekly-backup-pool-40.

You can't label a new volume while a running job is actively writing to
another volume.

Maybe that is also the cause of the original problem?  In general, you have to
either label volumes when nothing is running or label one when Bacula asks you
to.

__Martin


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


Re: [Bacula-users] label command frequently fails

2018-09-28 Thread Kern Sibbald

Hello,

It should not take "I need a lot of new volumes to handle what amounts 
to a full backup of 160G of data" unless you are artificially 
restricting volume size.  Unless I misunderstood what you wrote, you 
should not have 40 volumes to store 160G of data. One would be 
sufficient.   In fact having so many volumes is a big disadvantage 
particularly from a performance stand point (Bacula is not very 
efficient when handling volume sets).


Best regards,
Kern

On 09/28/2018 02:57 AM, Gary Dale wrote:

On 2018-09-27 11:05 AM, Martin Simmons wrote:

On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's 
WorkingDirectory).
...and you can also add options=t to have timestamps in the *.trace 
file.



Best regards,

Bill



I was waiting for the label command to fail again. It didn't take long.
The bconsole messages were the same. The trace doesn't tell me anything
new. Hopefully you understand it better than I. Here's the output from
the trace:

#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: 
cH+vQ7+Fdw/6P7+9R7/jRA

bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)

bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter 
reserve_volume=weekly-backup-pool-37 drive="FileStorage" 
(/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
7f19c8011e88 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: 
weekly-backup-pool-37 in_use=1 swap=0 slot=0 on file device 
"FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 
slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved 
vol=weekly-backup-pool-37 slot=0 writers=1 reserves=0 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 
slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 
slot=0 dev="FileStorage" (/home/shares/backup)

bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling 
wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= 
devvol=

bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling 
wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= 
devvol=

bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling 
wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= 
devvol=

Is it still printing

3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.

when the label command fails?  If so, then the output of the "status 
storage"

command might give more information.

__Martin

That message always prints just before the label command fails. It 
makes no sense to me because what is there to initialize? It's a 
folder on a disk (/home/shares/backup).


I just got an example of another one:

Connecting to Storage daemon File at 
molar.dentaloffice.rossland.dental:9103 ...

Sending label command for Volume "weekly-backup-pool-40" Slot 0 ...
3908 Error reserving volume: vol_mgr.c:419 Cannot free Volume 
"weekly-backup-pool-37", because it is reserved by someone else.


Label command failed for Volume weekly-backup-pool-40.
Do not forget to mount the drive!!!
You have messages.


Looking at the messages I find:

27-Sep 20:34 bacula-sd JobId 3302: Elapsed time=00:00:24, Transfer 
rate=68.80 M Bytes/second
27-Sep 20:34 bacula-sd JobId 3302: Sending spooled attrs to the 
Director. Despooling 34,365 bytes ...

27-Sep 20:34 bacula-dir JobId 3302: Bacula bacula-dir 7.4.4 (202Sep16):
  Build OS:   x86_64-pc-linux-gnu debian 9.0
  JobId:  3302
  Job:    BackupServer.2018-09-27_20.34.14_04
  Backup Level:   Incremental, since=2018-09-25 23:47:15
  

Re: [Bacula-users] label command frequently fails

2018-09-27 Thread Gary Dale

On 2018-09-27 11:05 AM, Martin Simmons wrote:

On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's WorkingDirectory).

...and you can also add options=t to have timestamps in the *.trace file.


Best regards,

Bill



I was waiting for the label command to fail again. It didn't take long.
The bconsole messages were the same. The trace doesn't tell me anything
new. Hopefully you understand it better than I. Here's the output from
the trace:

#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: cH+vQ7+Fdw/6P7+9R7/jRA
bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)
bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
drive="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 7f19c8011e88 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 in_use=1 swap=0 
slot=0 on file device "FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 slot=0 writers=1 
reserves=0 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
dev="FileStorage" (/home/shares/backup)
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=

Is it still printing

3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.

when the label command fails?  If so, then the output of the "status storage"
command might give more information.

__Martin

That message always prints just before the label command fails. It makes 
no sense to me because what is there to initialize? It's a folder on a 
disk (/home/shares/backup).


I just got an example of another one:

Connecting to Storage daemon File at 
molar.dentaloffice.rossland.dental:9103 ...

Sending label command for Volume "weekly-backup-pool-40" Slot 0 ...
3908 Error reserving volume: vol_mgr.c:419 Cannot free Volume 
"weekly-backup-pool-37", because it is reserved by someone else.


Label command failed for Volume weekly-backup-pool-40.
Do not forget to mount the drive!!!
You have messages.


Looking at the messages I find:

27-Sep 20:34 bacula-sd JobId 3302: Elapsed time=00:00:24, Transfer 
rate=68.80 M Bytes/second
27-Sep 20:34 bacula-sd JobId 3302: Sending spooled attrs to the 
Director. Despooling 34,365 bytes ...

27-Sep 20:34 bacula-dir JobId 3302: Bacula bacula-dir 7.4.4 (202Sep16):
  Build OS:   x86_64-pc-linux-gnu debian 9.0
  JobId:  3302
  Job:    BackupServer.2018-09-27_20.34.14_04
  Backup Level:   Incremental, since=2018-09-25 23:47:15
  Client: "server-fd" 5.2.10 (28Jun12) Microsoft 
Windows 7 Professional Service Pack 1 (build 7601), 
64-bit,Cross-compile,Win32

  FileSet:    "ServerFileSet" 2018-09-18 23:05:00
  Pool:   "DailyBackupPool" (From Job IncPool override)
  Catalog:    "MyCatalog" (From Client resource)
  Storage:    "File" (From Pool resource)
  Scheduled time: 27-Sep-2018 20:34:10
  Start time: 27-Sep-2018 20:34:18
  End time:   27-Sep-2018 20:34:49

Re: [Bacula-users] label command frequently fails

2018-09-27 Thread Gary Dale

On 2018-09-27 05:10 AM, Jérôme Blion wrote:

Le 27/09/2018 à 05:38, Gary Dale a écrit :

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's 
WorkingDirectory).
...and you can also add options=t to have timestamps in the *.trace 
file.



Best regards,

Bill


I was waiting for the label command to fail again. It didn't take 
long. The bconsole messages were the same. The trace doesn't tell me 
anything new. Hopefully you understand it better than I. Here's the 
output from the trace:


#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: 
cH+vQ7+Fdw/6P7+9R7/jRA

bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)

bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
drive="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
7f19c8011e88 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 
in_use=1 swap=0 slot=0 on file device "FileStorage" 
(/home/shares/backup)

bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 
slot=0 writers=1 reserves=0 dev="FileStorage" (/home/shares/backup)

bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
dev="FileStorage" (/home/shares/backup)

bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling 
wait_for_device

bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling 
wait_for_device

bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling 
wait_for_device

bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=



Hello,

Did you add the volume before trying to label it?

Could you provide us commands you used?

For a disk volume, you only need to use the label command. It creates a 
file with that label that is 219 bytes initially then expands up to the 
maximum volume size during use. As jobs get pruned, the volume will also 
shrink...




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


Re: [Bacula-users] label command frequently fails

2018-09-27 Thread Martin Simmons
> On Wed, 26 Sep 2018 23:38:39 -0400, Gary Dale said:
> 
> On 2018-09-26 11:33 AM, Bill Arlofski wrote:
> > On 09/26/2018 06:22 AM, Martin Simmons wrote:
> >> Try
> >>
> >> setdebug level=150 trace=1 Storage
> >>
> >> and look for a file matching *.trace (probably in the SD's 
> >> WorkingDirectory).
> > ...and you can also add options=t to have timestamps in the *.trace file.
> >
> >
> > Best regards,
> >
> > Bill
> >
> >
> I was waiting for the label command to fail again. It didn't take long. 
> The bconsole messages were the same. The trace doesn't tell me anything 
> new. Hopefully you understand it better than I. Here's the output from 
> the trace:
> 
> #cat /var/lib/bacula/bacula-sd.trace
> bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
> bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
> bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
> <56845663.1538019025@bacula-sd> ssl=0
> bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
> <554803286.1538019025@bacula-dir> ssl=0
> bacula-sd: cram-md5.c:157-0 sending resp to challenge: cH+vQ7+Fdw/6P7+9R7/jRA
> bacula-sd: dircmd.c:204-0 Message channel init completed.
> bacula-sd: dircmd.c:806-0 Found device FileStorage
> bacula-sd: dircmd.c:850-0 Found device FileStorage
> bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
> bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
> (/home/shares/backup)
> bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
> bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
> bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
> drive="FileStorage" (/home/shares/backup)
> bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
> 7f19c8011e88 dev="FileStorage" (/home/shares/backup)
> bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
> dev="FileStorage" (/home/shares/backup)
> bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
> volname=weekly-backup-pool-37
> bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 
> in_use=1 swap=0 slot=0 on file device "FileStorage" (/home/shares/backup)
> bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
> bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 slot=0 
> writers=1 reserves=0 dev="FileStorage" (/home/shares/backup)
> bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
> bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
> dev="FileStorage" (/home/shares/backup)
> bacula-sd: mount.c:384-3298 Again dir_find_next_append...
> bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
> bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
> bacula-sd: mount.c:384-3298 Again dir_find_next_append...
> bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
> bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
> bacula-sd: mount.c:384-3298 Again dir_find_next_append...
> bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
> bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=

Is it still printing

3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.

when the label command fails?  If so, then the output of the "status storage"
command might give more information.

__Martin


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


Re: [Bacula-users] label command frequently fails

2018-09-27 Thread Jérôme Blion

Le 27/09/2018 à 05:38, Gary Dale a écrit :

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's 
WorkingDirectory).
...and you can also add options=t to have timestamps in the *.trace 
file.



Best regards,

Bill


I was waiting for the label command to fail again. It didn't take 
long. The bconsole messages were the same. The trace doesn't tell me 
anything new. Hopefully you understand it better than I. Here's the 
output from the trace:


#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: 
cH+vQ7+Fdw/6P7+9R7/jRA

bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)

bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
drive="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
7f19c8011e88 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 
in_use=1 swap=0 slot=0 on file device "FileStorage" (/home/shares/backup)

bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 
slot=0 writers=1 reserves=0 dev="FileStorage" (/home/shares/backup)

bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
dev="FileStorage" (/home/shares/backup)

bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=



Hello,

Did you add the volume before trying to label it?

Could you provide us commands you used?


HTH
Jérôme.


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


Re: [Bacula-users] label command frequently fails

2018-09-26 Thread Gary Dale

On 2018-09-26 11:33 AM, Bill Arlofski wrote:

On 09/26/2018 06:22 AM, Martin Simmons wrote:

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's WorkingDirectory).

...and you can also add options=t to have timestamps in the *.trace file.


Best regards,

Bill


I was waiting for the label command to fail again. It didn't take long. 
The bconsole messages were the same. The trace doesn't tell me anything 
new. Hopefully you understand it better than I. Here's the output from 
the trace:


#cat /var/lib/bacula/bacula-sd.trace
bacula-sd: bnet.c:566-0 who=client host=192.168.1.17 port=9103
bacula-sd: dircmd.c:178-0 Got a DIR connection at 26-Sep-2018 23:30:25
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge 
<56845663.1538019025@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<554803286.1538019025@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: 
cH+vQ7+Fdw/6P7+9R7/jRA

bacula-sd: dircmd.c:204-0 Message channel init completed.
bacula-sd: dircmd.c:806-0 Found device FileStorage
bacula-sd: dircmd.c:850-0 Found device FileStorage
bacula-sd: block_util.c:143-0 New block len=64512 block=7f19c8001160
bacula-sd: acquire.c:673-0 Attach 0xc8001c78 to dev "FileStorage" 
(/home/shares/backup)

bacula-sd: vol_mgr.c:657-0 find_read_vol: read_vol_list empty.
bacula-sd: vol_mgr.c:851-0 Vol=weekly-backup-pool-37 not in use.
bacula-sd: vol_mgr.c:381-0 enter reserve_volume=weekly-backup-pool-37 
drive="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:286-0 new Vol=weekly-backup-pool-37 slot=0 at 
7f19c8011e88 dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:547-0 set in_use. vol=weekly-backup-pool-37 
dev="FileStorage" (/home/shares/backup)
bacula-sd: vol_mgr.c:581-0 Inc walk_start use_count=2 
volname=weekly-backup-pool-37
bacula-sd: vol_mgr.c:220-0 List end new volume: weekly-backup-pool-37 
in_use=1 swap=0 slot=0 on file device "FileStorage" (/home/shares/backup)

bacula-sd: vol_mgr.c:693-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:710-0 set not reserved vol=weekly-backup-pool-37 
slot=0 writers=1 reserves=0 dev="FileStorage" (/home/shares/backup)

bacula-sd: vol_mgr.c:740-0 Clear in_use vol=weekly-backup-pool-37 slot=0
bacula-sd: vol_mgr.c:746-0 Remove volume weekly-backup-pool-37 slot=0 
dev="FileStorage" (/home/shares/backup)

bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=
bacula-sd: mount.c:384-3298 Again dir_find_next_append...
bacula-sd: mount.c:374-3298 No appendable volume. Calling wait_for_device
bacula-sd: wait.c:270-3298 Enter wait_for_device. busy=1 dcrvol= devvol=



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


Re: [Bacula-users] label command frequently fails

2018-09-26 Thread Bill Arlofski
On 09/26/2018 06:22 AM, Martin Simmons wrote:
> Try
> 
> setdebug level=150 trace=1 Storage
> 
> and look for a file matching *.trace (probably in the SD's WorkingDirectory).

...and you can also add options=t to have timestamps in the *.trace file.


Best regards,

Bill


-- 
Bill Arlofski
http://www.revpol.com/bacula
-- Not responsible for anything below this line --


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


Re: [Bacula-users] label command frequently fails

2018-09-26 Thread Martin Simmons
> On Wed, 26 Sep 2018 00:06:48 -0400, Gary Dale said:
> 
> On 2018-09-20 06:09 AM, Kern Sibbald wrote:
> > Hello,
> >
> > The output produced by Bacula seems unusually short.  Normally Bacula 
> > displays a reason for the failure.
> >
> > I recommend trying your label command again, but turn on debug with 
> > something link
> >
> > setdebug level=150 Storage
> >
> > prior to doing the label command.  It should give you a more detailed 
> > reason for
> > the failure.
> 
> It gives me the exact same output. It took the setdebug command but 
> continues to complain when I try to label a new volume. After a reboot I 
> was able to label a volume however. After a while I lose that ability 
> once more.

The debug output goes to /dev/null unless the daemon is run in the foreground
using the -f option.

Try

setdebug level=150 trace=1 Storage

and look for a file matching *.trace (probably in the SD's WorkingDirectory).

__Martin


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


Re: [Bacula-users] label command frequently fails

2018-09-25 Thread Gary Dale

On 2018-09-20 06:09 AM, Kern Sibbald wrote:

Hello,

The output produced by Bacula seems unusually short.  Normally Bacula 
displays a reason for the failure.


I recommend trying your label command again, but turn on debug with 
something link


setdebug level=150 Storage

prior to doing the label command.  It should give you a more detailed 
reason for

the failure.


It gives me the exact same output. It took the setdebug command but 
continues to complain when I try to label a new volume. After a reboot I 
was able to label a volume however. After a while I lose that ability 
once more.


Meanwhile I am currently getting messages every minute to the effect:
25-Sep 23:36 bacula-dir JobId 3284: Pruning oldest volume 
"weekly-backup-pool-03"
25-Sep 23:36 bacula-dir JobId 3284: Found no Job associated with the 
Volume "weekly-backup-pool-03" to  prune

(repeated at 23:37, 23:38, etc.)

This is possibly unrelated but I don't think it should be happening either.


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


Re: [Bacula-users] label command frequently fails

2018-09-23 Thread Kern Sibbald

Hello Martin,

Yes, the variable expansion code is deprecated (destined to be removed 
at some future unspecified time), but as I do not yet have a replacement 
for it, I have keep to the code.


I have some ideas about how to replace the old functionality, but have 
not yet implemented it as there are still a few important new features 
to add before rewriting old features.


Python was removed because it was not really stable and only one person 
that I know used it.  I would like to implement some full scripting 
language (or plugin), but have not yet found the ideal solution or time 
to do it.  Any suggestions would be welcome.


Best regards,
Kern

On 09/20/2018 01:47 PM, Martin Simmons wrote:

Hi Kern,

Is variable expansion fully supported again now?  The doc
(http://www.bacula.org/9.2.x-manuals/en/misc/Variable_Expansion.html) still
says that it was deprecated as of version 1.37, but the replacement python
scripting has been removed.

__Martin


On Thu, 20 Sep 2018 12:09:25 +0200, Kern Sibbald said:

PS: Bacula can create labels in many different formats using variable
substitution. This is documented in the manual.




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


Re: [Bacula-users] label command frequently fails

2018-09-20 Thread Martin Simmons
Hi Kern,

Is variable expansion fully supported again now?  The doc
(http://www.bacula.org/9.2.x-manuals/en/misc/Variable_Expansion.html) still
says that it was deprecated as of version 1.37, but the replacement python
scripting has been removed.

__Martin

> On Thu, 20 Sep 2018 12:09:25 +0200, Kern Sibbald said:
> 
> PS: Bacula can create labels in many different formats using variable 
> substitution. This is documented in the manual.


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


Re: [Bacula-users] label command frequently fails

2018-09-20 Thread Josh Fisher
Check permissions on the disk, including SELinux or other ACLs. The 
bacula-sd user must have read/write permissions.



On 9/19/2018 3:40 PM, Gary Dale wrote:

I'm running bacula 7.4.4 on a Debian/Stretch AMD64 server.

When I try to create a new disk volume for my steadily increasing 
amount of data needing to be backed up, it usually fails after I 
create the first new volume. There is lots of free space on the disk, 
so it's not that. Eventually I might be able to create another new 
volume (possibly because of an intervening reboot) but in the 
meanwhile I only have the one new volume (25G) which is about 1/10 the 
size of a full backup...


Here's an example of what I see in bconsole when executing the label 
command:


Sending label command for Volume "weekly-backup-pool-30" Slot 0 ...
3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
Label command failed for Volume weekly-backup-pool-30.
Do not forget to mount the drive!!!

Any ideas on what is happening and how to fix it?

Thanks.



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




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


Re: [Bacula-users] label command frequently fails

2018-09-20 Thread Kern Sibbald

Hello,

The output produced by Bacula seems unusually short.  Normally Bacula 
displays a reason for the failure.


I recommend trying your label command again, but turn on debug with 
something link


setdebug level=150 Storage

prior to doing the label command.  It should give you a more detailed 
reason for

the failure.

Best regards,
Kern

PS: Bacula can create labels in many different formats using variable 
substitution. This is documented in the manual.



On 09/19/2018 09:40 PM, Gary Dale wrote:

I'm running bacula 7.4.4 on a Debian/Stretch AMD64 server.

When I try to create a new disk volume for my steadily increasing 
amount of data needing to be backed up, it usually fails after I 
create the first new volume. There is lots of free space on the disk, 
so it's not that. Eventually I might be able to create another new 
volume (possibly because of an intervening reboot) but in the 
meanwhile I only have the one new volume (25G) which is about 1/10 the 
size of a full backup...


Here's an example of what I see in bconsole when executing the label 
command:


Sending label command for Volume "weekly-backup-pool-30" Slot 0 ...
3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
Label command failed for Volume weekly-backup-pool-30.
Do not forget to mount the drive!!!

Any ideas on what is happening and how to fix it?

Thanks.



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





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


Re: [Bacula-users] label command frequently fails

2018-09-20 Thread Jérôme Blion

Le 20/09/2018 à 05:23, Gary Dale a écrit :

On 2018-09-19 05:35 PM, Jérôme Blion wrote:

Le 19/09/2018 à 21:40, Gary Dale a écrit :

I'm running bacula 7.4.4 on a Debian/Stretch AMD64 server.

When I try to create a new disk volume for my steadily increasing 
amount of data needing to be backed up, it usually fails after I 
create the first new volume. There is lots of free space on the 
disk, so it's not that. Eventually I might be able to create another 
new volume (possibly because of an intervening reboot) but in the 
meanwhile I only have the one new volume (25G) which is about 1/10 
the size of a full backup...


Here's an example of what I see in bconsole when executing the label 
command:


Sending label command for Volume "weekly-backup-pool-30" Slot 0 ...
3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
Label command failed for Volume weekly-backup-pool-30.
Do not forget to mount the drive!!!

Any ideas on what is happening and how to fix it?

Thanks.


Hello,

why don't you let bacula create volumes when needed ?


Because I didn't start with them that way and bacula doesn't like you 
to change volume labels once assigned. It wants to create new volumes 
with a 4-digit serial number ending. I've been using 2-digits. The 
manual recommends using python scripts for this which I don't want to 
get into to save myself what should be a few minutes every few months.


http://www.bacula.org/7.4.x-manuals/en/misc/Variable_Expansion.html

Perhaps you should do some tests to see if if can create volumes 
according to your naming convention.


You should avoid any manual action regarding your backup solution. 
That's a troubles source.


Moreover, it isn't guaranteed to resolve the problem I'm having. If 
bacula can't label a volume manually through bconsole, why should I 
expect it to do so automatically?


I'd still also need to monitor the number of volumes / amount of disk 
space bacula is taking so it might not actually save me any time. It 
just gives me a different thing to worry about.


http://www.bacula.org/7.4.x-manuals/en/main/Basic_Volume_Management.html

When using automatic volume creation, you should use:

  Maximum Volume Bytes = 50G  # Limit Volume size to something 
reasonable

  Maximum Volumes = 10    # Limit number of Volumes in Pool

This way, you don't have to worry about disk filling.

HTH.
Jérôme Blion.


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


Re: [Bacula-users] label command frequently fails

2018-09-19 Thread Gary Dale

On 2018-09-19 05:35 PM, Jérôme Blion wrote:

Le 19/09/2018 à 21:40, Gary Dale a écrit :

I'm running bacula 7.4.4 on a Debian/Stretch AMD64 server.

When I try to create a new disk volume for my steadily increasing 
amount of data needing to be backed up, it usually fails after I 
create the first new volume. There is lots of free space on the disk, 
so it's not that. Eventually I might be able to create another new 
volume (possibly because of an intervening reboot) but in the 
meanwhile I only have the one new volume (25G) which is about 1/10 
the size of a full backup...


Here's an example of what I see in bconsole when executing the label 
command:


Sending label command for Volume "weekly-backup-pool-30" Slot 0 ...
3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
Label command failed for Volume weekly-backup-pool-30.
Do not forget to mount the drive!!!

Any ideas on what is happening and how to fix it?

Thanks.


Hello,

why don't you let bacula create volumes when needed ?


Because I didn't start with them that way and bacula doesn't like you to 
change volume labels once assigned. It wants to create new volumes with 
a 4-digit serial number ending. I've been using 2-digits. The manual 
recommends using python scripts for this which I don't want to get into 
to save myself what should be a few minutes every few months.


Moreover, it isn't guaranteed to resolve the problem I'm having. If 
bacula can't label a volume manually through bconsole, why should I 
expect it to do so automatically?


I'd still also need to monitor the number of volumes / amount of disk 
space bacula is taking so it might not actually save me any time. It 
just gives me a different thing to worry about.



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


Re: [Bacula-users] label command frequently fails

2018-09-19 Thread Jérôme Blion

Le 19/09/2018 à 21:40, Gary Dale a écrit :

I'm running bacula 7.4.4 on a Debian/Stretch AMD64 server.

When I try to create a new disk volume for my steadily increasing 
amount of data needing to be backed up, it usually fails after I 
create the first new volume. There is lots of free space on the disk, 
so it's not that. Eventually I might be able to create another new 
volume (possibly because of an intervening reboot) but in the 
meanwhile I only have the one new volume (25G) which is about 1/10 the 
size of a full backup...


Here's an example of what I see in bconsole when executing the label 
command:


Sending label command for Volume "weekly-backup-pool-30" Slot 0 ...
3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
Label command failed for Volume weekly-backup-pool-30.
Do not forget to mount the drive!!!

Any ideas on what is happening and how to fix it?

Thanks.


Hello,

why don't you let bacula create volumes when needed ?

HTH.
Jérôme Blion.


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


[Bacula-users] label command frequently fails

2018-09-19 Thread Gary Dale

I'm running bacula 7.4.4 on a Debian/Stretch AMD64 server.

When I try to create a new disk volume for my steadily increasing amount 
of data needing to be backed up, it usually fails after I create the 
first new volume. There is lots of free space on the disk, so it's not 
that. Eventually I might be able to create another new volume (possibly 
because of an intervening reboot) but in the meanwhile I only have the 
one new volume (25G) which is about 1/10 the size of a full backup...


Here's an example of what I see in bconsole when executing the label 
command:


Sending label command for Volume "weekly-backup-pool-30" Slot 0 ...
3934 Device ""FileStorage" (/home/shares/backup)" is being initialized.
Label command failed for Volume weekly-backup-pool-30.
Do not forget to mount the drive!!!

Any ideas on what is happening and how to fix it?

Thanks.



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