Skip to content
Permalink
Browse files

autochanger: empty slot bug workaround

fixes #990: SD sometimes tries to load empty tape slot
  • Loading branch information...
franku committed Jul 22, 2019
1 parent d145c8e commit 9ce7cd8de62335222c58cc766805e90e712d7180
Showing with 65 additions and 50 deletions.
  1. +1 −2 core/src/stored/askdir.cc
  2. +55 −48 core/src/stored/autochanger.cc
  3. +9 −0 core/src/stored/mount.cc
@@ -277,7 +277,7 @@ bool StorageDaemonDeviceControlRecord::DirGetVolumeInfo(enum get_vol_info_rw wri
*/
bool StorageDaemonDeviceControlRecord::DirFindNextAppendableVolume()
{
bool retval;
bool retval = false;
BareosSocket *dir = jcr->dir_bsock;
PoolMem unwanted_volumes(PM_MESSAGE);

@@ -333,7 +333,6 @@ bool StorageDaemonDeviceControlRecord::DirFindNextAppendableVolume()
Dmsg2(debuglevel, "No vol. index %d return false. dev=%s\n", vol_index, dev->print_name());
break;
}
retval = false;
VolumeName[0] = 0;

get_out:
@@ -116,7 +116,7 @@ int AutoloadDevice(DeviceControlRecord *dcr, int writing, BareosSocket *dir)
{
POOLMEM *changer;
int rtn_stat = -1; /* error status */
slot_number_t slot;
slot_number_t wanted_slot;
JobControlRecord *jcr = dcr->jcr;
drive_number_t drive;
Device * volatile dev = dcr->dev;
@@ -135,15 +135,15 @@ int AutoloadDevice(DeviceControlRecord *dcr, int writing, BareosSocket *dir)
}

drive = dev->drive_index;
slot = dcr->VolCatInfo.InChanger ? dcr->VolCatInfo.Slot : 0;
wanted_slot = dcr->VolCatInfo.InChanger ? dcr->VolCatInfo.Slot : 0;
Dmsg3(100, "autoload: slot=%hd InChgr=%d Vol=%s\n", dcr->VolCatInfo.Slot,
dcr->VolCatInfo.InChanger, dcr->getVolCatName());

/*
* Handle autoloaders here. If we cannot autoload it, we will return 0 so that
* the sysop will be asked to load it.
*/
if (writing && slot <= 0) {
if (writing && wanted_slot <= 0) {
if (dir) {
return 0; /* For user, bail out right now */
}
@@ -152,21 +152,21 @@ int AutoloadDevice(DeviceControlRecord *dcr, int writing, BareosSocket *dir)
* ***FIXME*** this really should not be here
*/
if (dcr->DirFindNextAppendableVolume()) {
slot = dcr->VolCatInfo.InChanger ? dcr->VolCatInfo.Slot : 0;
wanted_slot = dcr->VolCatInfo.InChanger ? dcr->VolCatInfo.Slot : 0;
} else {
slot = 0;
wanted_slot = 0;
}
}
Dmsg1(400, "Want changer slot=%hd\n", slot);
Dmsg1(400, "Want changer slot=%hd\n", wanted_slot);

changer = GetPoolMemory(PM_FNAME);
if (slot <= 0) {
if (wanted_slot <= 0) {
/*
* Suppress info when polling
*/
if (!dev->poll) {
Jmsg(jcr, M_INFO, 0, _("No slot defined in catalog (slot=%hd) for Volume \"%s\" on %s.\n"),
slot, dcr->getVolCatName(), dev->print_name());
wanted_slot, dcr->getVolCatName(), dev->print_name());
Jmsg(jcr, M_INFO, 0, _("Cartridge change or \"update slots\" may be required.\n"));
}
rtn_stat = 0;
@@ -190,13 +190,13 @@ int AutoloadDevice(DeviceControlRecord *dcr, int writing, BareosSocket *dir)
} else {
uint32_t timeout = dcr->device->max_changer_wait;
int status;
slot_number_t loaded;
slot_number_t loaded_slot;

/*
* Attempt to load the Volume
*/
loaded = GetAutochangerLoadedSlot(dcr);
if (loaded != slot) {
loaded_slot = GetAutochangerLoadedSlot(dcr);
if (loaded_slot != wanted_slot) {
PoolMem results(PM_MESSAGE);

if (!LockChanger(dcr)) {
@@ -207,36 +207,36 @@ int AutoloadDevice(DeviceControlRecord *dcr, int writing, BareosSocket *dir)
/*
* Unload anything in our drive
*/
if (!UnloadAutochanger(dcr, loaded, true)) {
if (!UnloadAutochanger(dcr, loaded_slot, true)) {
UnlockChanger(dcr);
goto bail_out;
}

/*
* Make sure desired slot is unloaded
*/
if (!UnloadOtherDrive(dcr, slot, true)) {
if (!UnloadOtherDrive(dcr, wanted_slot, true)) {
UnlockChanger(dcr);
goto bail_out;
}

/*
* Load the desired volume.
*/
Dmsg2(100, "Doing changer load slot %hd %s\n", slot, dev->print_name());
Dmsg2(100, "Doing changer load slot %hd %s\n", wanted_slot, dev->print_name());
Jmsg(jcr, M_INFO, 0,
_("3304 Issuing autochanger \"load slot %hd, drive %hd\" command.\n"),
slot, drive);
dcr->VolCatInfo.Slot = slot; /* slot to be loaded */
wanted_slot, drive);
dcr->VolCatInfo.Slot = wanted_slot; /* slot to be loaded */
changer = edit_device_codes(dcr, changer, dcr->device->changer_command, "load");
dev->close(dcr);
Dmsg1(200, "Run program=%s\n", changer);
status = RunProgramFullOutput(changer, timeout, results.addr());
if (status == 0) {
Jmsg(jcr, M_INFO, 0, _("3305 Autochanger \"load slot %hd, drive %hd\", status is OK.\n"),
slot, drive);
Dmsg2(100, "load slot %hd, drive %hd, status is OK.\n", slot, drive);
dev->SetSlot(slot); /* set currently loaded slot */
wanted_slot, drive);
Dmsg2(100, "load slot %hd, drive %hd, status is OK.\n", wanted_slot, drive);
dev->SetSlot(wanted_slot); /* set currently loaded slot */
if (dev->vol) {
/*
* We just swapped this Volume so it cannot be swapping any more
@@ -246,19 +246,26 @@ int AutoloadDevice(DeviceControlRecord *dcr, int writing, BareosSocket *dir)
} else {
BErrNo be;
be.SetErrno(status);
Dmsg3(100, "load slot %hd, drive %hd, bad stats=%s.\n", slot, drive,
be.bstrerror());
Jmsg(jcr, M_FATAL, 0, _("3992 Bad autochanger \"load slot %hd, drive %hd\": "
"ERR=%s.\nResults=%s\n"),
slot, drive, be.bstrerror(), results.c_str());
rtn_stat = -1; /* hard error */
dev->SetSlot(-1); /* mark unknown */
std::string tmp(results.c_str());
if (tmp.find("Source Element Address") != std::string::npos
&& tmp.find("is Empty") != std::string::npos) {
rtn_stat = -3; /* medium not found in slot */
} else {
rtn_stat = -1; /* hard error */
}
Dmsg3(100, "load slot %hd, drive %hd, bad stats=%s.\n", wanted_slot, drive,
be.bstrerror());
Jmsg(jcr, rtn_stat == -3 ? M_ERROR : M_FATAL, 0,
_("3992 Bad autochanger \"load slot %hd, drive %hd\": "
"ERR=%s.\nResults=%s\n"),
wanted_slot, drive, be.bstrerror(), results.c_str());
dev->SetSlot(-1); /* mark unknown */
}
Dmsg2(100, "load slot %hd status=%d\n", slot, status);
Dmsg2(100, "load slot %hd status=%d\n", wanted_slot, status);
UnlockChanger(dcr);
} else {
status = 0; /* we got what we want */
dev->SetSlot(slot); /* set currently loaded slot */
dev->SetSlot(wanted_slot); /* set currently loaded slot */
}

Dmsg1(100, "After changer, status=%d\n", status);
@@ -284,7 +291,7 @@ slot_number_t GetAutochangerLoadedSlot(DeviceControlRecord *dcr, bool lock_set)
int status;
POOLMEM *changer;
JobControlRecord *jcr = dcr->jcr;
slot_number_t loaded;
slot_number_t loaded_slot;
Device *dev = dcr->dev;
PoolMem results(PM_MESSAGE);
uint32_t timeout = dcr->device->max_changer_wait;
@@ -333,15 +340,15 @@ slot_number_t GetAutochangerLoadedSlot(DeviceControlRecord *dcr, bool lock_set)
Dmsg3(100, "run_prog: %s stat=%d result=%s", changer, status, results.c_str());

if (status == 0) {
loaded = str_to_int16(results.c_str());
if (loaded > 0) {
loaded_slot = str_to_int16(results.c_str());
if (loaded_slot > 0) {
/*
* Suppress info when polling
*/
if (!dev->poll && debug_level >= 1) {
Jmsg(jcr, M_INFO, 0, _("3302 Autochanger \"loaded? drive %hd\", result is Slot %hd.\n"), drive, loaded);
Jmsg(jcr, M_INFO, 0, _("3302 Autochanger \"loaded? drive %hd\", result is Slot %hd.\n"), drive, loaded_slot);
}
dev->SetSlot(loaded);
dev->SetSlot(loaded_slot);
} else {
/*
* Suppress info when polling
@@ -350,7 +357,7 @@ slot_number_t GetAutochangerLoadedSlot(DeviceControlRecord *dcr, bool lock_set)
Jmsg(jcr, M_INFO, 0, _("3302 Autochanger \"loaded? drive %hd\", result: nothing loaded.\n"),
drive);
}
if (loaded == 0) { /* no slot loaded */
if (loaded_slot == 0) { /* no slot loaded */
dev->SetSlot(0);
} else { /* probably some error */
dev->ClearSlot(); /* unknown */
@@ -361,7 +368,7 @@ slot_number_t GetAutochangerLoadedSlot(DeviceControlRecord *dcr, bool lock_set)
be.SetErrno(status);
Jmsg(jcr, M_INFO, 0, _("3991 Bad autochanger \"loaded? drive %hd\" command: "
"ERR=%s.\nResults=%s\n"), drive, be.bstrerror(), results.c_str());
loaded = -1; /* force unload */
loaded_slot = -1; /* force unload */
}

if (!lock_set) {
@@ -370,7 +377,7 @@ slot_number_t GetAutochangerLoadedSlot(DeviceControlRecord *dcr, bool lock_set)

FreePoolMemory(changer);

return loaded;
return loaded_slot;
}

static bool LockChanger(DeviceControlRecord *dcr)
@@ -419,19 +426,19 @@ static bool UnlockChanger(DeviceControlRecord *dcr)

/**
* Unload the volume, if any, in this drive
* On entry: loaded == 0 -- nothing to do
* loaded < 0 -- check if anything to do
* loaded > 0 -- load slot == loaded
* On entry: loaded_slot == 0 -- nothing to do
* loaded_slot < 0 -- check if anything to do
* loaded_slot > 0 -- load slot == loaded_slot
*/
bool UnloadAutochanger(DeviceControlRecord *dcr, slot_number_t loaded, bool lock_set)
bool UnloadAutochanger(DeviceControlRecord *dcr, slot_number_t loaded_slot, bool lock_set)
{
Device *dev = dcr->dev;
JobControlRecord *jcr = dcr->jcr;
slot_number_t slot;
uint32_t timeout = dcr->device->max_changer_wait;
bool retval = true;

if (loaded == 0) {
if (loaded_slot == 0) {
return true;
}

@@ -458,20 +465,20 @@ bool UnloadAutochanger(DeviceControlRecord *dcr, slot_number_t loaded, bool lock
}
}

if (loaded < 0) {
loaded = GetAutochangerLoadedSlot(dcr, true);
if (loaded_slot < 0) {
loaded_slot = GetAutochangerLoadedSlot(dcr, true);
}

if (loaded > 0) {
if (loaded_slot > 0) {
int status;
PoolMem results(PM_MESSAGE);
POOLMEM *changer = GetPoolMemory(PM_FNAME);

Jmsg(jcr, M_INFO, 0,
_("3307 Issuing autochanger \"unload slot %hd, drive %hd\" command.\n"),
loaded, dev->drive);
loaded_slot, dev->drive);
slot = dcr->VolCatInfo.Slot;
dcr->VolCatInfo.Slot = loaded;
dcr->VolCatInfo.Slot = loaded_slot;
changer = edit_device_codes(dcr, changer,
dcr->device->changer_command, "unload");
dev->close(dcr);
@@ -484,7 +491,7 @@ bool UnloadAutochanger(DeviceControlRecord *dcr, slot_number_t loaded, bool lock
be.SetErrno(status);
Jmsg(jcr, M_INFO, 0, _("3995 Bad autochanger \"unload slot %hd, drive %hd\": "
"ERR=%s\nResults=%s\n"),
loaded, dev->drive, be.bstrerror(), results.c_str());
loaded_slot, dev->drive, be.bstrerror(), results.c_str());
retval = false;
dev->ClearSlot(); /* unknown */
} else {
@@ -501,7 +508,7 @@ bool UnloadAutochanger(DeviceControlRecord *dcr, slot_number_t loaded, bool lock
UnlockChanger(dcr);
}

if (loaded > 0) { /* FreeVolume outside from changer lock */
if (loaded_slot > 0) { /* FreeVolume outside from changer lock */
FreeVolume(dev); /* Free any volume associated with this drive */
}

@@ -158,6 +158,15 @@ bool DeviceControlRecord::MountNextWriteVolume()
}

switch (AutoloadDevice(dcr, true /* writing */, NULL)) {
case -3:
Dmsg0(100, "Wait after a unsuccessful tape load (empty slot).\n");
Jmsg0(jcr, M_WARNING, 0, "Wait after a unsuccessful tape load (empty slot).\n");
Bmicrosleep(1, 0);
dev->VolHdr.VolumeName[0] = 0;
dev->vol=0; /* do not free volume here because in this case
* it is still on the vol_list chain for another job */
goto mount_next_vol;
break;
case -2:
case -1:
/*

0 comments on commit 9ce7cd8

Please sign in to comment.
You can’t perform that action at this time.