On 10/28/2017 10:10 AM, Phil Stracchino wrote:
> On 10/28/17 04:15, Kern Sibbald wrote:
>> Hello,
>>
>> Thanks for the feedback. Can you confirm that your Bacula signs on with
>> version 9.0.5? If so, it means that some recent patches that I have
>> made for this problem (3-4 bug reports) solve the problem :-)
>
> I will definitely download and test.
Hi Kern,
Version 9.0.5 from git seems to mitigate this issue. (with a caveat or two).
In my quick test here, I set up a restore job knowing full well that the
storage array with the volumes required to do the restore was powered off -
hoping to force Bacula to ask the operator for a volume and then wait. :)
Bacula attempted to reserve, and then access each of the 6 disk devices in the
autochanger. Of course it could not open any of them because the array was
off/dismounted. It properly warned me for each device, then tried to loop
through the 6 drives 3 more times (for a total of 4 loops), and then it marked
the job as:
"is waiting on Storage "aoe-file"
So far so good.
However, a few things:
1. It performed this loop every 30 seconds generating a lot of logging
2. It never mailed the operator to ask for a volume.
3. After pretty much exactly 10 minutes, the job was failed and a normal "job
failure" email was sent to the admin.
This second one might be the correct behavior since it is not trying to find a
volume, it simply cannot access the defined drive devices -- something to
think about... Should an operator be notified when a device cannot be opened
by the SD?
Attached is the first and last loop and job summary since it would just wrap
horribly in this email. :)
Kern, I understand that this test I just did may be a corner case and may just
be throwing a monkey wrench into the mix, but similar scenarios have been seen
in BEE Support, so it might be sensible to trap for this.
Best regards,
Bill
--
Bill Arlofski
http://www.revpol.com/bacula
-- Not responsible for anything below this line --
*llist joblog jobid=17968
time: 2017-10-28 10:27:30
logtext: bacula-dir JobId 17968: Start Restore Job
Restore.2017-10-28_10.27.28_53
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive0 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive0" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive1 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive1" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive2 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive2" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive3 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive3" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive4 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive4" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive5 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:27:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive5" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
(about 3600 more log entries.... snipped)
(last loop and job summary)
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive0 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive0" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive1 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive1" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive2 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive2" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive3 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive3" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive4 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive4" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Error: init_dev.c:123 [SE0001] Unable to stat
device AoE-Changer0_drive5 at /mnt/Coraid/AoE-File0: ERR=Permission denied
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Warning:
Device "AoE-Changer0_drive5" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-sd JobId 17968: Fatal error: Device reservation failed for
JobId=17968: Jmsg JobId=17968 type=5 level=1509208650 bacula-sd JobId 17968:
Warning:
Device "AoE-Changer0_drive5" in changer "AoE-Changer0" requested by DIR
could not be opened or does not exist.
time: 2017-10-28 10:37:30
logtext: bacula-dir JobId 17968: Fatal error:
Storage daemon didn't accept Device "AoE-Changer0" because:
3924 Device "AoE-Changer0" not in SD Device resources or no matching Media
Type or is disabled.
time: 2017-10-28 10:37:31
logtext: bacula-dir JobId 17968: Error: Bacula bacula-dir 9.0.5 (23Oct17):
Build OS: x86_64-pc-linux-gnu gentoo
JobId: 17968
Job: Restore.2017-10-28_10.27.28_53
Restore Client: speedy-fd
Start time: 28-Oct-2017 10:27:30
End time: 28-Oct-2017 10:37:30
Files Expected: 632,217
Files Restored: 0
Bytes Restored: 0
Rate: 0.0 KB/s
FD Errors: 1
FD termination status:
SD termination status:
Termination: *** Restore Error ***
time: 2017-10-28 10:37:31
logtext: bacula-dir JobId 17968: Error: Bacula bacula-dir 9.0.5 (23Oct17):
Build OS: x86_64-pc-linux-gnu gentoo
JobId: 17968
Job: Restore.2017-10-28_10.27.28_53
Restore Client: speedy-fd
Start time: 28-Oct-2017 10:27:30
End time: 28-Oct-2017 10:37:31
Files Expected: 632,217
Files Restored: 0
Bytes Restored: 0
Rate: 0.0 KB/s
FD Errors: 2
FD termination status:
SD termination status:
Termination: *** Restore Error ***
jobid: 17,968
job: Restore.2017-10-28_10.27.28_53
name: Restore
purgedfiles: 0
type: R
level: F
clientid: 2
clientname: speedy-fd
jobstatus: f
schedtime: 2017-10-28 10:27:25
starttime: 2017-10-28 10:27:30
endtime: 2017-10-28 10:37:31
realendtime: 2017-10-28 10:37:31
jobtdate: 1,509,208,651
volsessionid: 1
volsessiontime: 1,508,817,356
jobfiles: 0
jobbytes: 0
readbytes: 0
joberrors: 2
jobmissingfiles: 0
poolid: 0
poolname:
priorjobid: 0
filesetid: 0
fileset:
hasbase: 0
hascache: 0
comment:
*@tall
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
