if ((errstat=rwl_init(&reservation_lock)) != 0) {
berrno be;
Emsg1(M_ABORT, 0, _("Unable to initialize reservation lock. ERR=%s\n"),
- be.strerror(errstat));
+ be.bstrerror(errstat));
}
}
if ((errstat=rwl_writelock(&reservation_lock)) != 0) {
berrno be;
Emsg2(M_ABORT, 0, "rwl_writelock failure. stat=%d: ERR=%s\n",
- errstat, be.strerror(errstat));
+ errstat, be.bstrerror(errstat));
}
}
if ((errstat=rwl_writeunlock(&reservation_lock)) != 0) {
berrno be;
Emsg2(M_ABORT, 0, "rwl_writeunlock failure. stat=%d: ERR=%s\n",
- errstat, be.strerror(errstat));
+ errstat, be.bstrerror(errstat));
}
}
/* ***FIXME**** remove after 1.38 release */
char *device_name;
foreach_alist(store, dirstore) {
- Dmsg5(110, "Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n",
+ Dmsg6(110, "JobId=%u Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n",
+ (int)rctx.jcr->JobId,
store->name, store->media_type, store->pool_name,
store->pool_type, store->append);
foreach_alist(device_name, store->device) {
* Wiffle through them and find one that can do the backup.
*/
if (ok) {
- bool first = true; /* print wait message once */
+ int retries = 0; /* wait for device retries */
bool fail = false;
rctx.notify_dir = true;
lock_reservations();
rctx.PreferMountedVols = false;
rctx.exact_match = false;
rctx.autochanger_only = true;
- Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ Dmsg6(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ (int)rctx.jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only, rctx.any_drive);
if ((ok = find_suitable_device_for_job(jcr, rctx))) {
rctx.try_low_use_drive = false;
}
rctx.autochanger_only = false;
- Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ Dmsg6(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ (int)rctx.jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only, rctx.any_drive);
if ((ok = find_suitable_device_for_job(jcr, rctx))) {
rctx.PreferMountedVols = true;
rctx.exact_match = true;
rctx.autochanger_only = false;
- Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ Dmsg6(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ (int)rctx.jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only, rctx.any_drive);
if ((ok = find_suitable_device_for_job(jcr, rctx))) {
}
/* Look for any mounted drive */
rctx.exact_match = false;
- Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ Dmsg6(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ (int)rctx.jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only, rctx.any_drive);
if ((ok = find_suitable_device_for_job(jcr, rctx))) {
}
/* Try any drive */
rctx.any_drive = true;
- Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ Dmsg6(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ (int)rctx.jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only, rctx.any_drive);
if ((ok = find_suitable_device_for_job(jcr, rctx))) {
}
/* Keep reservations locked *except* during wait_for_device() */
unlock_reservations();
- if (!rctx.suitable_device || !wait_for_device(jcr, first)) {
- Dmsg0(100, "Fail. !suitable_device || !wait_for_device\n");
+ if (!rctx.suitable_device || !wait_for_device(jcr, retries)) {
+ Dmsg1(100, "JobId=%u Fail. !suitable_device || !wait_for_device\n",
+ (int)rctx.jcr->JobId);
fail = true;
}
lock_reservations();
- first = false;
bnet_sig(dir, BNET_HEARTBEAT); /* Inform Dir that we are alive */
}
unlock_reservations();
* For each storage device that the user specified, we
* search and see if there is a resource for that device.
*/
- Dmsg4(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d\n",
+ Dmsg5(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d\n",
+ (int)rctx.jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only);
ok = false;
rctx.device_name = device_name;
stat = search_res_for_device(rctx);
if (stat == 1) { /* found available device */
- Dmsg1(100, "Suitable device found=%s\n", device_name);
+ Dmsg2(100, "JobId=%u Suitable device found=%s\n", (int)rctx.jcr->JobId,
+ device_name);
ok = true;
break;
} else if (stat == 0) { /* device busy */
- Dmsg1(110, "Suitable device=%s, busy: not use\n", device_name);
+ Dmsg2(110, "JobId=%u Suitable device=%s, busy: not use\n",
+ (int)rctx.jcr->JobId, device_name);
} else {
/* otherwise error */
- Dmsg0(110, "No suitable device found.\n");
+ Dmsg1(110, "JobId=%u No suitable device found.\n", (int)rctx.jcr->JobId);
}
}
if (ok) {
bool ok;
int stat;
- Dmsg1(110, "Search res for %s\n", rctx.device_name);
+ Dmsg2(110, "JobId=%u search res for %s\n", (int)rctx.jcr->JobId, rctx.device_name);
/* Look through Autochangers first */
foreach_res(changer, R_AUTOCHANGER) {
- Dmsg1(150, "Try match changer res=%s\n", changer->hdr.name);
+ Dmsg2(150, "JobId=%u Try match changer res=%s\n", (int)rctx.jcr->JobId, changer->hdr.name);
/* Find resource, and make sure we were able to open it */
if (fnmatch(rctx.device_name, changer->hdr.name, 0) == 0) {
/* Try each device in this AutoChanger */
foreach_alist(rctx.device, changer->device) {
- Dmsg1(110, "Try changer device %s\n", rctx.device->hdr.name);
+ Dmsg2(110, "JobId=%u Try changer device %s\n", (int)rctx.jcr->JobId,
+ rctx.device->hdr.name);
stat = reserve_device(rctx);
if (stat != 1) { /* try another device */
continue;
}
POOL_MEM dev_name;
if (rctx.store->append == SD_APPEND) {
- Dmsg2(100, "Device %s reserved=%d for append.\n", rctx.device->hdr.name,
+ Dmsg3(100, "JobId=%u Device %s reserved=%d for append.\n",
+ (int)rctx.jcr->JobId, rctx.device->hdr.name,
rctx.jcr->dcr->dev->reserved_device);
} else {
- Dmsg2(100, "Device %s reserved=%d for read.\n", rctx.device->hdr.name,
+ Dmsg3(100, "JobId=%u Device %s reserved=%d for read.\n",
+ (int)rctx.jcr->JobId, rctx.device->hdr.name,
rctx.jcr->read_dcr->dev->reserved_device);
}
if (rctx.notify_dir) {
/* Now if requested look through regular devices */
if (!rctx.autochanger_only) {
foreach_res(rctx.device, R_DEVICE) {
- Dmsg1(150, "Try match res=%s\n", rctx.device->hdr.name);
+ Dmsg2(150, "JobId=%u Try match res=%s\n", (int)rctx.jcr->JobId, rctx.device->hdr.name);
/* Find resource, and make sure we were able to open it */
if (fnmatch(rctx.device_name, rctx.device->hdr.name, 0) == 0) {
stat = reserve_device(rctx);
const int name_len = MAX_NAME_LENGTH;
/* Make sure MediaType is OK */
- Dmsg2(110, "MediaType device=%s request=%s\n",
+ Dmsg3(110, "JobId=%u MediaType device=%s request=%s\n",
+ (int)rctx.jcr->JobId,
rctx.device->media_type, rctx.store->media_type);
if (strcmp(rctx.device->media_type, rctx.store->media_type) != 0) {
return -1;
bstrncpy(dcr->media_type, rctx.store->media_type, name_len);
bstrncpy(dcr->dev_name, rctx.device_name, name_len);
if (rctx.store->append == SD_APPEND) {
- Dmsg2(100, "have_vol=%d vol=%s\n", rctx.have_volume, rctx.VolumeName);
+ Dmsg3(100, "JobId=%u have_vol=%d vol=%s\n", (int)rctx.jcr->JobId,
+ rctx.have_volume, rctx.VolumeName);
if (!rctx.have_volume) {
dcr->any_volume = true;
if (dir_find_next_appendable_volume(dcr)) {
Dmsg2(100, "JobId=%u looking for Volume=%s\n", (int)rctx.jcr->JobId, rctx.VolumeName);
rctx.have_volume = true;
} else {
- Dmsg0(100, "No next volume found\n");
+ Dmsg1(100, "JobId=%u No next volume found\n", (int)rctx.jcr->JobId);
rctx.have_volume = false;
rctx.VolumeName[0] = 0;
}
ok = reserve_device_for_append(dcr, rctx);
if (ok) {
rctx.jcr->dcr = dcr;
- Dmsg5(100, "Reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+ Dmsg6(100, "JobId=%u Reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+ (int)rctx.jcr->JobId,
dcr->dev->reserved_device,
dcr->dev_name, dcr->media_type, dcr->pool_name, ok);
}
ok = reserve_device_for_read(dcr);
if (ok) {
rctx.jcr->read_dcr = dcr;
- Dmsg5(100, "Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+ Dmsg6(100, "JobId=%u Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+ (int)rctx.jcr->JobId,
dcr->dev->reserved_device,
dcr->dev_name, dcr->media_type, dcr->pool_name, ok);
}
if (!ok) {
rctx.have_volume = false;
free_dcr(dcr);
- Dmsg0(110, "Not OK.\n");
+ Dmsg1(110, "JobId=%u Not OK.\n", (int)rctx.jcr->JobId);
return 0;
}
return 1;
dev->dlock();
if (is_device_unmounted(dev)) {
- Dmsg1(200, "Device %s is BLOCKED due to user unmount.\n", dev->print_name());
+ Dmsg2(200, "JobId=%u Device %s is BLOCKED due to user unmount.\n",
+ (int)jcr->JobId, dev->print_name());
Mmsg(jcr->errmsg, _("3601 JobId=%u device %s is BLOCKED due to user unmount.\n"),
jcr->JobId, dev->print_name());
queue_reserve_message(jcr);
}
if (dev->is_busy()) {
- Dmsg4(200, "Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", dev->print_name(),
+ Dmsg5(200, "JobId=%u Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n",
+ (int)jcr->JobId, dev->print_name(),
dev->state & ST_READ?1:0, dev->num_writers, dev->reserved_device);
Mmsg(jcr->errmsg, _("3602 JobId=%u device %s is busy (already reading/writing).\n"),
jcr->JobId, dev->print_name());
dev->set_read();
ok = true;
dev->reserved_device++;
- Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device,
- dev->print_name(), dev);
+ Dmsg4(100, "JobId=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId,
+ dev->reserved_device, dev->print_name(), dev);
dcr->reserved_device = true;
bail_out:
goto bail_out;
}
- Dmsg1(110, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk");
+ Dmsg2(110, "JobId=%u reserve_append device is %s\n",
+ (int)jcr->JobId, dev->is_tape()?"tape":"disk");
/* Now do detailed tests ... */
if (can_reserve_drive(dcr, rctx) != 1) {
- Dmsg0(110, "can_reserve_drive!=1\n");
+ Dmsg1(110, "JobId=%u can_reserve_drive!=1\n", (int)jcr->JobId);
goto bail_out;
}
dev->reserved_device++;
- Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device,
+ Dmsg4(100, "JobId=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, dev->reserved_device,
dev->print_name(), dev);
dcr->reserved_device = true;
ok = true;
DEVICE *dev = dcr->dev;
JCR *jcr = dcr->jcr;
- Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ Dmsg6(110, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+ (int)jcr->JobId,
rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
rctx.autochanger_only, rctx.any_drive);
if ((dev->num_writers + dev->reserved_device) < rctx.num_writers) {
rctx.num_writers = dev->num_writers + dev->reserved_device;
rctx.low_use_drive = dev;
- Dmsg2(110, "set low use drive=%s num_writers=%d\n", dev->print_name(),
- rctx.num_writers);
+ Dmsg3(110, "JobId=%u set low use drive=%s num_writers=%d\n",
+ (int)jcr->JobId, dev->print_name(), rctx.num_writers);
} else {
- Dmsg1(110, "not low use num_writers=%d\n", dev->num_writers+
- dev->reserved_device);
+ Dmsg2(110, "JobId=%u not low use num_writers=%d\n",
+ (int)jcr->JobId, dev->num_writers+dev->reserved_device);
}
Dmsg1(110, "failed: !prefMnt && busy. JobId=%u\n", jcr->JobId);
Mmsg(jcr->errmsg, _("3605 JobId=%u wants free drive but device %s is busy.\n"),
}
/* Check for prefer mounted volumes */
- if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) {
+// if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) {
+ if (rctx.PreferMountedVols && !dev->vol && dev->is_tape()) {
Mmsg(jcr->errmsg, _("3606 JobId=%u prefers mounted drives, but drive %s has no Volume.\n"),
jcr->JobId, dev->print_name());
queue_reserve_message(jcr);
- Dmsg1(110, "failed: want mounted -- no vol JobId=%u\n", jcr->JobId);
+ Dmsg1(110, "failed: want mounted -- no vol JobId=%u\n", (uint32_t)jcr->JobId);
return 0; /* No volume mounted */
}
/* Check for exact Volume name match */
+ /* ***FIXME*** use dev->vol.VolumeName */
if (rctx.exact_match && rctx.have_volume &&
strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) != 0) {
Mmsg(jcr->errmsg, _("3607 JobId=%u wants Vol=\"%s\" drive has Vol=\"%s\" on drive %s.\n"),
jcr->JobId, rctx.VolumeName, dev->VolHdr.VolumeName,
dev->print_name());
queue_reserve_message(jcr);
- Dmsg2(110, "failed: Not exact match have=%s want=%s\n",
- dev->VolHdr.VolumeName, rctx.VolumeName);
+ Dmsg3(110, "JobId=%u failed: Not exact match have=%s want=%s\n",
+ (int)jcr->JobId, dev->VolHdr.VolumeName, rctx.VolumeName);
return 0;
}
}
/* Check for unused autochanger drive */
+ /* ***FIXME*** use !dev->is_busy() */
if (rctx.autochanger_only && dev->num_writers == 0 &&
dev->VolHdr.VolumeName[0] == 0) {
/* Device is available but not yet reserved, reserve it for us */
jcr->JobId, dcr->pool_name, dev->pool_name,
dev->reserved_device, dev->print_name());
queue_reserve_message(jcr);
- Dmsg2(110, "failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
- dev->pool_name, dcr->pool_name);
+ Dmsg3(110, "JobId=%u failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
+ (int)jcr->JobId, dev->pool_name, dcr->pool_name);
return 0; /* wait */
}
} else if (dev->can_append()) {
return 1;
} else {
/* Changing pool, unload old tape if any in drive */
- Dmsg0(100, "OK dev: num_writers=0, not reserved, pool change, unload changer\n");
+ Dmsg1(100, "JobId=%u OK dev: num_writers=0, not reserved, pool change, unload changer\n",
+ (int)jcr->JobId);
unload_autochanger(dcr, 0);
}
}
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);
- Dmsg2(110, "failed: busy num_writers>0, can_append, pool=%s wanted=%s\n",
- dev->pool_name, dcr->pool_name);
+ Dmsg3(110, "JobId=%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 */
}
} else {
- Pmsg0(000, _("Logic error!!!! Should not get here.\n"));
+ 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"),
jcr->JobId, dev->print_name());
queue_reserve_message(jcr);
projects / bacula / bacula / blobdiff