From: Kern Sibbald Date: Tue, 23 Aug 2005 16:13:31 +0000 (+0000) Subject: - Fix bug in acquire.c that incorrectly reported volume X-Git-Tag: Release-1.38.0~151 X-Git-Url: https://git.sur5r.net/?a=commitdiff_plain;h=fcc810b54e2fac2c96d6b8e24eb7ec8dd445ab34;p=bacula%2Fbacula - Fix bug in acquire.c that incorrectly reported volume busy. - Add additional debug code and messages in reserve.c - Eliminate unwanted warning message in reserve.c git-svn-id: https://bacula.svn.sourceforge.net/svnroot/bacula/trunk@2353 91ce42f0-d328-0410-95d8-f526ca767f89 --- diff --git a/bacula/kernstodo b/bacula/kernstodo index fba0879df9..c2539350a0 100644 --- a/bacula/kernstodo +++ b/bacula/kernstodo @@ -29,6 +29,7 @@ Document: records have been removed from the catalog. For 1.39: +- Allow Check Labels to be used with Bacula labels. - "Resuming" a failed backup (lost line for example) by using the failed backup as a sort of "base" job. - Look at NDMP @@ -1420,4 +1421,3 @@ Block Position: 0 wants a Volume that is released but in another drive -- chaos. - Run the regression scripts on Solaris and FreeBSD - diff --git a/bacula/kes-1.37 b/bacula/kes-1.37 index 21090459a9..c3ba3e153d 100644 --- a/bacula/kes-1.37 +++ b/bacula/kes-1.37 @@ -3,7 +3,14 @@ General: -Changes to 1.37.36: +Changes to 1.37.37: +23Aug05 +- Fix bug in acquire.c that incorrectly reported volume + busy. +- Add additional debug code and messages in reserve.c +- Eliminate unwanted warning message in reserve.c + +Changes to 1.37.36 release 22Aug05: 20Aug05 - Landon's fix for NLS detection - Eliminate incorrect compiler warning on FreeBSD. diff --git a/bacula/src/stored/acquire.c b/bacula/src/stored/acquire.c index b3cc711d88..4b88e35146 100644 --- a/bacula/src/stored/acquire.c +++ b/bacula/src/stored/acquire.c @@ -37,7 +37,7 @@ DCR *new_dcr(JCR *jcr, DEVICE *dev) dcr->jcr = jcr; if (dev) { if (jcr) { - jcr->dcr = dcr; + jcr->dcr = dcr; } dcr->dev = dev; dcr->device = dev->device; @@ -46,8 +46,8 @@ DCR *new_dcr(JCR *jcr, DEVICE *dev) dcr->max_job_spool_size = dev->device->max_job_spool_size; /* Attach this dcr only if dev is initialized */ if (dev->fd != 0 && jcr && jcr->JobType != JT_SYSTEM) { - dev->attached_dcrs->append(dcr); /* attach dcr to device */ -// jcr->dcrs->append(dcr); /* put dcr in list for Job */ + dev->attached_dcrs->append(dcr); /* attach dcr to device */ +// jcr->dcrs->append(dcr); /* put dcr in list for Job */ } } dcr->spool_fd = -1; @@ -68,13 +68,13 @@ static void remove_dcr_from_dcrs(DCR *dcr) DCR *ldcr; int num = jcr->dcrs->size(); for (i=0; i < num; i++) { - ldcr = (DCR *)jcr->dcrs->get(i); - if (ldcr == dcr) { - jcr->dcrs->remove(i); - if (jcr->dcr == dcr) { - jcr->dcr = NULL; - } - } + ldcr = (DCR *)jcr->dcrs->get(i); + if (ldcr == dcr) { + jcr->dcrs->remove(i); + if (jcr->dcr == dcr) { + jcr->dcr = NULL; + } + } } } } @@ -96,14 +96,14 @@ void free_dcr(DCR *dcr) dcr->reserved_device = false; if (dev->num_writers < 0) { Jmsg1(dcr->jcr, M_ERROR, 0, _("Hey! num_writers=%d!!!!\n"), dev->num_writers); - dev->num_writers = 0; + dev->num_writers = 0; } unlock_device(dev); } /* Detach this dcr only if the dev is initialized */ if (dev->fd != 0 && jcr && jcr->JobType != JT_SYSTEM) { - dev->attached_dcrs->remove(dcr); /* detach dcr from device */ + dev->attached_dcrs->remove(dcr); /* detach dcr from device */ // remove_dcr_from_dcrs(dcr); /* remove dcr from jcr list */ } if (dcr->block) { @@ -115,7 +115,7 @@ void free_dcr(DCR *dcr) if (dcr->jcr) { dcr->jcr->dcr = NULL; } - free_unused_volume(dcr); /* free unused vols attached to this dcr */ + free_unused_volume(dcr); /* free unused vols attached to this dcr */ free(dcr); } @@ -126,7 +126,7 @@ void free_dcr(DCR *dcr) * leave the block pointers just after the label. * * Returns: NULL if failed for any reason - * dcr if successful + * dcr if successful */ DCR *acquire_device_for_read(DCR *dcr) { @@ -144,7 +144,7 @@ DCR *acquire_device_for_read(DCR *dcr) if (dev->num_writers > 0) { Jmsg2(jcr, M_FATAL, 0, _("Num_writers=%d not zero. Job %d canceled.\n"), - dev->num_writers, jcr->JobId); + dev->num_writers, jcr->JobId); goto get_out; } @@ -159,14 +159,14 @@ DCR *acquire_device_for_read(DCR *dcr) vol = vol->next; } if (!vol) { - goto get_out; /* should not happen */ + goto get_out; /* should not happen */ } bstrncpy(dcr->VolumeName, vol->VolumeName, sizeof(dcr->VolumeName)); init_device_wait_timers(dcr); tape_previously_mounted = dev->can_read() || dev->can_append() || - dev->is_labeled(); + dev->is_labeled(); tape_initially_mounted = tape_previously_mounted; @@ -177,10 +177,10 @@ DCR *acquire_device_for_read(DCR *dcr) } for (i=0; i<5; i++) { - dev->clear_labeled(); /* force reread of label */ + dev->clear_labeled(); /* force reread of label */ if (job_canceled(jcr)) { Mmsg1(dev->errmsg, _("Job %d canceled.\n"), jcr->JobId); - goto get_out; /* error return */ + goto get_out; /* error return */ } /* * This code ensures that the device is ready for @@ -189,25 +189,25 @@ DCR *acquire_device_for_read(DCR *dcr) */ Dmsg1(100, "bstored: open vol=%s\n", dcr->VolumeName); if (dev->open(dcr, OPEN_READ_ONLY) < 0) { - if (dev->dev_errno == EIO) { /* no tape loaded */ + if (dev->dev_errno == EIO) { /* no tape loaded */ Jmsg3(jcr, M_WARNING, 0, _("Open device %s Volume \"%s\" failed (EIO): ERR=%s\n"), - dev->print_name(), dcr->VolumeName, strerror_dev(dev)); - goto default_path; - } - + dev->print_name(), dcr->VolumeName, strerror_dev(dev)); + goto default_path; + } + #ifdef xxx_needed - /* If we have a dvd that requires mount, - * we need to try to open the label, so the info can be reported - * if a wrong volume has been mounted. - */ - if (dev->is_dvd() && (dcr->VolCatInfo.VolCatParts > 0)) { - break; - } + /* If we have a dvd that requires mount, + * we need to try to open the label, so the info can be reported + * if a wrong volume has been mounted. + */ + if (dev->is_dvd() && (dcr->VolCatInfo.VolCatParts > 0)) { + break; + } #endif - + Jmsg3(jcr, M_FATAL, 0, _("Open device %s Volume \"%s\" failed: ERR=%s\n"), - dev->print_name(), dcr->VolumeName, strerror_dev(dev)); - goto get_out; + dev->print_name(), dcr->VolumeName, strerror_dev(dev)); + goto get_out; } Dmsg1(100, "opened dev %s OK\n", dev->print_name()); @@ -217,61 +217,61 @@ DCR *acquire_device_for_read(DCR *dcr) vol_label_status = read_dev_volume_label(dcr); switch (vol_label_status) { case VOL_OK: - vol_ok = true; - memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo)); - break; /* got it */ + vol_ok = true; + memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo)); + break; /* got it */ case VOL_IO_ERROR: - /* - * Send error message generated by read_dev_volume_label() - * only we really had a tape mounted. This supresses superfluous - * error messages when nothing is mounted. - */ - if (tape_previously_mounted) { + /* + * Send error message generated by read_dev_volume_label() + * only we really had a tape mounted. This supresses superfluous + * error messages when nothing is mounted. + */ + if (tape_previously_mounted) { Jmsg(jcr, M_WARNING, 0, "%s", jcr->errmsg); - } - goto default_path; + } + goto default_path; case VOL_NAME_ERROR: - if (tape_initially_mounted) { - tape_initially_mounted = false; - goto default_path; - } - /* Fall through */ + if (tape_initially_mounted) { + tape_initially_mounted = false; + goto default_path; + } + /* Fall through */ default: Jmsg1(jcr, M_WARNING, 0, "%s", jcr->errmsg); default_path: - tape_previously_mounted = true; - - /* If the device requires mount, close it, so the device can be ejected. - * FIXME: This should perhaps be done for all devices. */ - if (dev->requires_mount()) { - force_close_device(dev); - } - - /* Call autochanger only once unless ask_sysop called */ - if (try_autochanger) { - int stat; + tape_previously_mounted = true; + + /* If the device requires mount, close it, so the device can be ejected. + * FIXME: This should perhaps be done for all devices. */ + if (dev->requires_mount()) { + force_close_device(dev); + } + + /* Call autochanger only once unless ask_sysop called */ + if (try_autochanger) { + int stat; Dmsg2(200, "calling autoload Vol=%s Slot=%d\n", - dcr->VolumeName, dcr->VolCatInfo.Slot); - stat = autoload_device(dcr, 0, NULL); - if (stat > 0) { - try_autochanger = false; - continue; /* try reading volume mounted */ - } - } - - /* Mount a specific volume and no other */ + dcr->VolumeName, dcr->VolCatInfo.Slot); + stat = autoload_device(dcr, 0, NULL); + if (stat > 0) { + try_autochanger = false; + continue; /* try reading volume mounted */ + } + } + + /* Mount a specific volume and no other */ Dmsg0(200, "calling dir_ask_sysop\n"); - if (!dir_ask_sysop_to_mount_volume(dcr)) { - goto get_out; /* error return */ - } - try_autochanger = true; /* permit using autochanger again */ - continue; /* try reading again */ + if (!dir_ask_sysop_to_mount_volume(dcr)) { + goto get_out; /* error return */ + } + try_autochanger = true; /* permit using autochanger again */ + continue; /* try reading again */ } /* end switch */ break; } /* end for loop */ if (!vol_ok) { Jmsg1(jcr, M_FATAL, 0, _("Too many errors trying to mount device %s.\n"), - dev->print_name()); + dev->print_name()); goto get_out; } @@ -297,7 +297,7 @@ get_out: * If this is the first one, we read the label. * * Returns: NULL if failed for any reason - * dcr if successful. + * dcr if successful. * Note, normally reserve_device_for_append() is called * before this routine. */ @@ -346,42 +346,42 @@ DCR *acquire_device_for_append(DCR *dcr) */ bstrncpy(dcr->VolumeName, dev->VolHdr.VolumeName, sizeof(dcr->VolumeName)); if (!dir_get_volume_info(dcr, GET_VOL_INFO_FOR_WRITE) && - !(dir_find_next_appendable_volume(dcr) && - strcmp(dev->VolHdr.VolumeName, dcr->VolumeName) == 0)) { /* wrong tape mounted */ + !(dir_find_next_appendable_volume(dcr) && + strcmp(dev->VolHdr.VolumeName, dcr->VolumeName) == 0)) { /* wrong tape mounted */ Dmsg2(190, "Wrong tape mounted: %s. wants:%s\n", dev->VolHdr.VolumeName, - dcr->VolumeName); - /* Release volume reserved by dir_find_next_appendable_volume() */ - if (dcr->VolumeName[0]) { - free_unused_volume(dcr); - } - if (dev->num_writers != 0 || dev->reserved_device) { + dcr->VolumeName); + /* Release volume reserved by dir_find_next_appendable_volume() */ + if (dcr->VolumeName[0]) { + free_unused_volume(dcr); + } + if (dev->num_writers != 0) { Jmsg3(jcr, M_FATAL, 0, _("Wanted Volume \"%s\", but device %s is busy writing on \"%s\" .\n"), - dcr->VolumeName, dev->print_name(), dev->VolHdr.VolumeName); + dcr->VolumeName, dev->print_name(), dev->VolHdr.VolumeName); Dmsg3(200, "Wanted Volume \"%s\", but device %s is busy writing on \"%s\" .\n", - dcr->VolumeName, dev->print_name(), dev->VolHdr.VolumeName); - goto get_out; - } - /* Wrong tape mounted, release it, then fall through to get correct one */ + dcr->VolumeName, dev->print_name(), dev->VolHdr.VolumeName); + goto get_out; + } + /* Wrong tape mounted, release it, then fall through to get correct one */ Dmsg0(190, "Wrong tape mounted, release and try mount.\n"); - release = true; - do_mount = true; + release = true; + do_mount = true; } else { - /* - * At this point, the correct tape is already mounted, so - * we do not need to do mount_next_write_volume(), unless - * we need to recycle the tape. - */ + /* + * At this point, the correct tape is already mounted, so + * we do not need to do mount_next_write_volume(), unless + * we need to recycle the tape. + */ recycle = strcmp(dcr->VolCatInfo.VolCatStatus, "Recycle") == 0; Dmsg1(190, "Correct tape mounted. recycle=%d\n", recycle); - if (recycle && dev->num_writers != 0) { + if (recycle && dev->num_writers != 0) { Jmsg(jcr, M_FATAL, 0, _("Cannot recycle volume \"%s\"" " on device %s because it is in use by another job.\n"), - dev->VolHdr.VolumeName, dev->print_name()); - goto get_out; - } - if (dev->num_writers == 0) { - memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo)); - } + dev->VolHdr.VolumeName, dev->print_name()); + goto get_out; + } + if (dev->num_writers == 0) { + memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo)); + } } } else { /* Not already in append mode, so mount the device */ @@ -394,18 +394,18 @@ DCR *acquire_device_for_append(DCR *dcr) Dmsg0(190, "Do mount_next_write_vol\n"); bool mounted = mount_next_write_volume(dcr, release); if (!mounted) { - if (!job_canceled(jcr)) { + if (!job_canceled(jcr)) { /* Reduce "noise" -- don't print if job canceled */ Jmsg(jcr, M_FATAL, 0, _("Could not ready device %s for append.\n"), - dev->print_name()); + dev->print_name()); Dmsg1(200, "Could not ready device %s for append.\n", - dev->print_name()); - } - goto get_out; + dev->print_name()); + } + goto get_out; } } - dev->num_writers++; /* we are now a writer */ + dev->num_writers++; /* we are now a writer */ if (jcr->NumVolumes == 0) { jcr->NumVolumes = 1; } @@ -445,7 +445,7 @@ bool release_device(DCR *dcr) } if (dev->can_read()) { - dev->clear_read(); /* clear read bit */ + dev->clear_read(); /* clear read bit */ /******FIXME**** send read volume usage statistics to director */ @@ -460,26 +460,26 @@ bool release_device(DCR *dcr) Dmsg1(100, "There are %d writers in release_device\n", dev->num_writers); if (dev->is_labeled()) { Dmsg0(100, "dir_create_jobmedia_record. Release\n"); - if (!dev->at_weot() && !dir_create_jobmedia_record(dcr)) { + if (!dev->at_weot() && !dir_create_jobmedia_record(dcr)) { Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"), - dcr->VolCatInfo.VolCatName, jcr->Job); - } - /* If no more writers, write an EOF */ - if (!dev->num_writers && dev->can_write()) { - weof_dev(dev, 1); - write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName); - } - if (!dev->at_weot()) { - dev->VolCatInfo.VolCatFiles = dev->file; /* set number of files */ - dev->VolCatInfo.VolCatJobs++; /* increment number of jobs */ - /* Note! do volume update before close, which zaps VolCatInfo */ + dcr->VolCatInfo.VolCatName, jcr->Job); + } + /* If no more writers, write an EOF */ + if (!dev->num_writers && dev->can_write()) { + weof_dev(dev, 1); + write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName); + } + if (!dev->at_weot()) { + dev->VolCatInfo.VolCatFiles = dev->file; /* set number of files */ + dev->VolCatInfo.VolCatJobs++; /* increment number of jobs */ + /* Note! do volume update before close, which zaps VolCatInfo */ Dmsg0(100, "dir_update_vol_info. Release0\n"); - dir_update_volume_info(dcr, false); /* send Volume info to Director */ - } + dir_update_volume_info(dcr, false); /* send Volume info to Director */ + } } } else { - /* + /* * If we reach here, it is most likely because the job * has failed, since the device is not in read mode and * there are no writers. It was probably reserved. @@ -502,17 +502,17 @@ bool release_device(DCR *dcr) alert = edit_device_codes(dcr, alert, dcr->device->alert_command, ""); bpipe = open_bpipe(alert, 0, "r"); if (bpipe) { - while (fgets(line, sizeof(line), bpipe->rfd)) { + while (fgets(line, sizeof(line), bpipe->rfd)) { Jmsg(jcr, M_ALERT, 0, _("Alert: %s"), line); - } - status = close_bpipe(bpipe); + } + status = close_bpipe(bpipe); } else { - status = errno; + status = errno; } if (status != 0) { - berrno be; + berrno be; Jmsg(jcr, M_ALERT, 0, _("3997 Bad alert command: %s: ERR=%s.\n"), - alert, be.strerror(status)); + alert, be.strerror(status)); } Dmsg1(400, "alert status=%d\n", status); diff --git a/bacula/src/stored/job.c b/bacula/src/stored/job.c index 2ea2d341c0..9eb1d6780c 100644 --- a/bacula/src/stored/job.c +++ b/bacula/src/stored/job.c @@ -67,7 +67,7 @@ bool job_cmd(JCR *jcr) /* * Get JobId and permissions from Director */ - Dmsg1(100, "msg); + Dmsg1(100, "msg); if (sscanf(dir->msg, jobcmd, &JobId, job.c_str(), job_name.c_str(), client_name.c_str(), &JobType, &level, fileset_name.c_str(), &no_attributes, @@ -75,7 +75,7 @@ bool job_cmd(JCR *jcr) &write_part_after_job, &PreferMountedVols) != 13) { pm_strcpy(jcr->errmsg, dir->msg); bnet_fsend(dir, BAD_job, jcr->errmsg); - Dmsg1(100, ">dird: %s\n", dir->msg); + Dmsg1(100, ">dird: %s", dir->msg); Emsg1(M_FATAL, 0, _("Bad Job Command from Director: %s\n"), jcr->errmsg); set_jcr_job_status(jcr, JS_ErrorTerminated); return false; diff --git a/bacula/src/stored/reserve.c b/bacula/src/stored/reserve.c index 3139a43a7e..79a59044bf 100644 --- a/bacula/src/stored/reserve.c +++ b/bacula/src/stored/reserve.c @@ -675,7 +675,6 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx) Dmsg1(190, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk"); if (can_reserve_drive(dcr, rctx) != 1) { - Mmsg1(jcr->errmsg, _("Device %s is busy writing on another Volume.\n"), dev->print_name()); Dmsg1(100, "%s", jcr->errmsg); goto bail_out; } @@ -702,6 +701,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) /* Check for prefer mounted volumes */ if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) { + Mmsg0(jcr->errmsg, _("Want mounted Volume, drive is empty\n")); Dmsg0(200, "want mounted -- no vol\n"); return 0; /* No volume mounted */ } @@ -709,6 +709,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) /* Check for exact Volume name match */ if (rctx.exact_match && rctx.have_volume && strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) != 0) { + Mmsg2(jcr->errmsg, _("Not exact match have=%s want=%s\n"), + dev->VolHdr.VolumeName, rctx.VolumeName); Dmsg2(200, "Not exact match have=%s want=%s\n", dev->VolHdr.VolumeName, rctx.VolumeName); return 0; @@ -737,6 +739,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) return 1; } else { /* Drive not suitable for us */ + Mmsg2(jcr->errmsg, _("Drive busy wrong pool: num_writers=0, reserved, pool=%s wanted=%s\n"), + dev->pool_name, dcr->pool_name); Dmsg2(200, "busy: num_writers=0, reserved, pool=%s wanted=%s\n", dev->pool_name, dcr->pool_name); return 0; /* wait */ @@ -774,7 +778,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) return 1; } else { /* Drive not suitable for us */ - Jmsg(jcr, M_WARNING, 0, _("Wanted Pool \"%s\", but device %s is using Pool \"%s\" .\n"), + Mmsg(jcr->errmsg, _("Wanted Pool \"%s\", but device %s is using Pool \"%s\" .\n"), dcr->pool_name, dev->print_name(), dev->pool_name); Dmsg2(200, "busy: num_writers>0, can_append, pool=%s wanted=%s\n", dev->pool_name, dcr->pool_name); diff --git a/bacula/src/version.h b/bacula/src/version.h index bc3b63fc6d..ec394dc757 100644 --- a/bacula/src/version.h +++ b/bacula/src/version.h @@ -3,9 +3,9 @@ */ #undef VERSION -#define VERSION "1.37.36" -#define BDATE "20 August 2005" -#define LSMDATE "20Aug05" +#define VERSION "1.37.37" +#define BDATE "23 August 2005" +#define LSMDATE "23Aug05" /* Debug flags */ #undef DEBUG