X-Git-Url: https://git.sur5r.net/?a=blobdiff_plain;f=bacula%2Fsrc%2Fstored%2Freserve.c;h=a7763839bf1a6bf084c6218d80821635e9b15a35;hb=9326b2fd753cf4a714d40d5c190ba04b16261510;hp=ab1c3ea02c51ed1e9072dd2a0220363f4b3768d7;hpb=ed8d94891d0e98875d4d9df497de539fa5db2643;p=bacula%2Fbacula diff --git a/bacula/src/stored/reserve.c b/bacula/src/stored/reserve.c index ab1c3ea02c..a7763839bf 100644 --- a/bacula/src/stored/reserve.c +++ b/bacula/src/stored/reserve.c @@ -9,7 +9,7 @@ * */ /* - Copyright (C) 2000-2005 Kern Sibbald + Copyright (C) 2000-2006 Kern Sibbald This program is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License @@ -26,56 +26,16 @@ #include "bacula.h" #include "stored.h" -/* - * Use Device command from Director - * He tells is what Device Name to use, the Media Type, - * the Pool Name, and the Pool Type. - * - * Ensure that the device exists and is opened, then store - * the media and pool info in the JCR. This class is used - * only temporarily in this file. - */ -class DIRSTORE { -public: - alist *device; - bool append; - char name[MAX_NAME_LENGTH]; - char media_type[MAX_NAME_LENGTH]; - char pool_name[MAX_NAME_LENGTH]; - char pool_type[MAX_NAME_LENGTH]; -}; - -/* Reserve context */ -class RCTX { -public: - JCR *jcr; - char *device_name; - DIRSTORE *store; - DEVRES *device; - DEVICE *low_use_drive; /* Low use drive candidate */ - int num_writers; /* for selecting low use drive */ - bool try_low_use_drive; /* see if low use drive available */ - bool any_drive; /* Accept any drive if set */ - bool PreferMountedVols; /* Prefer volumes already mounted */ - bool exact_match; /* Want exact volume */ - bool have_volume; /* Have DIR suggested vol name */ - bool suitable_device; /* at least one device is suitable */ - bool autochanger_only; /* look at autochangers only */ - char VolumeName[MAX_NAME_LENGTH]; /* Vol name suggested by DIR */ -}; - static dlist *vol_list = NULL; static pthread_mutex_t vol_list_lock = PTHREAD_MUTEX_INITIALIZER; -static pthread_mutex_t search_lock = PTHREAD_MUTEX_INITIALIZER; /* Forward referenced functions */ static int can_reserve_drive(DCR *dcr, RCTX &rctx); -static int search_res_for_device(RCTX &rctx); static int reserve_device(RCTX &rctx); static bool reserve_device_for_read(DCR *dcr); static bool reserve_device_for_append(DCR *dcr, RCTX &rctx); static bool use_storage_cmd(JCR *jcr); -bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx); +static void queue_reserve_message(JCR *jcr); /* Requests from the Director daemon */ static char use_storage[] = "use storage=%127s media_type=%127s " @@ -105,6 +65,45 @@ static int my_compare(void *item1, void *item2) return strcmp(((VOLRES *)item1)->vol_name, ((VOLRES *)item2)->vol_name); } +static brwlock_t reservation_lock; + +void init_reservations_lock() +{ + int errstat; + if ((errstat=rwl_init(&reservation_lock)) != 0) { + berrno be; + Emsg1(M_ABORT, 0, _("Unable to initialize reservation lock. ERR=%s\n"), + be.strerror(errstat)); + } + +} + +void term_reservations_lock() +{ + rwl_destroy(&reservation_lock); +} + +/* This applies to a drive and to Volumes */ +void lock_reservations() +{ + int 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)); + } +} + +void unlock_reservations() +{ + int 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)); + } +} + /* * Put a new Volume entry in the Volume list. This @@ -119,6 +118,12 @@ VOLRES *new_volume(DCR *dcr, const char *VolumeName) VOLRES *vol, *nvol; Dmsg1(400, "new_volume %s\n", VolumeName); + /* + * We lock the reservations system here to ensure + * when adding a new volume that no newly scheduled + * job can reserve it. + */ + lock_reservations(); P(vol_list_lock); if (dcr->dev) { again: @@ -138,16 +143,27 @@ again: vol->vol_name = bstrdup(VolumeName); vol->dev = dcr->dev; vol->dcr = dcr; + Dmsg2(100, "New Vol=%s dev=%s\n", VolumeName, dcr->dev->print_name()); nvol = (VOLRES *)vol_list->binary_insert(vol, my_compare); if (nvol != vol) { free(vol->vol_name); free(vol); vol = NULL; if (dcr->dev) { - nvol->dev = dcr->dev; + DEVICE *dev = nvol->dev; + if (!dev->is_busy()) { + Dmsg3(100, "Swap vol=%s from dev=%s to %s\n", VolumeName, + dev->print_name(), dcr->dev->print_name()); + nvol->dev = dcr->dev; + dev->VolHdr.VolumeName[0] = 0; + } else { + Dmsg3(100, "!!!! could not swap vol=%s from dev=%s to %s\n", VolumeName, + dev->print_name(), dcr->dev->print_name()); + } } } V(vol_list_lock); + unlock_reservations(); return vol; } @@ -160,6 +176,7 @@ again: VOLRES *find_volume(const char *VolumeName) { VOLRES vol, *fvol; + /* Do not lock reservations here */ P(vol_list_lock); vol.vol_name = bstrdup(VolumeName); fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare); @@ -178,8 +195,9 @@ bool free_volume(DEVICE *dev) { VOLRES vol, *fvol; - P(vol_list_lock); + P(vol_list_lock); if (dev->VolHdr.VolumeName[0] == 0) { + Dmsg1(100, "free_volume: no vol on dev %s\n", dev->print_name()); /* * Our device has no VolumeName listed, but * search the list for any Volume attached to @@ -189,6 +207,7 @@ bool free_volume(DEVICE *dev) if (fvol && fvol->dev == dev) { vol_list->remove(fvol); if (fvol->vol_name) { + Dmsg2(100, "free_volume %s dev=%s\n", fvol->vol_name, dev->print_name()); free(fvol->vol_name); } free(fvol); @@ -202,6 +221,7 @@ bool free_volume(DEVICE *dev) fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare); if (fvol) { vol_list->remove(fvol); + Dmsg2(100, "free_volume %s dev=%s\n", fvol->vol_name, dev->print_name()); free(fvol->vol_name); free(fvol); } @@ -216,11 +236,13 @@ bail_out: void free_unused_volume(DCR *dcr) { VOLRES *vol; + P(vol_list_lock); for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) { if (vol->dcr == dcr && (vol->dev == NULL || strcmp(vol->vol_name, vol->dev->VolHdr.VolumeName) != 0)) { vol_list->remove(vol); + Dmsg1(100, "free_unused_volume %s\n", vol->vol_name); free(vol->vol_name); free(vol); break; @@ -232,16 +254,27 @@ void free_unused_volume(DCR *dcr) /* * List Volumes -- this should be moved to status.c */ -void list_volumes(BSOCK *user) +void list_volumes(void sendit(const char *msg, int len, void *sarg), void *arg) { VOLRES *vol; + char *msg; + int len; + + msg = (char *)get_pool_memory(PM_MESSAGE); + + P(vol_list_lock); for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) { if (vol->dev) { - bnet_fsend(user, "%s on device %s\n", vol->vol_name, vol->dev->print_name()); + len = Mmsg(msg, "%s on device %s\n", vol->vol_name, vol->dev->print_name()); + sendit(msg, len, arg); } else { - bnet_fsend(user, "%s\n", vol->vol_name); + len = Mmsg(msg, "%s\n", vol->vol_name); + sendit(msg, len, arg); } } + V(vol_list_lock); + + free_pool_memory(msg); } /* Create the Volume list */ @@ -260,29 +293,36 @@ void free_volume_list() if (!vol_list) { return; } + P(vol_list_lock); for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) { Dmsg3(000, "Unreleased Volume=%s dcr=0x%x dev=0x%x\n", vol->vol_name, vol->dcr, vol->dev); } delete vol_list; vol_list = NULL; + V(vol_list_lock); } bool is_volume_in_use(DCR *dcr) { VOLRES *vol = find_volume(dcr->VolumeName); if (!vol) { + Dmsg1(100, "Vol=%s not in use.\n", dcr->VolumeName); return false; /* vol not in list */ } if (!vol->dev) { /* vol not attached to device */ + Dmsg1(100, "Vol=%s has no dev.\n", dcr->VolumeName); return false; } if (dcr->dev == vol->dev) { /* same device OK */ + Dmsg1(100, "Vol=%s on same dev.\n", dcr->VolumeName); return false; } if (!vol->dev->is_busy()) { + Dmsg2(100, "Vol=%s dev=%s not busy.\n", dcr->VolumeName, vol->dev->print_name()); return false; } + Dmsg2(100, "Vol=%s used by %s.\n", dcr->VolumeName, vol->dev->print_name()); return true; } @@ -307,6 +347,9 @@ static bool use_storage_cmd(JCR *jcr) int Copy, Stripe; DIRSTORE *store; RCTX rctx; + char *msg; + alist *msgs; + alist *dirstore; memset(&rctx, 0, sizeof(RCTX)); rctx.jcr = jcr; @@ -314,7 +357,9 @@ static bool use_storage_cmd(JCR *jcr) * If there are multiple devices, the director sends us * use_device for each device that it wants to use. */ - jcr->dirstore = New(alist(10, not_owned_by_alist)); + dirstore = New(alist(10, not_owned_by_alist)); +// Dmsg2(000, "dirstore=%p JobId=%u\n", dirstore, jcr->JobId); + msgs = jcr->reserve_msgs = New(alist(10, not_owned_by_alist)); do { Dmsg1(100, "msg); ok = sscanf(dir->msg, use_storage, store_name.c_str(), @@ -323,12 +368,18 @@ static bool use_storage_cmd(JCR *jcr) if (!ok) { break; } + if (append) { + jcr->write_store = dirstore; + } else { + jcr->read_store = dirstore; + } + rctx.append = append; unbash_spaces(store_name); unbash_spaces(media_type); unbash_spaces(pool_name); unbash_spaces(pool_type); store = new DIRSTORE; - jcr->dirstore->append(store); + dirstore->append(store); memset(store, 0, sizeof(DIRSTORE)); store->device = New(alist(10)); bstrncpy(store->name, store_name, sizeof(store->name)); @@ -353,16 +404,17 @@ static bool use_storage_cmd(JCR *jcr) /* This loop is debug code and can be removed */ /* ***FIXME**** remove after 1.38 release */ char *device_name; - foreach_alist(store, jcr->dirstore) { - Dmsg4(100, "Storage=%s media_type=%s pool=%s pool_type=%s\n", + foreach_alist(store, dirstore) { + Dmsg5(110, "Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n", store->name, store->media_type, store->pool_name, - store->pool_type); + store->pool_type, store->append); foreach_alist(device_name, store->device) { - Dmsg1(100, " Device=%s\n", device_name); + Dmsg1(110, " Device=%s\n", device_name); } } #endif + init_jcr_device_wait_timers(jcr); /* * At this point, we have a list of all the Director's Storage * resources indicated for this Job, which include Pool, PoolType, @@ -374,7 +426,13 @@ static bool use_storage_cmd(JCR *jcr) */ if (ok) { bool first = true; /* print wait message once */ - for ( ; !job_canceled(jcr); ) { + bool fail = false; + rctx.notify_dir = true; + lock_reservations(); + for ( ; !fail && !job_canceled(jcr); ) { + while ((msg = (char *)msgs->pop())) { + free(msg); + } rctx.suitable_device = false; rctx.have_volume = false; rctx.any_drive = false; @@ -385,101 +443,109 @@ static bool use_storage_cmd(JCR *jcr) rctx.PreferMountedVols = false; rctx.exact_match = false; rctx.autochanger_only = true; - Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { - goto done; + break; } /* Look through all drives possibly for low_use drive */ if (rctx.low_use_drive) { rctx.try_low_use_drive = true; if ((ok = find_suitable_device_for_job(jcr, rctx))) { - goto done; + break; } rctx.try_low_use_drive = false; } rctx.autochanger_only = false; - Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { - goto done; + break; } } /* Look for an exact match all drives */ rctx.PreferMountedVols = true; rctx.exact_match = true; rctx.autochanger_only = false; - Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { - goto done; + break; } /* Look for any mounted drive */ rctx.exact_match = false; - Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { - goto done; + break; } /* Try any drive */ rctx.any_drive = true; - Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { - goto done; + break; } + /* Keep reservations locked *except* during wait_for_device() */ + unlock_reservations(); if (!rctx.suitable_device || !wait_for_device(jcr, first)) { - break; /* Get out, failure ... */ + Dmsg0(100, "Fail. !suitable_device || !wait_for_device\n"); + fail = true; } + lock_reservations(); first = false; bnet_sig(dir, BNET_HEARTBEAT); /* Inform Dir that we are alive */ } - - /* - * If we get here, there are no suitable devices available, which - * means nothing configured. If a device is suitable but busy - * with another Volume, we will not come here. - */ - if (verbose) { + unlock_reservations(); + if (!ok) { + /* + * If we get here, there are no suitable devices available, which + * means nothing configured. If a device is suitable but busy + * with another Volume, we will not come here. + */ unbash_spaces(dir->msg); pm_strcpy(jcr->errmsg, dir->msg); Jmsg(jcr, M_INFO, 0, _("Failed command: %s\n"), jcr->errmsg); - } - Jmsg(jcr, M_FATAL, 0, _("\n" - " Device \"%s\" with MediaType \"%s\" requested by DIR not found in SD Device resources.\n"), - dev_name.c_str(), media_type.c_str()); - bnet_fsend(dir, NO_device, dev_name.c_str()); + Jmsg(jcr, M_FATAL, 0, _("\n" + " Device \"%s\" with MediaType \"%s\" requested by DIR not found in SD Device resources.\n"), + dev_name.c_str(), media_type.c_str()); + bnet_fsend(dir, NO_device, dev_name.c_str()); - Dmsg1(100, ">dird: %s", dir->msg); + Dmsg1(100, ">dird: %s", dir->msg); + } } else { unbash_spaces(dir->msg); pm_strcpy(jcr->errmsg, dir->msg); - if (verbose) { - Jmsg(jcr, M_INFO, 0, _("Failed command: %s\n"), jcr->errmsg); - } + Jmsg(jcr, M_FATAL, 0, _("Failed command: %s\n"), jcr->errmsg); bnet_fsend(dir, BAD_use, jcr->errmsg); Dmsg1(100, ">dird: %s", dir->msg); } -done: - foreach_alist(store, jcr->dirstore) { - delete store->device; - delete store; - } - delete jcr->dirstore; -#ifdef implemented - while (error=(char*)rctx->errors.first()) { - free(error); - } -#endif + release_msgs(jcr); return ok; } +void release_msgs(JCR *jcr) +{ + alist *msgs = jcr->reserve_msgs; + char *msg; + + if (!msgs) { + return; + } + lock_reservations(); + while ((msg = (char *)msgs->pop())) { + free(msg); + } + delete msgs; + jcr->reserve_msgs = NULL; + unlock_reservations(); +} /* * Search for a device suitable for this job. @@ -489,37 +555,42 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) bool ok; DIRSTORE *store; char *device_name; + alist *dirstore; + if (rctx.append) { + dirstore = jcr->write_store; + } else { + dirstore = jcr->read_store; + } /* * For each storage device that the user specified, we * search and see if there is a resource for that device. */ - Dmsg4(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d\n", + Dmsg4(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only); - init_jcr_device_wait_timers(jcr); ok = false; - P(search_lock); - foreach_alist(store, jcr->dirstore) { + foreach_alist(store, dirstore) { rctx.store = store; foreach_alist(device_name, store->device) { int stat; rctx.device_name = device_name; stat = search_res_for_device(rctx); if (stat == 1) { /* found available device */ - rctx.suitable_device = true; + Dmsg1(100, "Suitable device found=%s\n", device_name); ok = true; break; } else if (stat == 0) { /* device busy */ - rctx.suitable_device = true; /* but it is busy, so continue looking */ + Dmsg1(110, "Suitable device found=%s, not used: busy\n", device_name); + } else { + /* otherwise error */ + Dmsg0(110, "No suitable device found.\n"); } - /* otherwise error */ } if (ok) { break; } } - V(search_lock); return ok; } @@ -528,14 +599,14 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) * Search for a particular storage device with particular storage * characteristics (MediaType). */ -static int search_res_for_device(RCTX &rctx) +int search_res_for_device(RCTX &rctx) { AUTOCHANGER *changer; BSOCK *dir = rctx.jcr->dir_bsock; bool ok; int stat; - Dmsg1(100, "Search res for %s\n", rctx.device_name); + Dmsg1(110, "Search res for %s\n", rctx.device_name); /* Look through Autochangers first */ foreach_res(changer, R_AUTOCHANGER) { Dmsg1(150, "Try match changer res=%s\n", changer->hdr.name); @@ -543,23 +614,27 @@ static int search_res_for_device(RCTX &rctx) if (fnmatch(rctx.device_name, changer->hdr.name, 0) == 0) { /* Try each device in this AutoChanger */ foreach_alist(rctx.device, changer->device) { - Dmsg1(100, "Try changer device %s\n", rctx.device->hdr.name); + Dmsg1(110, "Try changer device %s\n", 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.\n", rctx.device_name, + Dmsg2(100, "Device %s reserved=%d for append.\n", rctx.device->hdr.name, rctx.jcr->dcr->dev->reserved_device); } else { - Dmsg2(100, "Device %s reserved=%d.\n", rctx.device_name, + Dmsg2(100, "Device %s reserved=%d for read.\n", rctx.device->hdr.name, rctx.jcr->read_dcr->dev->reserved_device); } - pm_strcpy(dev_name, rctx.device->hdr.name); - bash_spaces(dev_name); - ok = bnet_fsend(dir, OK_device, dev_name.c_str()); /* Return real device name */ - Dmsg1(100, ">dird changer: %s", dir->msg); + if (rctx.notify_dir) { + pm_strcpy(dev_name, rctx.device->hdr.name); + bash_spaces(dev_name); + ok = bnet_fsend(dir, OK_device, dev_name.c_str()); /* Return real device name */ + Dmsg1(100, ">dird changer: %s", dir->msg); + } else { + ok = true; + } return ok ? 1 : -1; } } @@ -575,15 +650,18 @@ static int search_res_for_device(RCTX &rctx) if (stat != 1) { return stat; } - Dmsg1(220, "Got: %s", dir->msg); - bash_spaces(rctx.device_name); - ok = bnet_fsend(dir, OK_device, rctx.device_name); - Dmsg1(100, ">dird dev: %s", dir->msg); + if (rctx.notify_dir) { + bash_spaces(rctx.device_name); + ok = bnet_fsend(dir, OK_device, rctx.device_name); + Dmsg1(100, ">dird dev: %s", dir->msg); + } else { + ok = true; + } return ok ? 1 : -1; } } } - return 0; /* nothing found */ + return -1; /* nothing found */ } /* @@ -600,6 +678,8 @@ static int reserve_device(RCTX &rctx) const int name_len = MAX_NAME_LENGTH; /* Make sure MediaType is OK */ + Dmsg2(110, "MediaType device=%s request=%s\n", + rctx.device->media_type, rctx.store->media_type); if (strcmp(rctx.device->media_type, rctx.store->media_type) != 0) { return -1; } @@ -621,7 +701,8 @@ static int reserve_device(RCTX &rctx) return -1; /* no use waiting */ } - Dmsg2(100, "Try reserve %s jobid=%d\n", rctx.device->hdr.name, + rctx.suitable_device = true; + Dmsg2(110, "Try reserve %s JobId=%u\n", rctx.device->hdr.name, rctx.jcr->JobId); dcr = new_dcr(rctx.jcr, rctx.device->dev); if (!dcr) { @@ -638,8 +719,8 @@ static int reserve_device(RCTX &rctx) if (rctx.exact_match && !rctx.have_volume) { dcr->any_volume = true; if (dir_find_next_appendable_volume(dcr)) { - Dmsg1(100, "Looking for Volume=%s\n", dcr->VolumeName); bstrncpy(rctx.VolumeName, dcr->VolumeName, sizeof(rctx.VolumeName)); + Dmsg2(100, "JobId=%u looking for Volume=%s\n", rctx.jcr->JobId, rctx.VolumeName); rctx.have_volume = true; } else { Dmsg0(100, "No next volume found\n"); @@ -664,7 +745,7 @@ static int reserve_device(RCTX &rctx) } if (!ok) { free_dcr(dcr); - Dmsg0(100, "Not OK.\n"); + Dmsg0(110, "Not OK.\n"); return 0; } return 1; @@ -684,26 +765,35 @@ static bool reserve_device_for_read(DCR *dcr) ASSERT(dcr); + /* Get locks in correct order */ + unlock_reservations(); P(dev->mutex); + lock_reservations(); if (is_device_unmounted(dev)) { Dmsg1(200, "Device %s is BLOCKED due to user unmount.\n", dev->print_name()); - Mmsg(jcr->errmsg, _("Device %s is BLOCKED due to user unmount.\n"), - 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); goto bail_out; } if (dev->is_busy()) { Dmsg4(200, "Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", dev->print_name(), dev->state & ST_READ?1:0, dev->num_writers, dev->reserved_device); - Mmsg1(jcr->errmsg, _("Device %s is busy.\n"), - dev->print_name()); + Mmsg(jcr->errmsg, _("3602 JobId=%u device %s is busy (already reading/writing).\n"), + jcr->JobId, dev->print_name()); + queue_reserve_message(jcr); goto bail_out; } dev->clear_append(); dev->set_read(); ok = true; + dev->reserved_device++; + Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, + dev->print_name(), dev); + dcr->reserved_device = true; bail_out: V(dev->mutex); @@ -738,23 +828,27 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx) /* If device is being read, we cannot write it */ if (dev->can_read()) { - Mmsg1(jcr->errmsg, _("Device %s is busy reading.\n"), dev->print_name()); - Dmsg1(100, "%s", jcr->errmsg); + Mmsg(jcr->errmsg, _("3603 JobId=%u device %s is busy reading.\n"), + jcr->JobId, dev->print_name()); + Dmsg1(110, "%s", jcr->errmsg); + queue_reserve_message(jcr); goto bail_out; } /* If device is unmounted, we are out of luck */ if (is_device_unmounted(dev)) { - Mmsg(jcr->errmsg, _("Device %s is BLOCKED due to user unmount.\n"), dev->print_name()); - Dmsg1(100, "%s", jcr->errmsg); + Mmsg(jcr->errmsg, _("3604 JobId=%u device %s is BLOCKED due to user unmount.\n"), + jcr->JobId, dev->print_name()); + Dmsg1(110, "%s", jcr->errmsg); + queue_reserve_message(jcr); goto bail_out; } - Dmsg1(100, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk"); + Dmsg1(110, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk"); /* Now do detailed tests ... */ if (can_reserve_drive(dcr, rctx) != 1) { - Dmsg0(100, "can_reserve_drive!=1\n"); + Dmsg0(110, "can_reserve_drive!=1\n"); goto bail_out; } @@ -779,7 +873,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) DEVICE *dev = dcr->dev; JCR *jcr = dcr->jcr; - Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", + Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); @@ -792,7 +886,7 @@ 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(100, "OK dev=%s == low_drive=%s. JobId=%d\n", + Dmsg3(110, "OK dev=%s == low_drive=%s. JobId=%u\n", dev->print_name(), rctx.low_use_drive->print_name(), jcr->JobId); return 1; } @@ -802,26 +896,36 @@ 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; - Dmsg2(100, "set low use drive=%s num_writers=%d\n", dev->print_name(), + Dmsg2(110, "set low use drive=%s num_writers=%d\n", dev->print_name(), rctx.num_writers); } else { - Dmsg1(100, "not low use num_writers=%d\n", dev->num_writers+ + Dmsg1(110, "not low use num_writers=%d\n", dev->num_writers+ dev->reserved_device); } - Dmsg1(100, "failed: !prefMnt && busy. JobId=%d\n", jcr->JobId); + 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"), + jcr->JobId, dev->print_name()); + queue_reserve_message(jcr); return 0; } /* Check for prefer mounted volumes */ if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) { - Dmsg1(100, "failed: want mounted -- no vol JobId=%d\n", jcr->JobId); + 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); return 0; /* No volume mounted */ } /* Check for exact Volume name match */ if (rctx.exact_match && rctx.have_volume && strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) != 0) { - Dmsg2(100, "failed: Not exact match have=%s want=%s\n", + 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); return 0; } @@ -831,7 +935,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) if (rctx.autochanger_only && dev->num_writers == 0 && dev->VolHdr.VolumeName[0] == 0) { /* Device is available but not yet reserved, reserve it for us */ - Dmsg2(100, "OK Res Unused autochanger %s JobId=%d.\n", + Dmsg2(100, "OK Res Unused autochanger %s JobId=%u.\n", dev->print_name(), jcr->JobId); bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name)); bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type)); @@ -848,12 +952,15 @@ 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(100, "OK dev: %s num_writers=0, reserved, pool matches JobId=%d\n", + Dmsg2(100, "OK dev: %s num_writers=0, reserved, pool matches JobId=%u\n", dev->print_name(), jcr->JobId); return 1; } else { - /* Drive not suitable for us */ - Dmsg2(100, "failed: busy num_writers=0, reserved, pool=%s wanted=%s\n", + /* Drive Pool not suitable for us */ + Mmsg(jcr->errmsg, _("3608 JobId=%u wants Pool=\"%s\" but have 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, reserved, pool=%s wanted=%s\n", dev->pool_name, dcr->pool_name); return 0; /* wait */ } @@ -861,7 +968,7 @@ 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(100, "OK dev: %s num_writers=0, can_append, pool matches. JobId=%d\n", + Dmsg2(100, "OK dev: %s num_writers=0, can_append, pool matches. JobId=%u\n", dev->print_name(), jcr->JobId); /* OK, compatible device */ return 1; @@ -872,7 +979,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) } } /* Device is available but not yet reserved, reserve it for us */ - Dmsg2(100, "OK Dev avail reserved %s JobId=%d\n", dev->print_name(), + Dmsg2(100, "OK Dev avail reserved %s JobId=%u\n", dev->print_name(), jcr->JobId); bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name)); bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type)); @@ -887,21 +994,87 @@ 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(100, "OK dev: %s num_writers>=0, can_append, pool matches. JobId=%d\n", + Dmsg2(100, "OK dev: %s num_writers>=0, can_append, pool matches. JobId=%u\n", dev->print_name(), jcr->JobId); /* OK, compatible device */ return 1; } else { - /* Drive not suitable for us */ - Dmsg2(100, "failed: busy num_writers>0, can_append, pool=%s wanted=%s\n", + /* 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); + Dmsg2(110, "failed: busy num_writers>0, can_append, pool=%s wanted=%s\n", dev->pool_name, dcr->pool_name); return 0; /* wait */ } } else { Pmsg0(000, _("Logic error!!!! Should not get here.\n")); + Mmsg(jcr->errmsg, _("3910 JobId=%u Logic error!!!! drive %s Should not get here.\n"), + jcr->JobId, dev->print_name()); + queue_reserve_message(jcr); Jmsg0(jcr, M_FATAL, 0, _("Logic error!!!! Should not get here.\n")); return -1; /* error, should not get here */ } - Dmsg2(100, "failed: No reserve %s JobId=%d\n", dev->print_name(), jcr->JobId); + Mmsg(jcr->errmsg, _("3911 JobId=%u failed reserve drive %s.\n"), + jcr->JobId, dev->print_name()); + queue_reserve_message(jcr); + Dmsg2(110, "failed: No reserve %s JobId=%u\n", dev->print_name(), jcr->JobId); return 0; } + +/* + * search_lock is already set on entering this routine + */ +static void queue_reserve_message(JCR *jcr) +{ + int i; + alist *msgs = jcr->reserve_msgs; + char *msg; + + if (!msgs) { + return; + } + /* + * Look for duplicate message. If found, do + * not insert + */ + for (i=msgs->size()-1; i >= 0; i--) { + msg = (char *)msgs->get(i); + if (!msg) { + return; + } + /* Comparison based on 4 digit message number */ + if (strncmp(msg, jcr->errmsg, 4) == 0) { + return; + } + } + /* Message unique, so insert it */ + jcr->reserve_msgs->push(bstrdup(jcr->errmsg)); +} + +/* + * Send any reservation messages queued for this jcr + */ +void send_drive_reserve_messages(JCR *jcr, void sendit(const char *msg, int len, void *sarg), void *arg) +{ + int i; + alist *msgs; + char *msg; + + lock_reservations(); + msgs = jcr->reserve_msgs; + if (!msgs || msgs->size() == 0) { + unlock_reservations(); + return; + } + for (i=msgs->size()-1; i >= 0; i--) { + msg = (char *)msgs->get(i); + if (msg) { + sendit(" ", 3, arg); + sendit(msg, strlen(msg), arg); + } else { + break; + } + } + unlock_reservations(); +}