STORE *store = jcr->wstore;
bstrncpy(mr->MediaType, store->media_type, sizeof(mr->MediaType));
- Dmsg2(150, "find_next_vol_for_append: PoolId=%d, MediaType=%s\n", (int)mr->PoolId, mr->MediaType);
+ Dmsg3(100, "find_next_vol_for_append: JobId=%u PoolId=%d, MediaType=%s\n",
+ (uint32_t)jcr->JobId, (int)mr->PoolId, mr->MediaType);
/*
* If we are using an Autochanger, restrict Volume
* search to the Autochanger on the first pass
} else if (mr->MaxVolJobs > 0 && mr->MaxVolJobs <= mr->VolJobs) {
Jmsg(jcr, M_INFO, 0, _("Max Volume jobs exceeded. "
"Marking Volume \"%s\" as Used.\n"), mr->VolumeName);
+ Dmsg3(100, "MaxVolJobs=%d JobId=%d Vol=%s\n", mr->MaxVolJobs,
+ (uint32_t)jcr->JobId, mr->VolumeName);
bstrncpy(mr->VolStatus, "Used", sizeof(mr->VolStatus));
expired = true;
* For a set of errors, ... keep the current status
* so it isn't lost. For all others, set it.
*/
- Dmsg2(100, "OnEntry JobStatus=%c set=%c\n", jcr->JobStatus, JobStatus);
+ Dmsg3(300, "jid=%u OnEntry JobStatus=%c set=%c\n", (uint32_t)jcr->JobId,
+ jcr->JobStatus, JobStatus);
switch (jcr->JobStatus) {
case JS_ErrorTerminated:
case JS_FatalError:
default:
jcr->JobStatus = JobStatus;
}
- Dmsg2(100, "OnExit JobStatus=%c set=%c\n", jcr->JobStatus, JobStatus);
+ Dmsg3(100, "jid=%u OnExit JobStatus=%c set=%c\n", (uint32_t)jcr->JobId,
+ jcr->JobStatus, JobStatus);
}
#ifdef TRACE_JCR_CHAIN
dev->dlock();
if (dcr->reserved_device) {
dev->reserved_device--;
- Dmsg2(100, "Dec reserve=%d dev=%s\n", dev->reserved_device, dev->print_name());
+ Dmsg3(100, "jid=%u Dec reserve=%d dev=%s\n", (uint32_t)jcr->JobId,
+ dev->reserved_device, dev->print_name());
dcr->reserved_device = false;
}
dev->dunblock(DEV_LOCKED);
dev->dlock();
if (dcr->reserved_device) {
dev->reserved_device--;
- Dmsg2(100, "Dec reserve=%d dev=%s\n", dev->reserved_device, dev->print_name());
+ Dmsg3(100, "jid=%u Dec reserve=%d dev=%s\n", (uint32_t)jcr->JobId,
+ dev->reserved_device, dev->print_name());
dcr->reserved_device = false;
}
dev->dunblock(DEV_LOCKED);
return false;
}
memset(&vol, 0, sizeof(vol));
- Dmsg1(100, "<dird %s\n", dir->msg);
+ Dmsg2(100, "<dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
n = sscanf(dir->msg, OK_media, vol.VolCatName,
&vol.VolCatJobs, &vol.VolCatFiles,
&vol.VolCatBlocks, &vol.VolCatBytes,
&vol.EndFile, &vol.EndBlock, &vol.VolCatParts,
&vol.LabelType, &vol.VolMediaId);
if (n != 22) {
- Dmsg3(100, "Bad response from Dir fields=%d, len=%d: %s", n, dir->msglen, dir->msg);
+ Dmsg4(100, "Bad response from Dir jid=%u fields=%d, len=%d: %s",
+ (uint32_t)jcr->JobId, n, dir->msglen, dir->msg);
Mmsg(jcr->errmsg, _("Error getting Volume info: %s"), dir->msg);
return false;
}
bstrncpy(dcr->VolumeName, vol.VolCatName, sizeof(dcr->VolumeName));
dcr->VolCatInfo = vol; /* structure assignment */
- Dmsg2(100, "do_reqest_vol_info return true slot=%d Volume=%s\n",
- vol.Slot, vol.VolCatName);
+ Dmsg3(100, "do_reqest_vol_info return true jid=%u slot=%d Volume=%s\n",
+ (uint32_t)jcr->JobId, vol.Slot, vol.VolCatName);
return true;
}
bash_spaces(dcr->VolCatInfo.VolCatName);
dir->fsend(Get_Vol_Info, jcr->Job, dcr->VolCatInfo.VolCatName,
writing==GET_VOL_INFO_FOR_WRITE?1:0);
- Dmsg1(100, ">dird: %s\n", dir->msg);
+ Dmsg2(100, ">dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
unbash_spaces(dcr->VolCatInfo.VolCatName);
bool ok = do_get_volume_info(dcr);
V(vol_info_mutex);
dir->fsend(Find_media, jcr->Job, vol_index, dcr->pool_name, dcr->media_type);
unbash_spaces(dcr->media_type);
unbash_spaces(dcr->pool_name);
- Dmsg1(100, ">dird: %s", dir->msg);
+ Dmsg2(100, ">dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
bool ok = do_get_volume_info(dcr);
if (ok) {
if (!is_volume_in_use(dcr)) {
found = true;
break;
} else {
- Dmsg1(100, "Volume %s is in use.\n", dcr->VolumeName);
+ Dmsg2(100, "jid=%u Volume %s is in use.\n", (uint32_t)jcr->JobId, dcr->VolumeName);
dcr->volume_in_use = true;
continue;
}
edit_int64(vol->VolWriteTime, ed4),
edit_uint64(vol->VolFirstWritten, ed5),
vol->VolCatParts);
- Dmsg1(100, ">dird: %s", dir->msg);
+ Dmsg2(100, ">dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
/* Do not lock device here because it may be locked from label */
if (!do_get_volume_info(dcr)) {
vol->VolCatName, jcr->errmsg);
goto bail_out;
}
- Dmsg1(420, "get_volume_info(): %s", dir->msg);
+ Dmsg2(420, "get_volume_info() jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
/* Update dev Volume info in case something changed (e.g. expired) */
dev->VolCatInfo = dcr->VolCatInfo;
ok = true;
dcr->StartBlock, dcr->EndBlock,
dcr->Copy, dcr->Stripe,
edit_uint64(dcr->VolMediaId, ed1));
- Dmsg1(100, ">dird: %s", dir->msg);
+ Dmsg2(100, ">dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
if (bnet_recv(dir) <= 0) {
Dmsg0(190, "create_jobmedia error bnet_recv\n");
Jmsg(jcr, M_FATAL, 0, _("Error creating JobMedia record: ERR=%s\n"),
bnet_strerror(dir));
return false;
}
- Dmsg1(100, "<dir: %s", dir->msg);
+ Dmsg2(100, "<dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
if (strcmp(dir->msg, OK_create) != 0) {
Dmsg1(130, "Bad response from Dir: %s\n", dir->msg);
Jmsg(jcr, M_FATAL, 0, _("Error creating JobMedia record: %s\n"), dir->msg);
ser_uint32(rec->data_len);
ser_bytes(rec->data, rec->data_len);
dir->msglen = ser_length(dir->msg);
- Dmsg1(1800, ">dird: %s\n", dir->msg); /* Attributes */
+ Dmsg2(1800, ">dird jid=%u: %s\n", (uint32_t)jcr->JobId, dir->msg); /* Attributes */
return bnet_send(dir);
}
make_session_key(auth_key, NULL, 1);
dir->fsend(OKjob, jcr->VolSessionId, jcr->VolSessionTime, auth_key);
if (debug_level == 3) {
- Dmsg1(000, ">dird: %s", dir->msg);
+ Dmsg2(000, ">dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
}
- Dmsg1(100, ">dird: %s", dir->msg);
+ Dmsg2(100, ">dird jid=%u: %s", (uint32_t)jcr->JobId, dir->msg);
jcr->sd_auth_key = bstrdup(auth_key);
memset(auth_key, 0, sizeof(auth_key));
generate_daemon_event(jcr, "JobStart");
V(mutex);
if (debug_level == 3) {
- Dmsg0(000, "Zap sd_auth_key\n");
+ Dmsg1(000, "jid=%u Zap sd_auth_key\n", (uint32_t)jcr->JobId);
}
memset(jcr->sd_auth_key, 0, strlen(jcr->sd_auth_key));
* Authenticate the File daemon
*/
if (debug_level == 3) {
- Dmsg1(000, "sd_auth_key=%s\n", jcr->sd_auth_key);
+ Dmsg2(000, "jid=%u sd_auth_key=%s\n", (uint32_t)jcr->JobId, jcr->sd_auth_key);
}
if (jcr->authenticated || !authenticate_filed(jcr)) {
Dmsg1(100, "Authentication failed Job %s\n", jcr->Job);
Jmsg(jcr, M_FATAL, 0, _("Unable to authenticate File daemon\n"));
} else {
jcr->authenticated = true;
- Dmsg1(110, "OK Authentication Job %s\n", jcr->Job);
+ Dmsg2(110, "OK Authentication jid=%u Job %s\n", (uint32_t)jcr->JobId, jcr->Job);
}
if (!jcr->authenticated) {
* DEVICE::dlock() does P(m_mutex) (in dev.h)
* DEVICE::dunlock() does V(m_mutex)
*
+ * DEVICE::r_dlock() does recursive locking
+ * dlock()
+ * if blocked and not same thread that locked
+ * pthread_cond_wait
+ * leaves device locked
+ *
+ * DEVICE::r_dunlock()
+ * same as dunlock();
+ *
* DEVICE::dblock(why) does
* r_dlock(); (recursive device lock)
* block_device(this, why)
* unblock_device()
* dunlock()
*
- * DEVICE::r_dlock() does recursive locking
- * dlock()
- * if blocked and not same thread that locked
- * pthread_cond_wait
- * leaves device locked
- *
- * DEVICE::r_dunlock()
- * same as dunlock();
- *
* block_device() does (must be locked and not blocked at entry)
* set blocked status
* set our pid
/*
* First erase all memory of the current volume
*/
+ free_volume(dev);
dev->block_num = dev->file = 0;
dev->EndBlock = dev->EndFile = 0;
memset(&dev->VolCatInfo, 0, sizeof(dev->VolCatInfo));
#include "bacula.h"
#include "stored.h"
-#define jid() ((int)get_jobid_from_tid())
+#define jid() ((uint32_t)get_jobid_from_tid())
const int dbglvl = 50;
DEVICE *dev = NULL;
foreach_dlist(vol, vol_list) {
if (vol->dev == dev) {
- Dmsg0(000, "Two Volumes on same device.\n");
+ Dmsg0(dbglvl, "Two Volumes on same device.\n");
ASSERT(0);
dev = vol->dev;
}
* already exist and are correctly programmed and will need no changes -- use
* counts are always very tricky.
*
- * The old code had a concept of "reserving" a Volume, but it needs to be changed
+ * The old code had a concept of "reserving" a Volume, but was changed
* to reserving and using a drive. A volume is must be attached to (owned by) a
* drive and can move from drive to drive or be unused given certain specific
* conditions of the drive. The key is that the drive must "own" the Volume.
- * The old code has the job (dcr) owning the volume (more or less). The job is
+ * The old code had the job (dcr) owning the volume (more or less). The job was
* to change the insertion and removal of the volumes from the list to be based
* on the drive rather than the job.
*
if (strcmp(vol->vol_name, VolumeName) == 0) {
goto get_out; /* Volume already on this device */
} else {
+ if (dev->is_busy() && dev->VolHdr.VolumeName[0]) {
+ vol = NULL;
+ goto get_out;
+ }
Dmsg3(dbglvl, "jid=%u reserve_vol free vol=%s at %p\n",
(int)dcr->jcr->JobId, vol->vol_name, vol->vol_name);
debug_list_volumes("reserve_vol free");
dlist *temp_vol_list, *save_vol_list;
VOLRES *vol = NULL;
lock_volumes();
+ Dmsg1(dbglvl, "jid=%u lock volumes\n", (uint32_t)rctx.jcr->JobId);
/*
* Create a temporary copy of the volume list. We do this,
Jmsg(jcr, M_WARNING, 0, "Logic error. Duplicating vol list hit duplicate.\n");
}
}
+ Dmsg1(dbglvl, "jid=%u unlock volumes\n", (uint32_t)jcr->JobId);
unlock_volumes();
/* Look through reserved volumes for one we can use */
}
} /* end for loop over reserved volumes */
+ Dmsg1(dbglvl, "jid=%u lock volumes\n", (uint32_t)rctx.jcr->JobId);
lock_volumes();
save_vol_list = vol_list;
vol_list = temp_vol_list;
free_volume_list(); /* release temp_vol_list */
vol_list = save_vol_list;
Dmsg1(dbglvl, "jid=%u deleted temp vol list\n", (int)rctx.jcr->JobId);
+ Dmsg1(dbglvl, "jid=%u lock volumes\n", (uint32_t)rctx.jcr->JobId);
unlock_volumes();
}
if (ok) {
*/
if (dcr->volume_in_use && !rctx.PreferMountedVols) {
rctx.PreferMountedVols = true;
+ if (dcr->VolumeName[0]) {
+ volume_unused(dcr);
+ }
+ goto bail_out;
+ }
+ if (dcr->dev->num_writers != 0) {
+ if (dcr->VolumeName[0]) {
+ volume_unused(dcr);
+ }
goto bail_out;
}
}
pm_strcpy(dev_name, rctx.device->hdr.name);
bash_spaces(dev_name);
ok = dir->fsend(OK_device, dev_name.c_str()); /* Return real device name */
- Dmsg2(dbglvl, "jid=%u >dird changer: %s", jid(), dir->msg);
+ Dmsg2(dbglvl, "jid=%u >dird: %s", jid(), dir->msg);
} else {
ok = true;
}
return ok;
}
+static int is_pool_ok(DCR *dcr)
+{
+ DEVICE *dev = dcr->dev;
+ JCR *jcr = dcr->jcr;
+
+ /* Now check if we want the same Pool and pool type */
+ if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
+ strcmp(dev->pool_type, dcr->pool_type) == 0) {
+ /* OK, compatible device */
+ Dmsg2(dbglvl, "jid=%u OK dev: %s num_writers=0, reserved, pool matches\n",
+ jcr->JobId, dev->print_name());
+ return 1;
+ } else {
+ /* Drive Pool not suitable for us */
+ Mmsg(jcr->errmsg, _(
+"3608 JobId=%u wants Pool=\"%s\" but have Pool=\"%s\" nreserve=%d on drive %s.\n"),
+ jcr->JobId, dcr->pool_name, dev->pool_name,
+ dev->reserved_device, dev->print_name());
+ queue_reserve_message(jcr);
+ Dmsg3(dbglvl, "jid=%u failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
+ (int)jcr->JobId, dev->pool_name, dcr->pool_name);
+ }
+ return 0;
+}
+
+static bool is_max_jobs_ok(DCR *dcr)
+{
+ DEVICE *dev = dcr->dev;
+ JCR *jcr = dcr->jcr;
+
+ Dmsg5(dbglvl, "jid=%u MaxJobs=%d Jobs=%d reserves=%d Vol=%s\n",
+ (uint32_t)jcr->JobId, dcr->VolCatInfo.VolCatMaxJobs,
+ dcr->VolCatInfo.VolCatJobs, dev->reserved_device,
+ dcr->VolumeName);
+ if (dcr->VolCatInfo.VolCatMaxJobs > 0 && dcr->VolCatInfo.VolCatMaxJobs <=
+ (dcr->VolCatInfo.VolCatJobs + dev->reserved_device)) {
+ /* Max Job Vols depassed or already reserved */
+ Mmsg(jcr->errmsg, _("3610 JobId=%u Volume max jobs exceeded on drive %s.\n"),
+ (uint32_t)jcr->JobId, dev->print_name());
+ queue_reserve_message(jcr);
+ Dmsg2(dbglvl, "jid=%u reserve dev failed: %s", (uint32_t)jcr->JobId, jcr->errmsg);
+ return false; /* wait */
+ }
+ return true;
+}
+
/*
* Returns: 1 if drive can be reserved
* 0 if we should wait
if (dev->num_writers == 0) {
/* Now check if there are any reservations on the drive */
if (dev->reserved_device) {
- /* Now check if we want the same Pool and pool type */
- if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
- strcmp(dev->pool_type, dcr->pool_type) == 0) {
- /* OK, compatible device */
- Dmsg2(dbglvl, "jid=%u OK dev: %s num_writers=0, reserved, pool matches\n",
- jcr->JobId, dev->print_name());
- return 1;
- } else {
- /* Drive Pool not suitable for us */
- Mmsg(jcr->errmsg, _(
-"3608 JobId=%u wants Pool=\"%s\" but have Pool=\"%s\" nreserve=%d on drive %s.\n"),
- jcr->JobId, dcr->pool_name, dev->pool_name,
- dev->reserved_device, dev->print_name());
- queue_reserve_message(jcr);
- Dmsg3(dbglvl, "jid=%u failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
- (int)jcr->JobId, dev->pool_name, dcr->pool_name);
- return 0; /* wait */
+ if (!is_max_jobs_ok(dcr)) {
+ return 0;
}
+ return is_pool_ok(dcr);
} else if (dev->can_append()) {
- /* Device in append mode, check if changing pool */
- if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
- strcmp(dev->pool_type, dcr->pool_type) == 0) {
- Dmsg2(dbglvl, "jid=%u OK dev: %s num_writers=0, can_append, pool matches.\n",
- jcr->JobId, dev->print_name());
- /* OK, compatible device */
- return 1;
+ if (is_pool_ok(dcr)) {
+ return 1;
} else {
/* Changing pool, unload old tape if any in drive */
Dmsg1(dbglvl, "jid=%u OK dev: num_writers=0, not reserved, pool change, unload changer\n",
* available if pool is the same).
*/
if (dev->can_append() || dev->num_writers > 0) {
- /* Yes, now check if we want the same Pool and pool type */
- if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
- strcmp(dev->pool_type, dcr->pool_type) == 0) {
- Dmsg2(dbglvl, "jid=%u OK dev: %s num_writers>=0, can_append, pool matches.\n",
- jcr->JobId, dev->print_name());
- /* OK, compatible device */
- return 1;
- } else {
- /* Drive Pool not suitable for us */
- Mmsg(jcr->errmsg, _("3609 JobId=%u wants Pool=\"%s\" but has Pool=\"%s\" on drive %s.\n"),
- jcr->JobId, dcr->pool_name, dev->pool_name, dev->print_name());
- queue_reserve_message(jcr);
- Dmsg3(dbglvl, "jid=%u failed: busy num_writers>0, can_append, pool=%s wanted=%s\n",
- (int)jcr->JobId, dev->pool_name, dcr->pool_name);
- return 0; /* wait */
+ if (!is_max_jobs_ok(dcr)) {
+ return 0;
}
+ return is_pool_ok(dcr);
} else {
Pmsg1(000, _("Logic error!!!! JobId=%u Should not get here.\n"), (int)jcr->JobId);
Mmsg(jcr->errmsg, _("3910 JobId=%u Logic error!!!! drive %s Should not get here.\n"),
*/
#undef VERSION
-#define VERSION "2.3.4"
-#define BDATE "14 September 2007"
-#define LSMDATE "14Sep07"
+#define VERSION "2.3.5"
+#define BDATE "23 September 2007"
+#define LSMDATE "23Sep07"
#define PROG_COPYRIGHT "Copyright (C) %d-2007 Free Software Foundation Europe e.V.\n"
#define BYEAR "2007" /* year for copyright messages in progs */
Technical notes on version 2.3
General:
+23Sep07
+kes Rework the reservation system to take into account that the Director
+ might give us a Volume that is different from the current one being
+ used, and to ensure that we don't exceed Maximum Volume Jobs.
+ This fixes (mostly) bug #947 ' Maximum Volume Jobs = 1 produces
+ fatal error with multiple jobs running'
+kes Add more debug code in reservation system.
+kes Implement maxvol-test to check bug #947.
22Sep07
kes Add code to handle tray monitor separated from Win32 FD.
kes Fix display of Win32 tray monitor after reboot. Fixes bug #952.