From d7522c18b809a8047d01d03b2b0009510911fa79 Mon Sep 17 00:00:00 2001 From: Kern Sibbald Date: Mon, 11 Jun 2007 10:49:48 +0000 Subject: [PATCH] 10Jun08 kes Move find_next_appendable_volume() to after acquiring a valid device in reserve.c. This fixes bug #864 -- confirmed by reporter. 09Jun07 kes Unable to reproduce bug 872. However added additional testing for integer. kes Bug #874 resolved by documenting SQLite limitations. kes Bug #882 resolved by documenting mtx-changer script for new drive code. kes Bug #881 resolved by removing typo in mtx-changer script. kes Made Frank Sweetser's wiki the official Bacula wiki with his approval. Added a link to the wiki on the web page, and implemented a backup from http://paramount.ind.wpi.edu 08Jun07 kes Fix update allfrompool to pass pool name git-svn-id: https://bacula.svn.sourceforge.net/svnroot/bacula/trunk@5006 91ce42f0-d328-0410-95d8-f526ca767f89 --- bacula/ChangeLog | 30 +++++ bacula/ReleaseNotes | 10 +- bacula/src/stored/reserve.c | 211 ++++++++++++++++++------------------ bacula/src/version.h | 6 +- bacula/technotes-2.1 | 5 +- 5 files changed, 153 insertions(+), 109 deletions(-) diff --git a/bacula/ChangeLog b/bacula/ChangeLog index b729e29b7a..0d50c90d98 100644 --- a/bacula/ChangeLog +++ b/bacula/ChangeLog @@ -1,6 +1,36 @@ Technical notes on version 2.1 General: +10Jun08 +kes Move find_next_appendable_volume() to after acquiring a valid device + in reserve.c. This fixes bug #864 -- confirmed by reporter. +09Jun07 +kes Unable to reproduce bug 872. However added additional testing for + integer. +kes Bug #874 resolved by documenting SQLite limitations. +kes Bug #882 resolved by documenting mtx-changer script for new drive code. +kes Bug #881 resolved by removing typo in mtx-changer script. +kes Made Frank Sweetser's wiki the official Bacula wiki with his + approval. Added a link to the wiki on the web page, and implemented + a backup from http://paramount.ind.wpi.edu +08Jun07 +kes Fix update allfrompool to pass pool name. +07Jun07 +kes Convert to pure GPL v2 license. +kes Fix sscanf problems reported by Peter Buschman that caused + a bus error on Solaris. +kes Rework (simplify) the select prompt in bat. +kes Move get_jobid_from_tid() into lib and create a + get_jcr_from_tid(). +kes Use get_jcr_from_tid() to conver all tls Emsg() to Jmsg(). This + should definitely fix the problem of lost error messages in the + encryption code. +kes Remove over zellous addition of FSFE copyright in a few eggxxx files. +kes Eliminate tcpd.h from the project. Enclose the #include from the + library with extern C ... +kes Add print of signal name when a signal is trapped. + +Release: 2.1.12 beta 04Jun07 kes Fix a seg fault in the PostgreSQL driver dereferencing a NULL pointer. 03Jun07 diff --git a/bacula/ReleaseNotes b/bacula/ReleaseNotes index 6430ee50f1..3b7656ca92 100644 --- a/bacula/ReleaseNotes +++ b/bacula/ReleaseNotes @@ -1,5 +1,5 @@ - Release Notes for Bacula 2.1.12 + Release Notes for Bacula 2.1.14 Bacula code: Total files = 458 Total lines = 170,197 (*.h *.c *.in) @@ -9,6 +9,14 @@ use some of the new features that affect the FD. In other words, you should not have to upgrade all your File daemons. However, bat works only with a 2.1.8 Director or greater. +Changes since Beta release 2.1.12 +- Fixed bugs #864, 872, 874, 882, 882 +- License is now GPL v2 without modifications, fix a few copyright + mistakes made when adding FSFE copyright notice. +- Fix update all from pool to pass pool name. +- Correct reservation system bug that invalidated Volumes by + calling find_next_appendable volume before acquiring a device. + Changes since Beta release 2.1.10 - Lots of new bat functionality !!!!!! - Additional drive reservation algorithm that should solve a lot of diff --git a/bacula/src/stored/reserve.c b/bacula/src/stored/reserve.c index cec631d9b2..429f20cf62 100644 --- a/bacula/src/stored/reserve.c +++ b/bacula/src/stored/reserve.c @@ -39,6 +39,8 @@ #include "bacula.h" #include "stored.h" +#define jid() ((int)get_jobid_from_tid()) + const int dbglvl = 50; static dlist *vol_list = NULL; @@ -175,7 +177,7 @@ static void debug_list_volumes(const char *imsg) } else { Mmsg(msg, "List from %s: %s at %p no dev\n", imsg, vol->vol_name, vol->vol_name); } - Dmsg1(dbglvl, "%s", msg.c_str()); + Dmsg2(dbglvl, "jid=%u %s", jid(), msg.c_str()); } #ifdef xxx @@ -227,7 +229,7 @@ static VOLRES *new_vol_item(DCR *dcr, const char *VolumeName) memset(vol, 0, sizeof(VOLRES)); vol->vol_name = bstrdup(VolumeName); vol->dev = dcr->dev; - Dmsg4(dbglvl, "JobId=%u new Vol=%s at %p dev=%s\n", (int)dcr->jcr->JobId, + Dmsg4(dbglvl, "jid=%u new Vol=%s at %p dev=%s\n", (int)dcr->jcr->JobId, VolumeName, vol->vol_name, vol->dev->print_name()); return vol; } @@ -303,7 +305,7 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) ASSERT(dev != NULL); - Dmsg1(dbglvl, "reserve_volume %s\n", VolumeName); + Dmsg2(dbglvl, "jid=%u reserve_volume %s\n", jid(), VolumeName); /* * We lock the reservations system here to ensure * when adding a new volume that no newly scheduled @@ -324,8 +326,8 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) if (strcmp(vol->vol_name, VolumeName) == 0) { goto get_out; /* Volume already on this device */ } else { - Dmsg3(dbglvl, "reserve_vol free vol=%s at %p JobId=%u\n", vol->vol_name, - vol->vol_name, (int)dcr->jcr->JobId); + 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"); vol_list->remove(vol); free_vol_item(vol); @@ -340,14 +342,14 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) */ vol = (VOLRES *)vol_list->binary_insert(nvol, my_compare); if (vol != nvol) { - Dmsg2(dbglvl, "Found vol=%s dev-same=%d\n", vol->vol_name, dev==vol->dev); + Dmsg3(dbglvl, "jid=%u Found vol=%s dev-same=%d\n", jid(), vol->vol_name, dev==vol->dev); /* * At this point, a Volume with this name already is in the list, * so we simply release our new Volume entry. Note, this should * only happen if we are moving the volume from one drive to another. */ - Dmsg3(dbglvl, "reserve_vol free-tmp vol=%s at %p JobId=%u\n", vol->vol_name, - vol->vol_name, (int)dcr->jcr->JobId); + Dmsg3(dbglvl, "jid=%u reserve_vol free-tmp vol=%s at %p\n", + (int)dcr->jcr->JobId, vol->vol_name, vol->vol_name); /* * Clear dev pointer so that free_vol_item() doesn't * take away our volume. @@ -360,7 +362,7 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) /* Caller wants to switch Volume to another device */ if (!vol->dev->is_busy()) { /* OK to move it -- I'm not sure this will work */ - Dmsg3(dbglvl, "==== Swap vol=%s from dev=%s to %s\n", VolumeName, + Dmsg4(dbglvl, "==== jid=%u Swap vol=%s from dev=%s to %s\n", jid(), VolumeName, vol->dev->print_name(), dev->print_name()); vol->dev->vol = NULL; /* take vol from old drive */ vol->dev->VolHdr.VolumeName[0] = 0; @@ -368,8 +370,8 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) dev->vol = vol; /* point dev at vol */ dev->VolHdr.VolumeName[0] = 0; } else { - Dmsg3(dbglvl, "Volume busy could not swap vol=%s from dev=%s to %s\n", VolumeName, - vol->dev->print_name(), dev->print_name()); + Dmsg4(dbglvl, "jid=%u Volume busy could not swap vol=%s from dev=%s to %s\n", + jid(), VolumeName, vol->dev->print_name(), dev->print_name()); vol = NULL; /* device busy */ } } @@ -396,7 +398,7 @@ VOLRES *find_volume(DCR *dcr) vol.vol_name = bstrdup(dcr->VolumeName); fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare); free(vol.vol_name); - Dmsg2(dbglvl, "find_vol=%s found=%d\n", dcr->VolumeName, fvol!=NULL); + Dmsg3(dbglvl, "jid=%u find_vol=%s found=%d\n", jid(), dcr->VolumeName, fvol!=NULL); debug_list_volumes("find_volume"); unlock_volumes(); return fvol; @@ -413,7 +415,7 @@ void unreserve_device(DCR *dcr) if (dcr->reserved_device) { dcr->reserved_device = false; dev->reserved_device--; - Dmsg2(dbglvl, "Dec reserve=%d dev=%s\n", dev->reserved_device, dev->print_name()); + Dmsg3(dbglvl, "jid=%u Dec reserve=%d dev=%s\n", jid(), dev->reserved_device, dev->print_name()); dcr->reserved_device = false; /* If we set read mode in reserving, remove it */ if (dev->can_read()) { @@ -440,13 +442,13 @@ bool volume_unused(DCR *dcr) DEVICE *dev = dcr->dev; if (dev->vol == NULL) { - Dmsg2(dbglvl, "JobId=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name()); + Dmsg2(dbglvl, "jid=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name()); debug_list_volumes("null vol cannot unreserve_volume"); return false; } if (dev->is_busy()) { - Dmsg2(dbglvl, "JobId=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name()); + Dmsg2(dbglvl, "jid=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name()); debug_list_volumes("dev busy cannot unreserve_volume"); return false; } @@ -462,14 +464,14 @@ bool free_volume(DEVICE *dev) VOLRES *vol; if (dev->vol == NULL) { - Dmsg1(dbglvl, "No vol on dev %s\n", dev->print_name()); + Dmsg2(dbglvl, "jid=%u No vol on dev %s\n", jid(), dev->print_name()); return false; } lock_volumes(); vol = dev->vol; dev->vol = NULL; vol_list->remove(vol); - Dmsg2(dbglvl, "free_volume %s dev=%s\n", vol->vol_name, dev->print_name()); + Dmsg3(dbglvl, "jid=%u free_volume %s dev=%s\n", jid(), vol->vol_name, dev->print_name()); free_vol_item(vol); debug_list_volumes("free_volume"); unlock_volumes(); @@ -495,7 +497,7 @@ void free_volume_list() } lock_volumes(); foreach_dlist(vol, vol_list) { - Dmsg2(dbglvl, "Unreleased Volume=%s dev=%p\n", vol->vol_name, vol->dev); + Dmsg3(dbglvl, "jid=%u Unreleased Volume=%s dev=%p\n", jid(), vol->vol_name, vol->dev); free(vol->vol_name); vol->vol_name = NULL; } @@ -508,25 +510,25 @@ bool is_volume_in_use(DCR *dcr) { VOLRES *vol = find_volume(dcr); if (!vol) { - Dmsg1(dbglvl, "Vol=%s not in use.\n", dcr->VolumeName); + Dmsg2(dbglvl, "jid=%u Vol=%s not in use.\n", jid(), dcr->VolumeName); return false; /* vol not in list */ } ASSERT(vol->dev != NULL); if (dcr->dev == vol->dev) { /* same device OK */ - Dmsg1(dbglvl, "Vol=%s on same dev.\n", dcr->VolumeName); + Dmsg2(dbglvl, "jid=%u Vol=%s on same dev.\n", jid(), dcr->VolumeName); return false; } else { - Dmsg3(dbglvl, "Vol=%s on %s we have %s\n", dcr->VolumeName, + Dmsg4(dbglvl, "jid=%u Vol=%s on %s we have %s\n", jid(), dcr->VolumeName, vol->dev->print_name(), dcr->dev->print_name()); } if (!vol->dev->is_busy()) { - Dmsg2(dbglvl, "Vol=%s dev=%s not busy.\n", dcr->VolumeName, vol->dev->print_name()); + Dmsg3(dbglvl, "jid=%u Vol=%s dev=%s not busy.\n", jid(), dcr->VolumeName, vol->dev->print_name()); return false; } else { - Dmsg2(dbglvl, "Vol=%s dev=%s busy.\n", dcr->VolumeName, vol->dev->print_name()); + Dmsg3(dbglvl, "jid=%u Vol=%s dev=%s busy.\n", jid(), dcr->VolumeName, vol->dev->print_name()); } - Dmsg2(dbglvl, "Vol=%s in use by %s.\n", dcr->VolumeName, vol->dev->print_name()); + Dmsg3(dbglvl, "jid=%u Vol=%s in use by %s.\n", jid(), dcr->VolumeName, vol->dev->print_name()); return true; } @@ -564,7 +566,7 @@ static bool use_storage_cmd(JCR *jcr) dirstore = New(alist(10, not_owned_by_alist)); msgs = jcr->reserve_msgs = New(alist(10, not_owned_by_alist)); do { - Dmsg1(dbglvl, "msg); + Dmsg2(dbglvl, "jid=%u msg); ok = sscanf(dir->msg, use_storage, store_name.c_str(), media_type.c_str(), pool_name.c_str(), pool_type.c_str(), &append, &Copy, &Stripe) == 7; @@ -593,7 +595,7 @@ static bool use_storage_cmd(JCR *jcr) /* Now get all devices */ while (dir->recv() >= 0) { - Dmsg1(dbglvl, "msg); + Dmsg2(dbglvl, "jid=%u msg); ok = sscanf(dir->msg, use_device, dev_name.c_str()) == 1; if (!ok) { break; @@ -607,12 +609,12 @@ static bool use_storage_cmd(JCR *jcr) char *device_name; if (debug_level >= dbglvl) { foreach_alist(store, dirstore) { - Dmsg6(dbglvl, "JobId=%u Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n", + Dmsg6(dbglvl, "jid=%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) { - Dmsg1(dbglvl, " Device=%s\n", device_name); + Dmsg2(dbglvl, "jid=%u Device=%s\n", jid(), device_name); } } } @@ -648,7 +650,7 @@ static bool use_storage_cmd(JCR *jcr) rctx.PreferMountedVols = false; rctx.exact_match = false; rctx.autochanger_only = true; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -664,7 +666,7 @@ static bool use_storage_cmd(JCR *jcr) rctx.try_low_use_drive = false; } rctx.autochanger_only = false; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -676,7 +678,7 @@ static bool use_storage_cmd(JCR *jcr) rctx.PreferMountedVols = true; rctx.exact_match = true; rctx.autochanger_only = false; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -685,7 +687,7 @@ static bool use_storage_cmd(JCR *jcr) } /* Look for any mounted drive */ rctx.exact_match = false; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -694,7 +696,7 @@ static bool use_storage_cmd(JCR *jcr) } /* Try any drive */ rctx.any_drive = true; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -712,9 +714,9 @@ static bool use_storage_cmd(JCR *jcr) */ if (repeat++ > 1) { /* try algorithm 3 times */ bmicrosleep(30, 0); /* wait a bit */ - Dmsg1(dbglvl, "JobId=%u repeat reserve algorithm\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u repeat reserve algorithm\n", (int)rctx.jcr->JobId); } else if (!rctx.suitable_device || !wait_for_device(jcr, wait_for_device_retries)) { - Dmsg1(dbglvl, "JobId=%u Fail. !suitable_device || !wait_for_device\n", + Dmsg1(dbglvl, "jid=%u Fail. !suitable_device || !wait_for_device\n", (int)rctx.jcr->JobId); fail = true; } @@ -736,14 +738,14 @@ static bool use_storage_cmd(JCR *jcr) dev_name.c_str(), media_type.c_str()); dir->fsend(NO_device, dev_name.c_str()); - Dmsg1(dbglvl, ">dird: %s", dir->msg); + Dmsg2(dbglvl, "jid=%u >dird: %s", jid(), dir->msg); } } else { unbash_spaces(dir->msg); pm_strcpy(jcr->errmsg, dir->msg); Jmsg(jcr, M_FATAL, 0, _("Failed command: %s\n"), jcr->errmsg); dir->fsend(BAD_use, jcr->errmsg); - Dmsg1(dbglvl, ">dird: %s", dir->msg); + Dmsg2(dbglvl, "jid=%u >dird: %s", jid(), dir->msg); } release_msgs(jcr); @@ -782,7 +784,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) } else { dirstore = jcr->read_store; } - Dmsg5(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d\n", + Dmsg5(dbglvl, "jid=%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); @@ -801,7 +803,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) * we can take note and act accordingly (probably redo the * search at least a few times). */ - Dmsg1(dbglvl, "JobId=%u duplicate vol list\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u duplicate vol list\n", (int)rctx.jcr->JobId); temp_vol_list = New(dlist(vol, &vol->link)); foreach_dlist(vol, vol_list) { VOLRES *nvol; @@ -836,20 +838,20 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) bstrncpy(rctx.VolumeName, vol->vol_name, sizeof(rctx.VolumeName)); rctx.have_volume = true; /* Try reserving this device and volume */ - Dmsg3(dbglvl, "JobId=%u try vol=%s on device=%s\n", (int)rctx.jcr->JobId, + Dmsg3(dbglvl, "jid=%u try vol=%s on device=%s\n", (int)rctx.jcr->JobId, rctx.VolumeName, device_name); stat = reserve_device(rctx); if (stat == 1) { /* found available device */ - Dmsg2(dbglvl, "JobId=%u Suitable device found=%s\n", (int)rctx.jcr->JobId, + Dmsg2(dbglvl, "jid=%u Suitable device found=%s\n", (int)rctx.jcr->JobId, device_name); ok = true; break; } else if (stat == 0) { /* device busy */ - Dmsg2(dbglvl, "JobId=%u Suitable device=%s, busy: not use\n", + Dmsg2(dbglvl, "jid=%u Suitable device=%s, busy: not use\n", (int)rctx.jcr->JobId, device_name); } else { /* otherwise error */ - Dmsg1(dbglvl, "JobId=%u No suitable device found.\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u No suitable device found.\n", (int)rctx.jcr->JobId); } rctx.have_volume = false; } @@ -863,11 +865,11 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) vol_list = temp_vol_list; free_volume_list(); /* release temp_vol_list */ vol_list = save_vol_list; - Dmsg1(dbglvl, "JobId=%u deleted temp vol list\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u deleted temp vol list\n", (int)rctx.jcr->JobId); unlock_volumes(); } if (ok) { - Dmsg2(dbglvl, "JobId=%u got vol %s in reserved volums list\n", (int)rctx.jcr->JobId, + Dmsg2(dbglvl, "jid=%u got vol %s in reserved volums list\n", (int)rctx.jcr->JobId, rctx.VolumeName); return true; } @@ -885,16 +887,16 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) rctx.device_name = device_name; stat = search_res_for_device(rctx); if (stat == 1) { /* found available device */ - Dmsg2(dbglvl, "JobId=%u available device found=%s\n", (int)rctx.jcr->JobId, + Dmsg2(dbglvl, "jid=%u available device found=%s\n", (int)rctx.jcr->JobId, device_name); ok = true; break; } else if (stat == 0) { /* device busy */ - Dmsg2(dbglvl, "JobId=%u Suitable device=%s, busy: not use\n", + Dmsg2(dbglvl, "jid=%u Suitable device=%s, busy: not use\n", (int)rctx.jcr->JobId, device_name); } else { /* otherwise error */ - Dmsg1(dbglvl, "JobId=%u No suitable device found.\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u No suitable device found.\n", (int)rctx.jcr->JobId); } } if (ok) { @@ -913,15 +915,15 @@ int search_res_for_device(RCTX &rctx) AUTOCHANGER *changer; int stat; - Dmsg2(dbglvl, "JobId=%u search res for %s\n", (int)rctx.jcr->JobId, rctx.device_name); + Dmsg2(dbglvl, "jid=%u search res for %s\n", (int)rctx.jcr->JobId, rctx.device_name); /* Look through Autochangers first */ foreach_res(changer, R_AUTOCHANGER) { - Dmsg2(150, "JobId=%u Try match changer res=%s\n", (int)rctx.jcr->JobId, changer->hdr.name); + Dmsg2(dbglvl, "jid=%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) { - Dmsg2(dbglvl, "JobId=%u Try changer device %s\n", (int)rctx.jcr->JobId, + Dmsg2(dbglvl, "jid=%u Try changer device %s\n", (int)rctx.jcr->JobId, rctx.device->hdr.name); stat = reserve_device(rctx); if (stat != 1) { /* try another device */ @@ -929,11 +931,11 @@ int search_res_for_device(RCTX &rctx) } /* Debug code */ if (rctx.store->append == SD_APPEND) { - Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for append.\n", + Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for append.\n", (int)rctx.jcr->JobId, rctx.device->hdr.name, rctx.jcr->dcr->dev->reserved_device); } else { - Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for read.\n", + Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for read.\n", (int)rctx.jcr->JobId, rctx.device->hdr.name, rctx.jcr->read_dcr->dev->reserved_device); } @@ -945,7 +947,7 @@ int search_res_for_device(RCTX &rctx) /* Now if requested look through regular devices */ if (!rctx.autochanger_only) { foreach_res(rctx.device, R_DEVICE) { - Dmsg2(150, "JobId=%u Try match res=%s\n", (int)rctx.jcr->JobId, rctx.device->hdr.name); + Dmsg2(dbglvl, "jid=%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); @@ -954,11 +956,11 @@ int search_res_for_device(RCTX &rctx) } /* Debug code */ if (rctx.store->append == SD_APPEND) { - Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for append.\n", + Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for append.\n", (int)rctx.jcr->JobId, rctx.device->hdr.name, rctx.jcr->dcr->dev->reserved_device); } else { - Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for read.\n", + Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for read.\n", (int)rctx.jcr->JobId, rctx.device->hdr.name, rctx.jcr->read_dcr->dev->reserved_device); } @@ -983,7 +985,7 @@ static int reserve_device(RCTX &rctx) const int name_len = MAX_NAME_LENGTH; /* Make sure MediaType is OK */ - Dmsg3(dbglvl, "JobId=%u chk MediaType device=%s request=%s\n", + Dmsg3(dbglvl, "jid=%u chk 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) { @@ -1008,7 +1010,7 @@ static int reserve_device(RCTX &rctx) } rctx.suitable_device = true; - Dmsg2(dbglvl, "JobId=%u try reserve %s\n", rctx.jcr->JobId, rctx.device->hdr.name); + Dmsg2(dbglvl, "jid=%u try reserve %s\n", rctx.jcr->JobId, rctx.device->hdr.name); dcr = new_dcr(rctx.jcr, rctx.device->dev); if (!dcr) { BSOCK *dir = rctx.jcr->dir_bsock; @@ -1021,16 +1023,26 @@ static int reserve_device(RCTX &rctx) 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) { - Dmsg3(dbglvl, "JobId=%u have_vol=%d vol=%s\n", (int)rctx.jcr->JobId, + Dmsg3(dbglvl, "jid=%u have_vol=%d vol=%s\n", (int)rctx.jcr->JobId, rctx.have_volume, rctx.VolumeName); + ok = reserve_device_for_append(dcr, rctx); + if (!ok) { + goto bail_out; + } + + rctx.jcr->dcr = dcr; + Dmsg6(dbglvl, "jid=%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); if (!rctx.have_volume) { dcr->any_volume = true; if (dir_find_next_appendable_volume(dcr)) { bstrncpy(rctx.VolumeName, dcr->VolumeName, sizeof(rctx.VolumeName)); - Dmsg2(dbglvl, "JobId=%u looking for Volume=%s\n", (int)rctx.jcr->JobId, rctx.VolumeName); + Dmsg2(dbglvl, "jid=%u looking for Volume=%s\n", (int)rctx.jcr->JobId, rctx.VolumeName); rctx.have_volume = true; } else { - Dmsg1(dbglvl, "JobId=%u No next volume found\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u No next volume found\n", (int)rctx.jcr->JobId); rctx.have_volume = false; rctx.VolumeName[0] = 0; /* @@ -1046,19 +1058,11 @@ static int reserve_device(RCTX &rctx) } } } - ok = reserve_device_for_append(dcr, rctx); - if (ok) { - rctx.jcr->dcr = dcr; - Dmsg6(dbglvl, "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); - } } else { ok = reserve_device_for_read(dcr); if (ok) { rctx.jcr->read_dcr = dcr; - Dmsg6(dbglvl, "JobId=%u Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -1073,7 +1077,7 @@ static int reserve_device(RCTX &rctx) 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 */ - Dmsg1(dbglvl, ">dird changer: %s", dir->msg); + Dmsg2(dbglvl, "jid=%u >dird changer: %s", jid(), dir->msg); } else { ok = true; } @@ -1082,7 +1086,7 @@ static int reserve_device(RCTX &rctx) bail_out: rctx.have_volume = false; free_dcr(dcr); - Dmsg1(dbglvl, "JobId=%u Not OK.\n", (int)rctx.jcr->JobId); + Dmsg1(dbglvl, "jid=%u Not OK.\n", (int)rctx.jcr->JobId); return 0; } @@ -1103,7 +1107,7 @@ static bool reserve_device_for_read(DCR *dcr) dev->dlock(); if (is_device_unmounted(dev)) { - Dmsg2(dbglvl, "JobId=%u Device %s is BLOCKED due to user unmount.\n", + Dmsg2(dbglvl, "jid=%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()); @@ -1112,7 +1116,7 @@ static bool reserve_device_for_read(DCR *dcr) } if (dev->is_busy()) { - Dmsg5(dbglvl, "JobId=%u Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", + Dmsg5(dbglvl, "jid=%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"), @@ -1125,7 +1129,7 @@ static bool reserve_device_for_read(DCR *dcr) dev->set_read(); ok = true; dev->reserved_device++; - Dmsg4(dbglvl, "JobId=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, + Dmsg4(dbglvl, "jid=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, dev->reserved_device, dev->print_name(), dev); dcr->reserved_device = true; @@ -1164,7 +1168,7 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx) if (dev->can_read()) { Mmsg(jcr->errmsg, _("3603 JobId=%u device %s is busy reading.\n"), jcr->JobId, dev->print_name()); - Dmsg1(dbglvl, "%s", jcr->errmsg); + Dmsg2(dbglvl, "jid=%u %s", jid(), jcr->errmsg); queue_reserve_message(jcr); goto bail_out; } @@ -1173,22 +1177,22 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx) if (is_device_unmounted(dev)) { Mmsg(jcr->errmsg, _("3604 JobId=%u device %s is BLOCKED due to user unmount.\n"), jcr->JobId, dev->print_name()); - Dmsg1(dbglvl, "%s", jcr->errmsg); + Dmsg2(dbglvl, "jid=%u %s", jid(), jcr->errmsg); queue_reserve_message(jcr); goto bail_out; } - Dmsg2(dbglvl, "JobId=%u reserve_append device is %s\n", + Dmsg2(dbglvl, "jid=%u reserve_append device is %s\n", (int)jcr->JobId, dev->print_name()); /* Now do detailed tests ... */ if (can_reserve_drive(dcr, rctx) != 1) { - Dmsg1(dbglvl, "JobId=%u can_reserve_drive!=1\n", (int)jcr->JobId); + Dmsg1(dbglvl, "jid=%u can_reserve_drive!=1\n", (int)jcr->JobId); goto bail_out; } dev->reserved_device++; - Dmsg4(dbglvl, "JobId=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, dev->reserved_device, + Dmsg4(dbglvl, "jid=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, dev->reserved_device, dev->print_name(), dev); dcr->reserved_device = true; ok = true; @@ -1208,7 +1212,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) DEVICE *dev = dcr->dev; JCR *jcr = dcr->jcr; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); @@ -1222,8 +1226,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) * helps spread the load to the least used drives. */ if (rctx.try_low_use_drive && dev == rctx.low_use_drive) { - Dmsg3(dbglvl, "OK dev=%s == low_drive=%s. JobId=%u\n", - dev->print_name(), rctx.low_use_drive->print_name(), jcr->JobId); + Dmsg3(dbglvl, "jid=%u OK dev=%s == low_drive=%s.\n", + jcr->JobId, dev->print_name(), rctx.low_use_drive->print_name()); return 1; } /* If he wants a free drive, but this one is busy, no go */ @@ -1232,13 +1236,13 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) if ((dev->num_writers + dev->reserved_device) < rctx.num_writers) { rctx.num_writers = dev->num_writers + dev->reserved_device; rctx.low_use_drive = dev; - Dmsg3(dbglvl, "JobId=%u set low use drive=%s num_writers=%d\n", + Dmsg3(dbglvl, "jid=%u set low use drive=%s num_writers=%d\n", (int)jcr->JobId, dev->print_name(), rctx.num_writers); } else { - Dmsg2(dbglvl, "JobId=%u not low use num_writers=%d\n", + Dmsg2(dbglvl, "jid=%u not low use num_writers=%d\n", (int)jcr->JobId, dev->num_writers+dev->reserved_device); } - Dmsg1(dbglvl, "failed: !prefMnt && busy. JobId=%u\n", jcr->JobId); + Dmsg1(dbglvl, "jid=%u failed: !prefMnt && busy.\n", jcr->JobId); Mmsg(jcr->errmsg, _("3605 JobId=%u wants free drive but device %s is busy.\n"), jcr->JobId, dev->print_name()); queue_reserve_message(jcr); @@ -1250,7 +1254,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) 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(dbglvl, "failed: want mounted -- no vol JobId=%u\n", (uint32_t)jcr->JobId); + Dmsg1(dbglvl, "jid=%u failed: want mounted -- no vol\n", (uint32_t)jcr->JobId); return 0; /* No volume mounted */ } @@ -1260,11 +1264,11 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) */ if (rctx.exact_match && rctx.have_volume) { bool ok; - Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg6(dbglvl, "jid=%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); - Dmsg5(dbglvl, "JobId=%u have_vol=%d have=%s resvol=%s want=%s\n", + Dmsg5(dbglvl, "jid=%u have_vol=%d have=%s resvol=%s want=%s\n", (int)jcr->JobId, rctx.have_volume, dev->VolHdr.VolumeName, dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName); ok = strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) == 0 || @@ -1274,7 +1278,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) jcr->JobId, rctx.VolumeName, dev->VolHdr.VolumeName, dev->print_name()); queue_reserve_message(jcr); - Dmsg4(dbglvl, "JobId=%u not OK: dev have=%s resvol=%s want=%s\n", + Dmsg4(dbglvl, "jid=%u not OK: dev have=%s resvol=%s want=%s\n", (int)jcr->JobId, dev->VolHdr.VolumeName, dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName); return 0; @@ -1289,8 +1293,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) if (rctx.autochanger_only && !dev->is_busy() && dev->VolHdr.VolumeName[0] == 0) { /* Device is available but not yet reserved, reserve it for us */ - Dmsg2(dbglvl, "OK Res Unused autochanger %s JobId=%u.\n", - dev->print_name(), jcr->JobId); + Dmsg2(dbglvl, "jid=%u OK Res Unused autochanger %s.\n", + jcr->JobId, dev->print_name()); bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name)); bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type)); return 1; /* reserve drive */ @@ -1306,8 +1310,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) if (strcmp(dev->pool_name, dcr->pool_name) == 0 && strcmp(dev->pool_type, dcr->pool_type) == 0) { /* OK, compatible device */ - Dmsg2(dbglvl, "OK dev: %s num_writers=0, reserved, pool matches JobId=%u\n", - dev->print_name(), jcr->JobId); + 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 */ @@ -1316,7 +1320,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) jcr->JobId, dcr->pool_name, dev->pool_name, dev->reserved_device, dev->print_name()); queue_reserve_message(jcr); - Dmsg3(dbglvl, "JobId=%u failed: busy num_writers=0, reserved, pool=%s wanted=%s\n", + 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 */ } @@ -1324,20 +1328,19 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) /* 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, "OK dev: %s num_writers=0, can_append, pool matches. JobId=%u\n", - dev->print_name(), jcr->JobId); + 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 { /* Changing pool, unload old tape if any in drive */ - Dmsg1(dbglvl, "JobId=%u OK dev: num_writers=0, not reserved, pool change, unload changer\n", + Dmsg1(dbglvl, "jid=%u OK dev: num_writers=0, not reserved, pool change, unload changer\n", (int)jcr->JobId); unload_autochanger(dcr, 0); } } /* Device is available but not yet reserved, reserve it for us */ - Dmsg2(dbglvl, "OK Dev avail reserved %s JobId=%u\n", dev->print_name(), - jcr->JobId); + Dmsg2(dbglvl, "jid=%u OK Dev avail reserved %s\n", jcr->JobId, dev->print_name()); bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name)); bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type)); return 1; /* reserve drive */ @@ -1351,8 +1354,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) /* 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, "OK dev: %s num_writers>=0, can_append, pool matches. JobId=%u\n", - dev->print_name(), jcr->JobId); + 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 { @@ -1360,7 +1363,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) 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, "JobId=%u failed: busy num_writers>0, can_append, pool=%s wanted=%s\n", + 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 */ } @@ -1375,7 +1378,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) Mmsg(jcr->errmsg, _("3911 JobId=%u failed reserve drive %s.\n"), jcr->JobId, dev->print_name()); queue_reserve_message(jcr); - Dmsg2(dbglvl, "failed: No reserve %s JobId=%u\n", dev->print_name(), jcr->JobId); + Dmsg2(dbglvl, "jid=%u failed: No reserve %s\n", jcr->JobId, dev->print_name()); return 0; } diff --git a/bacula/src/version.h b/bacula/src/version.h index ed23507a82..e737e5fee3 100644 --- a/bacula/src/version.h +++ b/bacula/src/version.h @@ -3,9 +3,9 @@ */ #undef VERSION -#define VERSION "2.1.13" -#define BDATE "08 June 2007" -#define LSMDATE "08Jun07" +#define VERSION "2.1.14" +#define BDATE "10 June 2007" +#define LSMDATE "10Jun07" #define PROG_COPYRIGHT "Copyright (C) %d-2007 Free Software Foundation Europe e.V.\n" #define BYEAR "2007" /* year for copyright messages in progs */ diff --git a/bacula/technotes-2.1 b/bacula/technotes-2.1 index 4a0d7a6473..8cf9e3ffaf 100644 --- a/bacula/technotes-2.1 +++ b/bacula/technotes-2.1 @@ -1,6 +1,9 @@ Technical notes on version 2.1 General: +10Jun08 +kes Move find_next_appendable_volume() to after acquiring a valid device + in reserve.c. This fixes bug #864 -- confirmed by reporter. 09Jun07 kes Unable to reproduce bug 872. However added additional testing for integer. @@ -569,7 +572,7 @@ ebl add update volume=xxx recyclepool=yyyy kes Fix encryption deblocking bug, which caused some restored files to be truncated. This fixes bug #763. kes Add FD event sequence order prepared by Eric -- for RunScripts. -kes Fix 12am/pm bug as reported in bug #782. +kes Fix 12am/pm bug as reported in bug #782 -- scheduler problem. 13Feb07 kes Apply Eric's ClientRunScriptAfter patch to 2.0 and 2.1. ebl Use btime_t instead of uint64_t in media patch. -- 2.39.5