Re: [Bacula-users] label command frequently fails
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
> 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
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
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
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
> 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
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 Cl
Re: [Bacula-users] label command frequently fails
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
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
> 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
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
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
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
> 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
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
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
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
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
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
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
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
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
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