]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/askdir.c
Massive SD calling sequence reorganization
[bacula/bacula] / bacula / src / stored / askdir.c
1 /*
2  *  Subroutines to handle Catalog reqests sent to the Director
3  *   Reqests/commands from the Director are handled in dircmd.c
4  *
5  *   Kern Sibbald, December 2000
6  *
7  *   Version $Id$
8  */
9 /*
10    Copyright (C) 2000-2004 Kern Sibbald and John Walker
11
12    This program is free software; you can redistribute it and/or
13    modify it under the terms of the GNU General Public License as
14    published by the Free Software Foundation; either version 2 of
15    the License, or (at your option) any later version.
16
17    This program is distributed in the hope that it will be useful,
18    but WITHOUT ANY WARRANTY; without even the implied warranty of
19    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
20    General Public License for more details.
21
22    You should have received a copy of the GNU General Public
23    License along with this program; if not, write to the Free
24    Software Foundation, Inc., 59 Temple Place - Suite 330, Boston,
25    MA 02111-1307, USA.
26
27  */
28
29 #include "bacula.h"                   /* pull in global headers */
30 #include "stored.h"                   /* pull in Storage Deamon headers */
31
32 /* Requests sent to the Director */
33 static char Find_media[]   = "CatReq Job=%s FindMedia=%d\n";
34 static char Get_Vol_Info[] = "CatReq Job=%s GetVolInfo VolName=%s write=%d\n";
35 static char Update_media[] = "CatReq Job=%s UpdateMedia VolName=%s"
36    " VolJobs=%u VolFiles=%u VolBlocks=%u VolBytes=%s VolMounts=%u"
37    " VolErrors=%u VolWrites=%u MaxVolBytes=%s EndTime=%d VolStatus=%s"
38    " Slot=%d relabel=%d InChanger=%d VolReadTime=%s VolWriteTime=%s\n";
39 static char Create_job_media[] = "CatReq Job=%s CreateJobMedia" 
40    " FirstIndex=%u LastIndex=%u StartFile=%u EndFile=%u" 
41    " StartBlock=%u EndBlock=%u\n";
42 static char FileAttributes[] = "UpdCat Job=%s FileAttributes ";
43 static char Job_status[]     = "3012 Job %s jobstatus %d\n";
44
45
46 /* Responses received from the Director */
47 static char OK_media[] = "1000 OK VolName=%127s VolJobs=%u VolFiles=%u"
48    " VolBlocks=%u VolBytes=%" lld " VolMounts=%u VolErrors=%u VolWrites=%u"
49    " MaxVolBytes=%" lld " VolCapacityBytes=%" lld " VolStatus=%20s"
50    " Slot=%d MaxVolJobs=%u MaxVolFiles=%u InChanger=%d"
51    " VolReadTime=%" lld " VolWriteTime=%" lld;
52
53
54 static char OK_create[] = "1000 OK CreateJobMedia\n";
55
56 /* Forward referenced functions */
57 static int wait_for_sysop(DCR *dcr);
58
59 /*
60  * Send current JobStatus to Director
61  */
62 bool dir_send_job_status(JCR *jcr)
63 {
64    return bnet_fsend(jcr->dir_bsock, Job_status, jcr->Job, jcr->JobStatus);
65 }
66
67 /*
68  * Common routine for:
69  *   dir_get_volume_info()
70  * and
71  *   dir_find_next_appendable_volume()
72  * 
73  *  Returns: true  on success and vol info in dcr->VolCatInfo
74  *           false on failure
75  */
76 static bool do_get_volume_info(DCR *dcr)
77 {
78     JCR *jcr = dcr->jcr;
79     BSOCK *dir = jcr->dir_bsock;
80     VOLUME_CAT_INFO vol;
81     int n;
82     int InChanger;
83
84     dcr->VolumeName[0] = 0;           /* No volume */
85     if (bnet_recv(dir) <= 0) {
86        Dmsg0(200, "getvolname error bnet_recv\n");
87        Mmsg(jcr->errmsg, _("Network error on bnet_recv in req_vol_info.\n"));
88        return false;
89     }
90     memset(&vol, 0, sizeof(vol));
91     Dmsg1(200, "Get vol info=%s\n", dir->msg);
92     n = sscanf(dir->msg, OK_media, vol.VolCatName, 
93                &vol.VolCatJobs, &vol.VolCatFiles,
94                &vol.VolCatBlocks, &vol.VolCatBytes,
95                &vol.VolCatMounts, &vol.VolCatErrors,
96                &vol.VolCatWrites, &vol.VolCatMaxBytes,
97                &vol.VolCatCapacityBytes, vol.VolCatStatus,
98                &vol.Slot, &vol.VolCatMaxJobs, &vol.VolCatMaxFiles,
99                &InChanger, &vol.VolReadTime, &vol.VolWriteTime);
100     if (n != 17) {
101        Dmsg2(100, "Bad response from Dir fields=%d: %s\n", n, dir->msg);
102        Mmsg(jcr->errmsg, _("Error getting Volume info: %s\n"), dir->msg);
103        return false;
104     }
105     vol.InChanger = InChanger;        /* bool in structure */
106     unbash_spaces(vol.VolCatName);
107     bstrncpy(dcr->VolumeName, vol.VolCatName, sizeof(dcr->VolumeName));
108     memcpy(&dcr->VolCatInfo, &vol, sizeof(dcr->VolCatInfo));
109     
110     Dmsg2(200, "do_reqest_vol_info got slot=%d Volume=%s\n", 
111           vol.Slot, vol.VolCatName);
112     return true;
113 }
114
115
116 /*
117  * Get Volume info for a specific volume from the Director's Database
118  *
119  * Returns: true  on success   (not Director guarantees that Pool and MediaType
120  *                             are correct and VolStatus==Append or
121  *                             VolStatus==Recycle)
122  *          false on failure
123  *
124  *          Volume information returned in jcr
125  */
126 bool dir_get_volume_info(DCR *dcr, enum get_vol_info_rw writing)
127 {
128     JCR *jcr = dcr->jcr;
129     BSOCK *dir = jcr->dir_bsock;
130
131     bstrncpy(dcr->VolCatInfo.VolCatName, dcr->VolumeName, sizeof(dcr->VolCatInfo.VolCatName));
132     Dmsg1(200, "dir_get_volume_info=%s\n", dcr->VolCatInfo.VolCatName);
133     bash_spaces(dcr->VolCatInfo.VolCatName);
134     bnet_fsend(dir, Get_Vol_Info, jcr->Job, dcr->VolCatInfo.VolCatName, 
135        writing==GET_VOL_INFO_FOR_WRITE?1:0);
136     return do_get_volume_info(dcr);
137 }
138
139
140
141 /*
142  * Get info on the next appendable volume in the Director's database
143  * Returns: true  on success
144  *          false on failure
145  *
146  *          Volume information returned in jcr
147  *
148  */
149 bool dir_find_next_appendable_volume(DCR *dcr)
150 {
151     JCR *jcr = dcr->jcr;
152     BSOCK *dir = jcr->dir_bsock;
153     JCR *njcr;
154
155     Dmsg0(200, "dir_find_next_appendable_volume\n");
156     for (int vol_index=1;  vol_index < 3; vol_index++) {
157        bnet_fsend(dir, Find_media, jcr->Job, vol_index);
158        if (do_get_volume_info(dcr)) {
159           Dmsg2(200, "JobId=%d got possible Vol=%s\n", jcr->JobId, dcr->VolumeName);
160           bool found = false;
161           /* 
162            * Walk through all jobs and see if the volume is   
163            *  already mounted. If so, try a different one.
164            * This would be better done by walking through  
165            *  all the devices.
166            */
167           lock_jcr_chain();
168           foreach_jcr(njcr) {
169              if (jcr == njcr) {
170                 free_locked_jcr(njcr);
171                 continue;             /* us */
172              }
173              Dmsg2(200, "Compare to JobId=%d using Vol=%s\n", njcr->JobId, njcr->dcr->VolumeName);
174              if (njcr->dcr && strcmp(dcr->VolumeName, njcr->dcr->VolumeName) == 0) {
175                 found = true;
176                 Dmsg1(200, "Vol in use by JobId=%u\n", njcr->JobId);
177                 free_locked_jcr(njcr);
178                 break;
179              }
180              free_locked_jcr(njcr);
181           }
182           unlock_jcr_chain();
183           if (!found) {
184              Dmsg0(200, "dir_find_next_appendable_volume return true\n");
185              return true;             /* Got good Volume */
186           }
187        } else {
188           Dmsg0(200, "No volume info, return false\n");
189           return false;
190        }
191     }
192     Dmsg0(200, "dir_find_next_appendable_volume return true\n");
193     return true; 
194 }
195
196     
197 /*
198  * After writing a Volume, send the updated statistics
199  * back to the director. The information comes from the
200  * dev record.     
201  */
202 bool dir_update_volume_info(DCR *dcr, bool label)
203 {
204    JCR *jcr = dcr->jcr;
205    BSOCK *dir = jcr->dir_bsock;
206    DEVICE *dev = dcr->dev;
207    time_t LastWritten = time(NULL);
208    char ed1[50], ed2[50], ed3[50], ed4[50];
209    VOLUME_CAT_INFO *vol = &dev->VolCatInfo;
210    int InChanger;
211
212    if (vol->VolCatName[0] == 0) {
213       Jmsg0(jcr, M_FATAL, 0, _("NULL Volume name. This shouldn't happen!!!\n"));
214       return false;
215    }
216    if (dev_state(dev, ST_READ)) {
217       Jmsg0(jcr, M_FATAL, 0, _("Attempt to update_volume_info in read mode!!!\n"));
218       return false;
219    }
220
221    Dmsg1(100, "Update cat VolFiles=%d\n", dev->file);
222    /* Just labeled or relabeled the tape */
223    if (label) {
224       bstrncpy(vol->VolCatStatus, "Append", sizeof(vol->VolCatStatus));
225       vol->VolCatBytes = 1;           /* indicates tape labeled */
226    }
227    bash_spaces(vol->VolCatName);
228    InChanger = vol->InChanger;
229    bnet_fsend(dir, Update_media, jcr->Job, 
230       vol->VolCatName, vol->VolCatJobs, vol->VolCatFiles,
231       vol->VolCatBlocks, edit_uint64(vol->VolCatBytes, ed1),
232       vol->VolCatMounts, vol->VolCatErrors,
233       vol->VolCatWrites, edit_uint64(vol->VolCatMaxBytes, ed2), 
234       LastWritten, vol->VolCatStatus, vol->Slot, label,
235       InChanger,                      /* bool in structure */
236       edit_uint64(vol->VolReadTime, ed3), 
237       edit_uint64(vol->VolWriteTime, ed4) );
238
239    Dmsg1(120, "update_volume_info(): %s", dir->msg);
240    unbash_spaces(vol->VolCatName);
241
242    if (!do_get_volume_info(dcr)) {
243       Jmsg(jcr, M_FATAL, 0, "%s", jcr->errmsg);
244       return false;
245    }
246    Dmsg1(120, "get_volume_info(): %s", dir->msg);
247    /* Update dev Volume info in case something changed (e.g. expired) */
248    memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo));
249    return true;
250 }
251
252 /*
253  * After writing a Volume, create the JobMedia record.
254  */
255 bool dir_create_jobmedia_record(DCR *dcr)
256 {
257    JCR *jcr = dcr->jcr;
258    BSOCK *dir = jcr->dir_bsock;
259
260    if (!dcr->WroteVol) {
261       return true;                    /* nothing written to tape */
262    }
263
264    dcr->WroteVol = false;
265    bnet_fsend(dir, Create_job_media, jcr->Job, 
266       dcr->VolFirstIndex, dcr->VolLastIndex,
267       dcr->StartFile, dcr->EndFile,
268       dcr->StartBlock, dcr->EndBlock);
269    Dmsg1(100, "create_jobmedia(): %s", dir->msg);
270    if (bnet_recv(dir) <= 0) {
271       Dmsg0(190, "create_jobmedia error bnet_recv\n");
272       Jmsg(jcr, M_FATAL, 0, _("Error creating JobMedia record: ERR=%s\n"), 
273            bnet_strerror(dir));
274       return false;
275    }
276    Dmsg1(120, "Create_jobmedia: %s", dir->msg);
277    if (strcmp(dir->msg, OK_create) != 0) {
278       Dmsg1(130, "Bad response from Dir: %s\n", dir->msg);
279       Jmsg(jcr, M_FATAL, 0, _("Error creating JobMedia record: %s\n"), dir->msg);
280       return false;
281    }
282    return true;
283 }
284
285
286 /* 
287  * Update File Attribute data
288  */
289 bool dir_update_file_attributes(DCR *dcr, DEV_RECORD *rec)
290 {
291    JCR *jcr = dcr->jcr;
292    BSOCK *dir = jcr->dir_bsock;
293    ser_declare;
294
295    dir->msglen = sprintf(dir->msg, FileAttributes, jcr->Job);
296    dir->msg = check_pool_memory_size(dir->msg, dir->msglen + 
297                 sizeof(DEV_RECORD) + rec->data_len);
298    ser_begin(dir->msg + dir->msglen, 0);
299    ser_uint32(rec->VolSessionId);
300    ser_uint32(rec->VolSessionTime);
301    ser_int32(rec->FileIndex);
302    ser_int32(rec->Stream);
303    ser_uint32(rec->data_len);
304    ser_bytes(rec->data, rec->data_len);
305    dir->msglen = ser_length(dir->msg);
306    return bnet_send(dir);
307 }
308
309
310 /*
311  *   Request the sysop to create an appendable volume
312  *
313  *   Entered with device blocked.
314  *   Leaves with device blocked.
315  *
316  *   Returns: true  on success (operator issues a mount command)
317  *            false on failure
318  *              Note, must create dev->errmsg on error return.
319  *
320  *    On success, dcr->VolumeName and dcr->VolCatInfo contain
321  *      information on suggested volume, but this may not be the
322  *      same as what is actually mounted.
323  *
324  *    When we return with success, the correct tape may or may not
325  *      actually be mounted. The calling routine must read it and
326  *      verify the label.
327  */
328 bool dir_ask_sysop_to_create_appendable_volume(DCR *dcr)
329 {
330    int stat = 0, jstat;
331    bool unmounted;
332    bool first = true;
333    DEVICE *dev = dcr->dev;
334    JCR *jcr = dcr->jcr;
335
336    Dmsg0(200, "enter dir_ask_sysop_to_create_appendable_volume\n");
337    ASSERT(dev->dev_blocked);
338    for ( ;; ) {
339       if (job_canceled(jcr)) {
340          Mmsg(dev->errmsg,
341               _("Job %s canceled while waiting for mount on Storage Device \"%s\".\n"), 
342               jcr->Job, dcr->dev_name);
343          Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
344          return false;
345       }
346       /* First pass, we *know* there are no appendable volumes, so no need to call */
347       if (!first && dir_find_next_appendable_volume(dcr)) { /* get suggested volume */
348          unmounted = (dev->dev_blocked == BST_UNMOUNTED) ||
349                      (dev->dev_blocked == BST_UNMOUNTED_WAITING_FOR_SYSOP);
350          /*
351           * If we have a valid volume name and we are not
352           *   removable media, return now, or if we have a
353           *   Slot for an autochanger, otherwise wait
354           *   for the operator to mount the media.
355           */
356          if (!unmounted && ((dcr->VolumeName[0] && !dev_cap(dev, CAP_REM) && 
357                 dev_cap(dev, CAP_LABEL)) ||
358                  (dcr->VolumeName[0] && dcr->VolCatInfo.Slot))) {
359             Dmsg0(200, "Return 1 from mount without wait.\n");
360             return true;
361          }
362          jstat = JS_WaitMount;
363          if (!dev->poll) {
364             Jmsg(jcr, M_MOUNT, 0, _(
365 "Please mount Volume \"%s\" on Storage Device \"%s\" for Job %s\n"
366 "Use \"mount\" command to release Job.\n"),
367               dcr->VolumeName, dcr->dev_name, jcr->Job);
368             Dmsg3(200, "Mount %s on %s for Job %s\n",
369                   dcr->VolumeName, dcr->dev_name, jcr->Job);
370          }
371       } else {
372          jstat = JS_WaitMedia;
373          if (!dev->poll) {
374             Jmsg(jcr, M_MOUNT, 0, _(
375 "Job %s waiting. Cannot find any appendable volumes.\n\
376 Please use the \"label\"  command to create a new Volume for:\n\
377     Storage:      %s\n\
378     Media type:   %s\n\
379     Pool:         %s\n"),
380                jcr->Job, 
381                dcr->dev_name, 
382                dcr->media_type,
383                dcr->pool_name);
384          }
385       }
386       first = false;
387
388       jcr->JobStatus = jstat;
389       dir_send_job_status(jcr);
390
391       stat = wait_for_sysop(dcr);
392       if (dev->poll) {
393          Dmsg1(200, "Poll timeout in create append vol on device %s\n", dev_name(dev));
394          continue;
395       }
396
397       if (stat == ETIMEDOUT) {
398          if (!double_dev_wait_time(dev)) {
399             Mmsg(dev->errmsg, _("Max time exceeded waiting to mount Storage Device \"%s\" for Job %s\n"), 
400                dev_name(dev), jcr->Job);
401             Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
402             Dmsg1(200, "Gave up waiting on device %s\n", dev_name(dev));
403             return false;             /* exceeded maximum waits */
404          }
405          continue;
406       }
407       if (stat == EINVAL) {
408          berrno be;
409          Mmsg2(dev->errmsg, _("pthread error in mount_next_volume stat=%d ERR=%s\n"),
410                stat, be.strerror(stat));
411          Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
412          return false;
413       }
414       if (stat != 0) {
415          berrno be;
416          Jmsg(jcr, M_WARNING, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
417             be.strerror(stat));
418       }
419       Dmsg1(200, "Someone woke me for device %s\n", dev_name(dev));
420
421       /* If no VolumeName, and cannot get one, try again */
422       if (dcr->VolumeName[0] == 0 && !job_canceled(jcr) &&
423           !dir_find_next_appendable_volume(dcr)) {
424          Jmsg(jcr, M_MOUNT, 0, _(
425 "Someone woke me up, but I cannot find any appendable\n\
426 volumes for Job=%s.\n"), jcr->Job);
427          /* Restart wait counters after user interaction */
428          init_dev_wait_timers(dev);
429          continue;
430       }       
431       unmounted = (dev->dev_blocked == BST_UNMOUNTED) ||
432                   (dev->dev_blocked == BST_UNMOUNTED_WAITING_FOR_SYSOP);
433       if (unmounted) {
434          continue;                    /* continue to wait */
435       }
436
437       /*
438        * Device mounted, we have a volume, break and return   
439        */
440       break;
441    }
442    set_jcr_job_status(jcr, JS_Running);
443    dir_send_job_status(jcr);
444    Dmsg0(200, "leave dir_ask_sysop_to_mount_create_appendable_volume\n");
445    return true;
446 }
447
448 /*
449  *   Request to mount specific Volume
450  *
451  *   Entered with device blocked and dcr->VolumeName is desired
452  *      volume.
453  *   Leaves with device blocked.
454  *
455  *   Returns: true  on success (operator issues a mount command)
456  *            false on failure
457  *                  Note, must create dev->errmsg on error return.
458  *
459  */
460 bool dir_ask_sysop_to_mount_volume(DCR *dcr)
461 {
462    int stat = 0;
463    const char *msg;
464    DEVICE *dev = dcr->dev;
465    JCR *jcr = dcr->jcr;
466
467    Dmsg0(200, "enter dir_ask_sysop_to_mount_volume\n");
468    if (!dcr->VolumeName[0]) {
469       Mmsg0(dev->errmsg, _("Cannot request another volume: no volume name given.\n"));
470       return false;
471    }
472    ASSERT(dev->dev_blocked);
473    for ( ;; ) {
474       if (job_canceled(jcr)) {
475          Mmsg(dev->errmsg, _("Job %s canceled while waiting for mount on Storage Device \"%s\".\n"), 
476               jcr->Job, dcr->dev_name);
477          return false;
478       }
479
480       if (!dev->poll) {
481          msg = _("Please mount");
482          Jmsg(jcr, M_MOUNT, 0, _("%s Volume \"%s\" on Storage Device \"%s\" for Job %s\n"),
483               msg, dcr->VolumeName, dcr->dev_name, jcr->Job);
484          Dmsg3(200, "Mount \"%s\" on device \"%s\" for Job %s\n",
485                dcr->VolumeName, dcr->dev_name, jcr->Job);
486       }
487
488       jcr->JobStatus = JS_WaitMount;
489       dir_send_job_status(jcr);
490
491       stat = wait_for_sysop(dcr);    ;     /* wait on device */
492       if (dev->poll) {
493          Dmsg1(200, "Poll timeout in mount vol on device %s\n", dev_name(dev));
494          Dmsg1(200, "Blocked=%s\n", edit_blocked_reason(dev));
495          return true;
496       }
497
498       if (stat == ETIMEDOUT) {
499          if (!double_dev_wait_time(dev)) {
500             Mmsg(dev->errmsg, _("Max time exceeded waiting to mount Storage Device \"%s\" for Job %s\n"), 
501                dev_name(dev), jcr->Job);
502             Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
503             Dmsg1(200, "Gave up waiting on device %s\n", dev_name(dev));
504             return false;             /* exceeded maximum waits */
505          }
506          continue;
507       }
508       if (stat == EINVAL) {
509          berrno be;
510          Mmsg2(dev->errmsg, _("pthread error in mount_volume stat=%d ERR=%s\n"),
511                stat, be.strerror(stat));
512          Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
513          return false;
514       }
515       if (stat != 0) {
516          berrno be;
517          Jmsg(jcr, M_FATAL, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
518             be.strerror(stat));
519       }
520       Dmsg1(200, "Someone woke me for device %s\n", dev_name(dev));
521       break;
522    }
523    set_jcr_job_status(jcr, JS_Running);
524    dir_send_job_status(jcr);
525    Dmsg0(200, "leave dir_ask_sysop_to_mount_volume\n");
526    return true;
527 }
528
529 /*
530  * Wait for SysOp to mount a tape
531  */
532 static int wait_for_sysop(DCR *dcr)
533 {
534    struct timeval tv;
535    struct timezone tz;
536    struct timespec timeout;
537    time_t last_heartbeat = 0;
538    time_t first_start = time(NULL);
539    int stat = 0;
540    int add_wait;
541    bool unmounted;
542    DEVICE *dev = dcr->dev;
543    JCR *jcr = dcr->jcr;
544    
545    P(dev->mutex);
546    unmounted = (dev->dev_blocked == BST_UNMOUNTED) ||
547                 (dev->dev_blocked == BST_UNMOUNTED_WAITING_FOR_SYSOP);
548
549    dev->poll = false;
550    /*
551     * Wait requested time (dev->rem_wait_sec).  However, we also wake up every
552     *    HB_TIME seconds and send a heartbeat to the FD and the Director
553     *    to keep stateful firewalls from closing them down while waiting
554     *    for the operator.
555     */
556    add_wait = dev->rem_wait_sec;
557    if (me->heartbeat_interval && add_wait > me->heartbeat_interval) {
558       add_wait = me->heartbeat_interval;
559    }
560    /* If the user did not unmount the tape and we are polling, ensure
561     *  that we poll at the correct interval. 
562     */
563    if (!unmounted && dev->vol_poll_interval && add_wait > dev->vol_poll_interval) {
564       add_wait = dev->vol_poll_interval;
565    }
566    gettimeofday(&tv, &tz);
567    timeout.tv_nsec = tv.tv_usec * 1000;
568    timeout.tv_sec = tv.tv_sec + add_wait;
569
570    if (!unmounted) {
571       dev->dev_prev_blocked = dev->dev_blocked;
572       dev->dev_blocked = BST_WAITING_FOR_SYSOP; /* indicate waiting for mount */
573    }
574
575    for ( ; !job_canceled(jcr); ) {
576       time_t now, start;
577
578       Dmsg3(200, "I'm going to sleep on device %s. HB=%d wait=%d\n", dev_name(dev),
579          (int)me->heartbeat_interval, dev->wait_sec);
580       start = time(NULL);
581       /* Wait required time */
582       stat = pthread_cond_timedwait(&dev->wait_next_vol, &dev->mutex, &timeout);
583       Dmsg1(200, "Wokeup from sleep on device stat=%d\n", stat);
584
585       now = time(NULL);
586       dev->rem_wait_sec -= (now - start);
587
588       /* Note, this always triggers the first time. We want that. */
589       if (me->heartbeat_interval) {
590          if (now - last_heartbeat >= me->heartbeat_interval) {
591             /* send heartbeats */
592             if (jcr->file_bsock) {
593                bnet_sig(jcr->file_bsock, BNET_HEARTBEAT);
594                Dmsg0(200, "Send heartbeat to FD.\n");
595             }
596             if (jcr->dir_bsock) {
597                bnet_sig(jcr->dir_bsock, BNET_HEARTBEAT);
598             }
599             last_heartbeat = now;
600          }
601       }
602
603       /*
604        * Check if user unmounted the device while we were waiting
605        */
606       unmounted = (dev->dev_blocked == BST_UNMOUNTED) ||
607                    (dev->dev_blocked == BST_UNMOUNTED_WAITING_FOR_SYSOP);
608
609       if (stat != ETIMEDOUT) {     /* we blocked the device */
610          break;                    /* on error return */
611       }
612       if (dev->rem_wait_sec <= 0) {  /* on exceeding wait time return */
613          Dmsg0(200, "Exceed wait time.\n");
614          break;
615       }
616       
617       if (!unmounted && dev->vol_poll_interval &&       
618           (now - first_start >= dev->vol_poll_interval)) {
619          Dmsg1(200, "In wait blocked=%s\n", edit_blocked_reason(dev));
620          dev->poll = true;            /* returning a poll event */
621          break;
622       }
623       /*
624        * Check if user mounted the device while we were waiting
625        */
626       if (dev->dev_blocked == BST_MOUNT) {   /* mount request ? */
627          stat = 0;
628          break;
629       }
630
631       add_wait = dev->wait_sec - (now - start);
632       if (add_wait < 0) {
633          add_wait = 0;
634       }
635       if (me->heartbeat_interval && add_wait > me->heartbeat_interval) {
636          add_wait = me->heartbeat_interval;
637       }
638       gettimeofday(&tv, &tz);
639       timeout.tv_nsec = tv.tv_usec * 1000;
640       timeout.tv_sec = tv.tv_sec + add_wait; /* additional wait */
641       Dmsg1(200, "Additional wait %d sec.\n", add_wait);
642    }
643
644    if (!unmounted) {
645       dev->dev_blocked = dev->dev_prev_blocked;    /* restore entry state */
646    }
647    V(dev->mutex);
648    return stat;
649 }