]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/dircmd.c
7f8bded3a107f95ac1ec7e581153d56677959719
[bacula/bacula] / bacula / src / stored / dircmd.c
1 /*
2    Bacula® - The Network Backup Solution
3
4    Copyright (C) 2001-2010 Free Software Foundation Europe e.V.
5
6    The main author of Bacula is Kern Sibbald, with contributions from
7    many others, a complete list can be found in the file AUTHORS.
8    This program is Free Software; you can redistribute it and/or
9    modify it under the terms of version three of the GNU Affero General Public
10    License as published by the Free Software Foundation and included
11    in the file LICENSE.
12
13    This program is distributed in the hope that it will be useful, but
14    WITHOUT ANY WARRANTY; without even the implied warranty of
15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
16    General Public License for more details.
17
18    You should have received a copy of the GNU Affero General Public License
19    along with this program; if not, write to the Free Software
20    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
21    02110-1301, USA.
22
23    Bacula® is a registered trademark of Kern Sibbald.
24    The licensor of Bacula is the Free Software Foundation Europe
25    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
26    Switzerland, email:ftf@fsfeurope.org.
27 */
28 /*
29  *  This file handles accepting Director Commands
30  *
31  *    Most Director commands are handled here, with the
32  *    exception of the Job command command and subsequent
33  *    subcommands that are handled
34  *    in job.c.
35  *
36  *    N.B. in this file, in general we must use P(dev->mutex) rather
37  *      than dev->r_lock() so that we can examine the blocked
38  *      state rather than blocking ourselves because a Job
39  *      thread has the device blocked. In some "safe" cases,
40  *      we can do things to a blocked device. CAREFUL!!!!
41  *
42  *    File daemon commands are handled in fdcmd.c
43  *
44  *     Kern Sibbald, May MMI
45  *
46  */
47
48 #include "bacula.h"
49 #include "stored.h"
50
51 /* Exported variables */
52
53 /* Imported variables */
54 extern BSOCK *filed_chan;
55 extern struct s_last_job last_job;
56 extern bool init_done;
57
58 /* Static variables */
59 static char derrmsg[]     = "3900 Invalid command:";
60 static char OKsetdebug[]  = "3000 OK setdebug=%d\n";
61 static char invalid_cmd[] = "3997 Invalid command for a Director with Monitor directive enabled.\n";
62 static char OK_bootstrap[]    = "3000 OK bootstrap\n";
63 static char ERROR_bootstrap[] = "3904 Error bootstrap\n";
64
65 /* Imported functions */
66 extern void terminate_child();
67 extern bool job_cmd(JCR *jcr);
68 extern bool use_cmd(JCR *jcr);
69 extern bool run_cmd(JCR *jcr);
70 extern bool status_cmd(JCR *sjcr);
71 extern bool qstatus_cmd(JCR *jcr);
72 //extern bool query_cmd(JCR *jcr);
73
74 /* Forward referenced functions */
75 static bool label_cmd(JCR *jcr);
76 static bool die_cmd(JCR *jcr);
77 static bool relabel_cmd(JCR *jcr);
78 static bool readlabel_cmd(JCR *jcr);
79 static bool release_cmd(JCR *jcr);
80 static bool setdebug_cmd(JCR *jcr);
81 static bool cancel_cmd(JCR *cjcr);
82 static bool mount_cmd(JCR *jcr);
83 static bool unmount_cmd(JCR *jcr);
84 //static bool action_on_purge_cmd(JCR *jcr);
85 static bool bootstrap_cmd(JCR *jcr);
86 static bool changer_cmd(JCR *sjcr);
87 static bool do_label(JCR *jcr, int relabel);
88 static DCR *find_device(JCR *jcr, POOL_MEM &dev_name, int drive);
89 static void read_volume_label(JCR *jcr, DCR *dcr, DEVICE *dev, int Slot);
90 static void label_volume_if_ok(DCR *dcr, char *oldname,
91                                char *newname, char *poolname,
92                                int Slot, int relabel);
93 static bool try_autoload_device(JCR *jcr, DCR *dcr, int slot, const char *VolName);
94 static void send_dir_busy_message(BSOCK *dir, DEVICE *dev);
95
96 struct s_cmds {
97    const char *cmd;
98    bool (*func)(JCR *jcr);
99    bool monitoraccess;                      /* set if monitors can access this cmd */
100 };
101
102 /*
103  * The following are the recognized commands from the Director.
104  */
105 static struct s_cmds cmds[] = {
106    {"JobId=",      job_cmd,         0},     /* start Job */
107    {"autochanger", changer_cmd,     0},
108    {"bootstrap",   bootstrap_cmd,   0},
109    {"cancel",      cancel_cmd,      0},
110    {".die",        die_cmd,         0},
111    {"label",       label_cmd,       0},     /* label a tape */
112    {"mount",       mount_cmd,       0},
113    {"readlabel",   readlabel_cmd,   0},
114    {"release",     release_cmd,     0},
115    {"relabel",     relabel_cmd,     0},     /* relabel a tape */
116    {"setdebug=",   setdebug_cmd,    0},     /* set debug level */
117    {"status",      status_cmd,      1},
118    {".status",     qstatus_cmd,     1},
119    {"unmount",     unmount_cmd,     0},
120 //   {"action_on_purge",  action_on_purge_cmd,    0},
121    {"use storage=", use_cmd,        0},
122    {"run",         run_cmd,         0},
123 // {"query",       query_cmd,       0},
124    {NULL,        NULL}                      /* list terminator */
125 };
126
127
128 /*
129  * Connection request. We accept connections either from the
130  *  Director or a Client (File daemon).
131  *
132  * Note, we are running as a seperate thread of the Storage daemon.
133  *  and it is because a Director has made a connection with
134  *  us on the "Message" channel.
135  *
136  * Basic tasks done here:
137  *  - Create a JCR record
138  *  - If it was from the FD, call handle_filed_connection()
139  *  - Authenticate the Director
140  *  - We wait for a command
141  *  - We execute the command
142  *  - We continue or exit depending on the return status
143  */
144 void *handle_connection_request(void *arg)
145 {
146    BSOCK *bs = (BSOCK *)arg;
147    JCR *jcr;
148    int i;
149    bool found, quit;
150    int bnet_stat = 0;
151    char name[500];
152    char tbuf[100];
153
154    if (bs->recv() <= 0) {
155       Emsg1(M_ERROR, 0, _("Connection request from %s failed.\n"), bs->who());
156       bs->close();
157       return NULL;
158    }
159
160    /*
161     * Do a sanity check on the message received
162     */
163    if (bs->msglen < 25 || bs->msglen > (int)sizeof(name)) {
164       Dmsg1(000, "<filed: %s", bs->msg);
165       Emsg2(M_ERROR, 0, _("Invalid connection from %s. Len=%d\n"), bs->who(), bs->msglen);
166       bs->close();
167       return NULL;
168    }
169    /*
170     * See if this is a File daemon connection. If so
171     *   call FD handler.
172     */
173    Dmsg1(110, "Conn: %s", bs->msg);
174    if (debug_level == 3) {
175       Dmsg1(000, "<filed: %s", bs->msg);
176    }
177    if (sscanf(bs->msg, "Hello Start Job %127s", name) == 1) {
178       Dmsg1(110, "Got a FD connection at %s\n", bstrftimes(tbuf, sizeof(tbuf), 
179             (utime_t)time(NULL)));
180       Dmsg1(50, "%s", bs->msg);
181       handle_filed_connection(bs, name);
182       return NULL;
183    }
184
185    /* 
186     * This is a connection from the Director, so setup a JCR 
187     */
188    Dmsg1(110, "Got a DIR connection at %s\n", bstrftimes(tbuf, sizeof(tbuf), 
189          (utime_t)time(NULL)));
190    jcr = new_jcr(sizeof(JCR), stored_free_jcr); /* create Job Control Record */
191    jcr->dir_bsock = bs;               /* save Director bsock */
192    jcr->dir_bsock->set_jcr(jcr);
193    jcr->dcrs = New(alist(10, not_owned_by_alist));
194    /* Initialize FD start condition variable */
195    int errstat = pthread_cond_init(&jcr->job_start_wait, NULL);
196    if (errstat != 0) {
197       berrno be;
198       Jmsg1(jcr, M_FATAL, 0, _("Unable to init job cond variable: ERR=%s\n"), be.bstrerror(errstat));
199       goto bail_out;
200    }
201
202    Dmsg0(1000, "stored in start_job\n");
203
204    /*
205     * Authenticate the Director
206     */
207    if (!authenticate_director(jcr)) {
208       Jmsg(jcr, M_FATAL, 0, _("Unable to authenticate Director\n"));
209       goto bail_out;
210    }
211    Dmsg0(90, "Message channel init completed.\n");
212
213    for (quit=false; !quit;) {
214       /* Read command */
215       if ((bnet_stat = bs->recv()) <= 0) {
216          break;               /* connection terminated */
217       }
218       Dmsg1(199, "<dird: %s\n", bs->msg);
219       /* Ensure that device initialization is complete */
220       while (!init_done) {
221          bmicrosleep(1, 0);
222       }
223       found = false;
224       for (i=0; cmds[i].cmd; i++) {
225         if (strncmp(cmds[i].cmd, bs->msg, strlen(cmds[i].cmd)) == 0) {
226            if ((!cmds[i].monitoraccess) && (jcr->director->monitor)) {
227               Dmsg1(100, "Command \"%s\" is invalid.\n", cmds[i].cmd);
228               bs->fsend(invalid_cmd);
229               bs->signal(BNET_EOD);
230               break;
231            }
232            Dmsg1(200, "Do command: %s\n", cmds[i].cmd);
233            if (!cmds[i].func(jcr)) { /* do command */
234               quit = true; /* error, get out */
235               Dmsg1(190, "Command %s requests quit\n", cmds[i].cmd);
236            }
237            found = true;             /* indicate command found */
238            break;
239         }
240       }
241       if (!found) {                   /* command not found */
242         POOL_MEM err_msg;
243         Mmsg(err_msg, "%s %s\n", derrmsg, bs->msg);
244         bs->fsend(err_msg.c_str());
245         break;
246       }
247    }
248 bail_out:
249    generate_daemon_event(jcr, "JobEnd");
250    dequeue_messages(jcr);             /* send any queued messages */
251    bs->signal(BNET_TERMINATE);
252    free_jcr(jcr);
253    return NULL;
254 }
255
256
257 /*
258  * Force SD to die, and hopefully dump itself.  Turned on only
259  *  in development version.
260  */
261 static bool die_cmd(JCR *jcr)
262 {
263 #ifdef DEVELOPER
264    JCR *djcr = NULL;
265    int a;
266    Pmsg0(000, "I have been requested to die ...");
267    a = djcr->JobId;   /* ref NULL pointer */
268 #endif
269    return 0;
270 }
271
272      
273
274 /*
275  * Set debug level as requested by the Director
276  *
277  */
278 static bool setdebug_cmd(JCR *jcr)
279 {
280    BSOCK *dir = jcr->dir_bsock;
281    int level, trace_flag;
282
283    Dmsg1(10, "setdebug_cmd: %s", dir->msg);
284    if (sscanf(dir->msg, "setdebug=%d trace=%d", &level, &trace_flag) != 2 || level < 0) {
285       dir->fsend(_("3991 Bad setdebug command: %s\n"), dir->msg);
286       return 0;
287    }
288    debug_level = level;
289    set_trace(trace_flag);
290    return dir->fsend(OKsetdebug, level);
291 }
292
293
294 /*
295  * Cancel a Job
296  */
297 static bool cancel_cmd(JCR *cjcr)
298 {
299    BSOCK *dir = cjcr->dir_bsock;
300    int oldStatus;
301    char Job[MAX_NAME_LENGTH];
302    JCR *jcr;
303
304    if (sscanf(dir->msg, "cancel Job=%127s", Job) == 1) {
305       if (!(jcr=get_jcr_by_full_name(Job))) {
306          dir->fsend(_("3904 Job %s not found.\n"), Job);
307       } else {
308          oldStatus = jcr->JobStatus;
309          set_jcr_job_status(jcr, JS_Canceled);
310          Dmsg2(800, "Cancel JobId=%d %p\n", jcr->JobId, jcr);
311          if (!jcr->authenticated && oldStatus == JS_WaitFD) {
312             pthread_cond_signal(&jcr->job_start_wait); /* wake waiting thread */
313          }
314          if (jcr->file_bsock) {
315             jcr->file_bsock->signal(BNET_TERMINATE);
316             jcr->file_bsock->set_terminated();
317             Dmsg2(800, "Term bsock jid=%d %p\n", jcr->JobId, jcr);
318          } else {
319             /* Still waiting for FD to connect, release it */
320             pthread_cond_signal(&jcr->job_start_wait); /* wake waiting job */
321             Dmsg2(800, "Signal FD connect jid=%d %p\n", jcr->JobId, jcr);
322          }
323          /* If thread waiting on mount, wake him */
324          if (jcr->dcr && jcr->dcr->dev && jcr->dcr->dev->waiting_for_mount()) {
325             pthread_cond_broadcast(&jcr->dcr->dev->wait_next_vol);
326             Dmsg1(100, "JobId=%u broadcast wait_device_release\n", (uint32_t)jcr->JobId);
327             pthread_cond_broadcast(&wait_device_release);
328          }
329          if (jcr->read_dcr && jcr->read_dcr->dev && jcr->read_dcr->dev->waiting_for_mount()) {
330             pthread_cond_broadcast(&jcr->read_dcr->dev->wait_next_vol);
331             Dmsg1(100, "JobId=%u broadcast wait_device_release\n", (uint32_t)jcr->JobId);
332             pthread_cond_broadcast(&wait_device_release);
333          }
334          Jmsg(jcr, M_INFO, 0, _("JobId=%d Job=\"%s\" marked to be canceled.\n"), 
335             (int)jcr->JobId, jcr->Job);
336          dir->fsend(_("3000 Job %s marked to be canceled.\n"), jcr->Job);
337          free_jcr(jcr);
338       }
339    } else {
340       dir->fsend(_("3903 Error scanning cancel command.\n"));
341    }
342    dir->signal(BNET_EOD);
343    return 1;
344 }
345
346 /*
347  * Label a Volume
348  *
349  */
350 static bool label_cmd(JCR *jcr)
351 {
352    return do_label(jcr, 0);
353 }
354
355 static bool relabel_cmd(JCR *jcr)
356 {
357    return do_label(jcr, 1);
358 }
359
360 static bool do_label(JCR *jcr, int relabel)
361 {
362    POOLMEM *newname, *oldname, *poolname, *mtype;
363    POOL_MEM dev_name;
364    BSOCK *dir = jcr->dir_bsock;
365    DCR *dcr;
366    DEVICE *dev;
367    bool ok = false;
368    int slot;
369    int drive;
370
371    newname = get_memory(dir->msglen+1);
372    oldname = get_memory(dir->msglen+1);
373    poolname = get_memory(dir->msglen+1);
374    mtype = get_memory(dir->msglen+1);
375    if (relabel) {
376       if (sscanf(dir->msg, "relabel %127s OldName=%127s NewName=%127s PoolName=%127s "
377                  "MediaType=%127s Slot=%d drive=%d",
378                   dev_name.c_str(), oldname, newname, poolname, mtype, 
379                   &slot, &drive) == 7) {
380          ok = true;
381       }
382    } else {
383       *oldname = 0;
384       if (sscanf(dir->msg, "label %127s VolumeName=%127s PoolName=%127s "
385                  "MediaType=%127s Slot=%d drive=%d", 
386           dev_name.c_str(), newname, poolname, mtype, &slot, &drive) == 6) {
387          ok = true;
388       }
389    }
390    if (ok) {
391       unbash_spaces(newname);
392       unbash_spaces(oldname);
393       unbash_spaces(poolname);
394       unbash_spaces(mtype);
395       dcr = find_device(jcr, dev_name, drive);
396       if (dcr) {
397          dev = dcr->dev;
398          dev->dlock();                 /* Use P to avoid indefinite block */
399          if (!dev->is_open() && !dev->is_busy()) {
400             Dmsg1(400, "Can %slabel. Device is not open\n", relabel?"re":"");
401             label_volume_if_ok(dcr, oldname, newname, poolname, slot, relabel);
402             dev->close();
403          /* Under certain "safe" conditions, we can steal the lock */
404          } else if (dev->can_steal_lock()) {
405             Dmsg0(400, "Can relabel. can_steal_lock\n");
406             label_volume_if_ok(dcr, oldname, newname, poolname, slot, relabel);
407          } else if (dev->is_busy() || dev->is_blocked()) {
408             send_dir_busy_message(dir, dev);
409          } else {                     /* device not being used */
410             Dmsg0(400, "Can relabel. device not used\n");
411             label_volume_if_ok(dcr, oldname, newname, poolname, slot, relabel);
412          }
413          dev->dunlock();
414          free_dcr(dcr);
415       } else {
416          dir->fsend(_("3999 Device \"%s\" not found or could not be opened.\n"), dev_name.c_str());
417       }
418    } else {
419       /* NB dir->msg gets clobbered in bnet_fsend, so save command */
420       pm_strcpy(jcr->errmsg, dir->msg);
421       dir->fsend(_("3903 Error scanning label command: %s\n"), jcr->errmsg);
422    }
423    free_memory(oldname);
424    free_memory(newname);
425    free_memory(poolname);
426    free_memory(mtype);
427    dir->signal(BNET_EOD);
428    return true;
429 }
430
431 /*
432  * Read the tape label and determine if we can safely
433  * label the tape (not a Bacula volume), then label it.
434  *
435  *  Enter with the mutex set
436  */
437 static void label_volume_if_ok(DCR *dcr, char *oldname,
438                                char *newname, char *poolname,
439                                int slot, int relabel)
440 {
441    BSOCK *dir = dcr->jcr->dir_bsock;
442    bsteal_lock_t hold;
443    DEVICE *dev = dcr->dev;
444    int label_status;
445    int mode;
446    const char *volname = (relabel == 1) ? oldname : newname;
447    char ed1[50];
448
449    steal_device_lock(dev, &hold, BST_WRITING_LABEL);
450    Dmsg1(100, "Stole device %s lock, writing label.\n", dev->print_name());
451
452
453    Dmsg0(90, "try_autoload_device - looking for volume_info\n");
454    if (!try_autoload_device(dcr->jcr, dcr, slot, volname)) {
455       goto bail_out;                  /* error */
456    }
457
458    /* Ensure that the device is open -- autoload_device() closes it */
459    if (dev->is_tape()) {
460       mode = OPEN_READ_WRITE;
461    } else {
462       mode = CREATE_READ_WRITE;
463    }
464
465    if (relabel) {
466       dev->truncating = true;         /* let open() know we will truncate it */
467    }
468    /* Set old volume name for open if relabeling */
469    dcr->setVolCatName(volname);
470    if (dev->open(dcr, mode) < 0) {
471       dir->fsend(_("3910 Unable to open device %s: ERR=%s\n"),
472          dev->print_name(), dev->bstrerror());
473       goto bail_out;      
474    }
475
476    /* See what we have for a Volume */
477    label_status = read_dev_volume_label(dcr);
478    
479    /* Set new volume name */
480    dcr->setVolCatName(newname);
481    switch(label_status) {
482    case VOL_NAME_ERROR:
483    case VOL_VERSION_ERROR:
484    case VOL_LABEL_ERROR:
485    case VOL_OK:
486       if (!relabel) {
487          dir->fsend(_(
488             "3920 Cannot label Volume because it is already labeled: \"%s\"\n"),
489              dev->VolHdr.VolumeName);
490          break;
491       }
492
493       /* Relabel request. If oldname matches, continue */
494       if (strcmp(oldname, dev->VolHdr.VolumeName) != 0) {
495          dir->fsend(_("3921 Wrong volume mounted.\n"));
496          break;
497       }
498       if (dev->label_type != B_BACULA_LABEL) {
499          dir->fsend(_("3922 Cannot relabel an ANSI/IBM labeled Volume.\n"));
500          break;
501       }
502       /* Fall through wanted! */
503    case VOL_IO_ERROR:
504    case VOL_NO_LABEL:
505       if (!write_new_volume_label_to_dev(dcr, newname, poolname, 
506            relabel, true /* write dvd now */)) {
507          dir->fsend(_("3912 Failed to label Volume: ERR=%s\n"), dev->bstrerror());
508          break;
509       }
510       bstrncpy(dcr->VolumeName, newname, sizeof(dcr->VolumeName));
511       /* The following 3000 OK label. string is scanned in ua_label.c */
512       dir->fsend("3000 OK label. VolBytes=%s DVD=%d Volume=\"%s\" Device=%s\n",
513                  edit_uint64(dev->VolCatInfo.VolCatBytes, ed1),
514                  dev->is_dvd()?1:0, newname, dev->print_name());
515       break;
516    case VOL_NO_MEDIA:
517       dir->fsend(_("3914 Failed to label Volume (no media): ERR=%s\n"), dev->bstrerror());
518       break;
519    default:
520       dir->fsend(_("3913 Cannot label Volume. "
521 "Unknown status %d from read_volume_label()\n"), label_status);
522       break;
523    }
524
525 bail_out:
526    if (!dev->is_open()) {
527       dev->clear_volhdr();
528    }
529    volume_unused(dcr);                   /* no longer using volume */
530    give_back_device_lock(dev, &hold);
531    return;
532 }
533
534
535 /*
536  * Read the tape label
537  *
538  *  Enter with the mutex set
539  */
540 static bool read_label(DCR *dcr)
541 {
542    int ok;
543    JCR *jcr = dcr->jcr;
544    BSOCK *dir = jcr->dir_bsock;
545    bsteal_lock_t hold;
546    DEVICE *dev = dcr->dev;
547
548    steal_device_lock(dev, &hold, BST_DOING_ACQUIRE);
549
550    dcr->VolumeName[0] = 0;
551    dev->clear_labeled();              /* force read of label */
552    switch (read_dev_volume_label(dcr)) {
553    case VOL_OK:
554       dir->fsend(_("3001 Mounted Volume: %s\n"), dev->VolHdr.VolumeName);
555       ok = true;
556       break;
557    default:
558       dir->fsend(_("3902 Cannot mount Volume on Storage Device %s because:\n%s"),
559          dev->print_name(), jcr->errmsg);
560       ok = false;
561       break;
562    }
563    volume_unused(dcr);
564    give_back_device_lock(dev, &hold);
565    return ok;
566 }
567
568 /* 
569  * Searches for device by name, and if found, creates a dcr and
570  *  returns it.
571  */
572 static DCR *find_device(JCR *jcr, POOL_MEM &devname, int drive)
573 {
574    DEVRES *device;
575    AUTOCHANGER *changer;
576    bool found = false;
577    DCR *dcr = NULL;
578
579    unbash_spaces(devname);
580    foreach_res(device, R_DEVICE) {
581       /* Find resource, and make sure we were able to open it */
582       if (strcmp(device->hdr.name, devname.c_str()) == 0) {
583          if (!device->dev) {
584             device->dev = init_dev(jcr, device);
585          }
586          if (!device->dev) {
587             Jmsg(jcr, M_WARNING, 0, _("\n"
588                "     Device \"%s\" requested by DIR could not be opened or does not exist.\n"),
589                  devname.c_str());
590             continue;
591          }
592          Dmsg1(20, "Found device %s\n", device->hdr.name);
593          found = true;
594          break;
595       }
596    }
597    if (!found) {
598       foreach_res(changer, R_AUTOCHANGER) {
599          /* Find resource, and make sure we were able to open it */
600          if (strcmp(devname.c_str(), changer->hdr.name) == 0) {
601             /* Try each device in this AutoChanger */
602             foreach_alist(device, changer->device) {
603                Dmsg1(100, "Try changer device %s\n", device->hdr.name);
604                if (!device->dev) {
605                   device->dev = init_dev(jcr, device);
606                }
607                if (!device->dev) {
608                   Dmsg1(100, "Device %s could not be opened. Skipped\n", devname.c_str());
609                   Jmsg(jcr, M_WARNING, 0, _("\n"
610                      "     Device \"%s\" in changer \"%s\" requested by DIR could not be opened or does not exist.\n"),
611                        device->hdr.name, devname.c_str());
612                   continue;
613                }
614                if (!device->dev->autoselect) {
615                   Dmsg1(100, "Device %s not autoselect skipped.\n", devname.c_str());
616                   continue;              /* device is not available */
617                }
618                if (drive < 0 || drive == (int)device->dev->drive_index) {
619                   Dmsg1(20, "Found changer device %s\n", device->hdr.name);
620                   found = true;
621                   break;
622                }
623                Dmsg3(100, "Device %s drive wrong: want=%d got=%d skipping\n",
624                   devname.c_str(), drive, (int)device->dev->drive_index);
625             }
626             break;                    /* we found it but could not open a device */
627          }
628       }
629    }
630
631    if (found) {
632       Dmsg1(100, "Found device %s\n", device->hdr.name);
633       dcr = new_dcr(jcr, NULL, device->dev);
634       dcr->device = device;
635    }
636    return dcr;
637 }
638
639
640 /*
641  * Mount command from Director
642  */
643 static bool mount_cmd(JCR *jcr)
644 {
645    POOL_MEM devname;
646    BSOCK *dir = jcr->dir_bsock;
647    DEVICE *dev;
648    DCR *dcr;
649    int drive;
650    int slot = 0;
651    bool ok;
652
653    ok = sscanf(dir->msg, "mount %127s drive=%d slot=%d", devname.c_str(), 
654                &drive, &slot) == 3;
655    if (!ok) {
656       ok = sscanf(dir->msg, "mount %127s drive=%d", devname.c_str(), &drive) == 2;
657    }
658    if (ok) {
659       dcr = find_device(jcr, devname, drive);
660       if (dcr) {
661          dev = dcr->dev;
662          dev->dlock();                 /* Use P to avoid indefinite block */
663          Dmsg2(100, "mount cmd blocked=%d must_unload=%d\n", dev->blocked(), 
664             dev->must_unload());
665          switch (dev->blocked()) {         /* device blocked? */
666          case BST_WAITING_FOR_SYSOP:
667             /* Someone is waiting, wake him */
668             Dmsg0(100, "Waiting for mount. Attempting to wake thread\n");
669             dev->set_blocked(BST_MOUNT);
670             dir->fsend("3001 OK mount requested. %sDevice=%s\n", 
671                        slot>0?_("Specified slot ignored. "):"",
672                        dev->print_name());
673             pthread_cond_broadcast(&dev->wait_next_vol);
674             Dmsg1(100, "JobId=%u broadcast wait_device_release\n", (uint32_t)dcr->jcr->JobId);
675             pthread_cond_broadcast(&wait_device_release);
676             break;
677
678          /* In both of these two cases, we (the user) unmounted the Volume */
679          case BST_UNMOUNTED_WAITING_FOR_SYSOP:
680          case BST_UNMOUNTED:
681             if (dev->is_autochanger() && slot > 0) {
682                try_autoload_device(jcr, dcr, slot, "");
683             }
684             /* We freed the device, so reopen it and wake any waiting threads */
685             if (dev->open(dcr, OPEN_READ_ONLY) < 0) {
686                dir->fsend(_("3901 Unable to open device %s: ERR=%s\n"),
687                   dev->print_name(), dev->bstrerror());
688                if (dev->blocked() == BST_UNMOUNTED) {
689                   /* We blocked the device, so unblock it */
690                   Dmsg0(100, "Unmounted. Unblocking device\n");
691                   unblock_device(dev);
692                }
693                break;
694             }
695             read_dev_volume_label(dcr);
696             if (dev->blocked() == BST_UNMOUNTED) {
697                /* We blocked the device, so unblock it */
698                Dmsg0(100, "Unmounted. Unblocking device\n");
699                read_label(dcr);       /* this should not be necessary */
700                unblock_device(dev);
701             } else {
702                Dmsg0(100, "Unmounted waiting for mount. Attempting to wake thread\n");
703                dev->set_blocked(BST_MOUNT);
704             }
705             if (dev->is_labeled()) {
706                dir->fsend(_("3001 Device %s is mounted with Volume \"%s\"\n"),
707                   dev->print_name(), dev->VolHdr.VolumeName);
708             } else {
709                dir->fsend(_("3905 Device %s open but no Bacula volume is mounted.\n"
710                                  "If this is not a blank tape, try unmounting and remounting the Volume.\n"),
711                           dev->print_name());
712             }
713             pthread_cond_broadcast(&dev->wait_next_vol);
714             Dmsg1(100, "JobId=%u broadcast wait_device_release\n", (uint32_t)dcr->jcr->JobId);
715             pthread_cond_broadcast(&wait_device_release);
716             break;
717
718          case BST_DOING_ACQUIRE:
719             dir->fsend(_("3001 Device %s is doing acquire.\n"),
720                        dev->print_name());
721             break;
722
723          case BST_WRITING_LABEL:
724             dir->fsend(_("3903 Device %s is being labeled.\n"), 
725                dev->print_name());
726             break;
727
728          case BST_NOT_BLOCKED:
729             if (dev->is_autochanger() && slot > 0) {
730                try_autoload_device(jcr, dcr, slot, "");
731             }
732             if (dev->is_open()) {
733                if (dev->is_labeled()) {
734                   dir->fsend(_("3001 Device %s is mounted with Volume \"%s\"\n"),
735                      dev->print_name(), dev->VolHdr.VolumeName);
736                } else {
737                   dir->fsend(_("3905 Device %s open but no Bacula volume is mounted.\n"
738                                  "If this is not a blank tape, try unmounting and remounting the Volume.\n"),
739                              dev->print_name());
740                }
741             } else if (dev->is_tape()) {
742                if (dev->open(dcr, OPEN_READ_ONLY) < 0) {
743                   dir->fsend(_("3901 Unable to open device %s: ERR=%s\n"),
744                      dev->print_name(), dev->bstrerror());
745                   break;
746                }
747                read_label(dcr);
748                if (dev->is_labeled()) {
749                   dir->fsend(_("3001 Device %s is already mounted with Volume \"%s\"\n"),
750                      dev->print_name(), dev->VolHdr.VolumeName);
751                } else {
752                   dir->fsend(_("3905 Device %s open but no Bacula volume is mounted.\n"
753                                     "If this is not a blank tape, try unmounting and remounting the Volume.\n"),
754                              dev->print_name());
755                }
756             } else if (dev->is_unmountable()) {
757                if (dev->mount(1)) {
758                   dir->fsend(_("3002 Device %s is mounted.\n"), 
759                      dev->print_name());
760                } else {
761                   dir->fsend(_("3907 %s"), dev->bstrerror());
762                } 
763             } else { /* must be file */
764                dir->fsend(_("3906 File device %s is always mounted.\n"),
765                   dev->print_name());
766                pthread_cond_broadcast(&dev->wait_next_vol);
767                Dmsg1(100, "JobId=%u broadcast wait_device_release\n", (uint32_t)dcr->jcr->JobId);
768                pthread_cond_broadcast(&wait_device_release);
769             }
770             break;
771
772          default:
773             dir->fsend(_("3905 Bizarre wait state %d\n"), dev->blocked());
774             break;
775          }
776          dev->dunlock();
777          free_dcr(dcr);
778       } else {
779          dir->fsend(_("3999 Device \"%s\" not found or could not be opened.\n"), devname.c_str());
780       }
781    } else {
782       pm_strcpy(jcr->errmsg, dir->msg);
783       dir->fsend(_("3909 Error scanning mount command: %s\n"), jcr->errmsg);
784    }
785    dir->signal(BNET_EOD);
786    return true;
787 }
788
789 /*
790  * unmount command from Director
791  */
792 static bool unmount_cmd(JCR *jcr)
793 {
794    POOL_MEM devname;
795    BSOCK *dir = jcr->dir_bsock;
796    DEVICE *dev;
797    DCR *dcr;
798    int drive;
799
800    if (sscanf(dir->msg, "unmount %127s drive=%d", devname.c_str(), &drive) == 2) {
801       dcr = find_device(jcr, devname, drive);
802       if (dcr) {
803          dev = dcr->dev;
804          dev->dlock();                 /* Use P to avoid indefinite block */
805          if (!dev->is_open()) {
806             if (!dev->is_busy()) {
807                unload_autochanger(dcr, -1);          
808             }
809             if (dev->is_unmountable()) {
810                if (dev->unmount(0)) {
811                   dir->fsend(_("3002 Device %s unmounted.\n"), 
812                      dev->print_name());
813                } else {
814                   dir->fsend(_("3907 %s"), dev->bstrerror());
815                } 
816             } else {
817                Dmsg0(90, "Device already unmounted\n");
818                dir->fsend(_("3901 Device %s is already unmounted.\n"), 
819                   dev->print_name());
820             }
821          } else if (dev->blocked() == BST_WAITING_FOR_SYSOP) {
822             Dmsg2(90, "%d waiter dev_block=%d. doing unmount\n", dev->num_waiting,
823                dev->blocked());
824             if (!unload_autochanger(dcr, -1)) {
825                /* ***FIXME**** what is this ????  */
826                dev->close();
827                free_volume(dev);
828             }
829             if (dev->is_unmountable() && !dev->unmount(0)) {
830                dir->fsend(_("3907 %s"), dev->bstrerror());
831             } else {
832                dev->set_blocked(BST_UNMOUNTED_WAITING_FOR_SYSOP);
833                dir->fsend(_("3001 Device %s unmounted.\n"), 
834                   dev->print_name());
835             }
836
837          } else if (dev->blocked() == BST_DOING_ACQUIRE) {
838             dir->fsend(_("3902 Device %s is busy in acquire.\n"), 
839                dev->print_name());
840
841          } else if (dev->blocked() == BST_WRITING_LABEL) {
842             dir->fsend(_("3903 Device %s is being labeled.\n"), 
843                dev->print_name());
844
845          } else if (dev->is_busy()) {
846             send_dir_busy_message(dir, dev);
847          } else {                     /* device not being used */
848             Dmsg0(90, "Device not in use, unmounting\n");
849             /* On FreeBSD, I am having ASSERT() failures in block_device()
850              * and I can only imagine that the thread id that we are
851              * leaving in no_wait_id is being re-used. So here,
852              * we simply do it by hand.  Gross, but a solution.
853              */
854             /*  block_device(dev, BST_UNMOUNTED); replace with 2 lines below */
855             dev->set_blocked(BST_UNMOUNTED);
856             clear_thread_id(dev->no_wait_id);
857             if (!unload_autochanger(dcr, -1)) {
858                dev->close();
859                free_volume(dev);
860             }
861             if (dev->is_unmountable() && !dev->unmount(0)) {
862                dir->fsend(_("3907 %s"), dev->bstrerror());
863             } else {
864                dir->fsend(_("3002 Device %s unmounted.\n"), 
865                   dev->print_name());
866             }
867          }
868          dev->dunlock();
869          free_dcr(dcr);
870       } else {
871          dir->fsend(_("3999 Device \"%s\" not found or could not be opened.\n"), devname.c_str());
872       }
873    } else {
874       /* NB dir->msg gets clobbered in bnet_fsend, so save command */
875       pm_strcpy(jcr->errmsg, dir->msg);
876       dir->fsend(_("3907 Error scanning unmount command: %s\n"), jcr->errmsg);
877    }
878    dir->signal(BNET_EOD);
879    return true;
880 }
881
882 #if 0
883 /*
884  * The truncate command will recycle a volume. The director can call this
885  * after purging a volume so that disk space will not be wasted. Only useful
886  * for File Storage, of course.
887  *
888  *
889  * It is currently disabled
890  */
891 static bool action_on_purge_cmd(JCR *jcr)
892 {
893    BSOCK *dir = jcr->dir_bsock;
894
895    char devname[MAX_NAME_LENGTH];
896    char volumename[MAX_NAME_LENGTH];
897    int action;
898
899    /* TODO: Need to find a free device and ask for slot to the director */
900    if (sscanf(dir->msg, 
901               "action_on_purge %127s vol=%127s action=%d",
902               devname, volumename, &action)!= 5) 
903    {
904       dir->fsend(_("3916 Error scanning action_on_purge command\n"));
905       goto done;
906    }
907    unbash_spaces(volumename);
908    unbash_spaces(devname);
909
910    /* Check if action is correct */
911    if (action & AOP_TRUNCTATE) {
912
913    } 
914    /* ... */
915
916 done:
917    dir->signal(BNET_EOD);
918    return true;
919 }
920 #endif
921
922 /*
923  * Release command from Director. This rewinds the device and if
924  *   configured does a offline and ensures that Bacula will
925  *   re-read the label of the tape before continuing. This gives
926  *   the operator the chance to change the tape anytime before the
927  *   next job starts.
928  */
929 static bool release_cmd(JCR *jcr)
930 {
931    POOL_MEM devname;
932    BSOCK *dir = jcr->dir_bsock;
933    DEVICE *dev;
934    DCR *dcr;
935    int drive;
936
937    if (sscanf(dir->msg, "release %127s drive=%d", devname.c_str(), &drive) == 2) {
938       dcr = find_device(jcr, devname, drive);
939       if (dcr) {
940          dev = dcr->dev;
941          dev->dlock();                 /* Use P to avoid indefinite block */
942          if (!dev->is_open()) {
943             if (!dev->is_busy()) {
944                unload_autochanger(dcr, -1);
945             }
946             Dmsg0(90, "Device already released\n");
947             dir->fsend(_("3921 Device %s already released.\n"), 
948                dev->print_name());
949
950          } else if (dev->blocked() == BST_WAITING_FOR_SYSOP) {
951             Dmsg2(90, "%d waiter dev_block=%d.\n", dev->num_waiting,
952                dev->blocked());
953             unload_autochanger(dcr, -1);
954             dir->fsend(_("3922 Device %s waiting for sysop.\n"), 
955                dev->print_name());
956
957          } else if (dev->blocked() == BST_UNMOUNTED_WAITING_FOR_SYSOP) {
958             Dmsg2(90, "%d waiter dev_block=%d. doing unmount\n", dev->num_waiting,
959                dev->blocked());
960             dir->fsend(_("3922 Device %s waiting for mount.\n"), 
961                dev->print_name());
962
963          } else if (dev->blocked() == BST_DOING_ACQUIRE) {
964             dir->fsend(_("3923 Device %s is busy in acquire.\n"), 
965                dev->print_name());
966
967          } else if (dev->blocked() == BST_WRITING_LABEL) {
968             dir->fsend(_("3914 Device %s is being labeled.\n"), 
969                dev->print_name());
970
971          } else if (dev->is_busy()) {
972             send_dir_busy_message(dir, dev);
973          } else {                     /* device not being used */
974             Dmsg0(90, "Device not in use, releasing\n");
975             dcr->release_volume();
976             dir->fsend(_("3022 Device %s released.\n"), 
977                dev->print_name());
978          }
979          dev->dunlock();
980          free_dcr(dcr);
981       } else {
982          dir->fsend(_("3999 Device \"%s\" not found or could not be opened.\n"), devname.c_str());
983       }
984    } else {
985       /* NB dir->msg gets clobbered in bnet_fsend, so save command */
986       pm_strcpy(jcr->errmsg, dir->msg);
987       dir->fsend(_("3927 Error scanning release command: %s\n"), jcr->errmsg);
988    }
989    dir->signal(BNET_EOD);
990    return true;
991 }
992
993 static pthread_mutex_t bsr_mutex = PTHREAD_MUTEX_INITIALIZER;
994 static uint32_t bsr_uniq = 0;
995
996 static bool get_bootstrap_file(JCR *jcr, BSOCK *sock)
997 {
998    POOLMEM *fname = get_pool_memory(PM_FNAME);
999    FILE *bs;
1000    bool ok = false;
1001
1002    if (jcr->RestoreBootstrap) {
1003       unlink(jcr->RestoreBootstrap);
1004       free_pool_memory(jcr->RestoreBootstrap);
1005    }
1006    P(bsr_mutex);
1007    bsr_uniq++;
1008    Mmsg(fname, "%s/%s.%s.%d.bootstrap", me->working_directory, me->hdr.name,
1009       jcr->Job, bsr_uniq);
1010    V(bsr_mutex);
1011    Dmsg1(400, "bootstrap=%s\n", fname);
1012    jcr->RestoreBootstrap = fname;
1013    bs = fopen(fname, "a+b");           /* create file */
1014    if (!bs) {
1015       berrno be;
1016       Jmsg(jcr, M_FATAL, 0, _("Could not create bootstrap file %s: ERR=%s\n"),
1017          jcr->RestoreBootstrap, be.bstrerror());
1018       goto bail_out;
1019    }
1020    Dmsg0(10, "=== Bootstrap file ===\n");
1021    while (sock->recv() >= 0) {
1022        Dmsg1(10, "%s", sock->msg);
1023        fputs(sock->msg, bs);
1024    }
1025    fclose(bs);
1026    Dmsg0(10, "=== end bootstrap file ===\n");
1027    jcr->bsr = parse_bsr(jcr, jcr->RestoreBootstrap);
1028    if (!jcr->bsr) {
1029       Jmsg(jcr, M_FATAL, 0, _("Error parsing bootstrap file.\n"));
1030       goto bail_out;
1031    }
1032    if (debug_level >= 10) {
1033       dump_bsr(jcr->bsr, true);
1034    }
1035    /* If we got a bootstrap, we are reading, so create read volume list */
1036    create_restore_volume_list(jcr);
1037    ok = true;
1038
1039 bail_out:
1040    unlink(jcr->RestoreBootstrap);
1041    free_pool_memory(jcr->RestoreBootstrap);
1042    jcr->RestoreBootstrap = NULL;
1043    if (!ok) {
1044       sock->fsend(ERROR_bootstrap);
1045       return false;
1046    }
1047    return sock->fsend(OK_bootstrap);
1048 }
1049
1050 static bool bootstrap_cmd(JCR *jcr)
1051 {
1052    return get_bootstrap_file(jcr, jcr->dir_bsock);
1053 }
1054
1055 /*
1056  * Autochanger command from Director
1057  */
1058 static bool changer_cmd(JCR *jcr)
1059 {
1060    POOL_MEM devname;
1061    BSOCK *dir = jcr->dir_bsock;
1062    DEVICE *dev;
1063    DCR *dcr;
1064    const char *cmd = NULL;
1065    bool ok = false;
1066    /*
1067     * A safe_cmd may call autochanger script but does not load/unload
1068     *    slots so it can be done at the same time that the drive is open.
1069     */
1070    bool safe_cmd = false;
1071
1072    if (sscanf(dir->msg, "autochanger listall %127s", devname.c_str()) == 1) {
1073       cmd = "listall";
1074       safe_cmd = ok = true;
1075    } else if (sscanf(dir->msg, "autochanger list %127s", devname.c_str()) == 1) {
1076       cmd = "list";
1077       safe_cmd = ok = true;
1078    } else if (sscanf(dir->msg, "autochanger slots %127s", devname.c_str()) == 1) {
1079       cmd = "slots";
1080       safe_cmd = ok = true;
1081    } else if (sscanf(dir->msg, "autochanger drives %127s", devname.c_str()) == 1) {
1082       cmd = "drives";
1083       safe_cmd = ok = true;
1084    }
1085    if (ok) {
1086       dcr = find_device(jcr, devname, -1);
1087       if (dcr) {
1088          dev = dcr->dev;
1089          dev->dlock();                 /* Use P to avoid indefinite block */
1090          if (!dev->device->changer_res) {
1091             dir->fsend(_("3995 Device %s is not an autochanger.\n"), 
1092                dev->print_name());
1093          /* Under certain "safe" conditions, we can steal the lock */
1094          } else if (safe_cmd || !dev->is_open() || dev->can_steal_lock()) {
1095             autochanger_cmd(dcr, dir, cmd);
1096          } else if (dev->is_busy() || dev->is_blocked()) {
1097             send_dir_busy_message(dir, dev);
1098          } else {                     /* device not being used */
1099             autochanger_cmd(dcr, dir, cmd);
1100          }
1101          dev->dunlock();
1102          free_dcr(dcr);
1103       } else {
1104          dir->fsend(_("3999 Device \"%s\" not found or could not be opened.\n"), devname.c_str());
1105       }
1106    } else {  /* error on scanf */
1107       pm_strcpy(jcr->errmsg, dir->msg);
1108       dir->fsend(_("3908 Error scanning autocharger drives/list/slots command: %s\n"),
1109          jcr->errmsg);
1110    }
1111    dir->signal(BNET_EOD);
1112    return true;
1113 }
1114
1115 /*
1116  * Read and return the Volume label
1117  */
1118 static bool readlabel_cmd(JCR *jcr)
1119 {
1120    POOL_MEM devname;
1121    BSOCK *dir = jcr->dir_bsock;
1122    DEVICE *dev;
1123    DCR *dcr;
1124    int Slot;
1125    int drive;
1126
1127    if (sscanf(dir->msg, "readlabel %127s Slot=%d drive=%d", devname.c_str(), 
1128        &Slot, &drive) == 3) {
1129       dcr = find_device(jcr, devname, drive);
1130       if (dcr) {
1131          dev = dcr->dev;
1132          dev->dlock();                 /* Use P to avoid indefinite block */
1133          if (!dev->is_open()) {
1134             read_volume_label(jcr, dcr, dev, Slot);
1135             dev->close();
1136          /* Under certain "safe" conditions, we can steal the lock */
1137          } else if (dev->can_steal_lock()) {
1138             read_volume_label(jcr, dcr, dev, Slot);
1139          } else if (dev->is_busy() || dev->is_blocked()) {
1140             send_dir_busy_message(dir, dev);
1141          } else {                     /* device not being used */
1142             read_volume_label(jcr, dcr, dev, Slot);
1143          }
1144          dev->dunlock();
1145          free_dcr(dcr);
1146       } else {
1147          dir->fsend(_("3999 Device \"%s\" not found or could not be opened.\n"), devname.c_str());
1148       }
1149    } else {
1150       pm_strcpy(jcr->errmsg, dir->msg);
1151       dir->fsend(_("3909 Error scanning readlabel command: %s\n"), jcr->errmsg);
1152    }
1153    dir->signal(BNET_EOD);
1154    return true;
1155 }
1156
1157
1158 /*
1159  * Read the tape label
1160  *
1161  *  Enter with the mutex set
1162  */
1163 static void read_volume_label(JCR *jcr, DCR *dcr, DEVICE *dev, int Slot)
1164 {
1165    BSOCK *dir = jcr->dir_bsock;
1166    bsteal_lock_t hold;
1167
1168    dcr->dev = dev;
1169    steal_device_lock(dev, &hold, BST_WRITING_LABEL);
1170
1171    if (!try_autoload_device(jcr, dcr, Slot, "")) {
1172       goto bail_out;                  /* error */
1173    }
1174
1175    dev->clear_labeled();              /* force read of label */
1176    switch (read_dev_volume_label(dcr)) {
1177    case VOL_OK:
1178       /* DO NOT add quotes around the Volume name. It is scanned in the DIR */
1179       dir->fsend(_("3001 Volume=%s Slot=%d\n"), dev->VolHdr.VolumeName, Slot);
1180       Dmsg1(100, "Volume: %s\n", dev->VolHdr.VolumeName);
1181       break;
1182    default:
1183       dir->fsend(_("3902 Cannot mount Volume on Storage Device %s because:\n%s"),
1184                  dev->print_name(), jcr->errmsg);
1185       break;
1186    }
1187
1188 bail_out:
1189    give_back_device_lock(dev, &hold);
1190    return;
1191 }
1192
1193 static bool try_autoload_device(JCR *jcr, DCR *dcr, int slot, const char *VolName)
1194 {
1195    BSOCK *dir = jcr->dir_bsock;
1196
1197    bstrncpy(dcr->VolumeName, VolName, sizeof(dcr->VolumeName));
1198    dcr->VolCatInfo.Slot = slot;
1199    dcr->VolCatInfo.InChanger = slot > 0;
1200    if (autoload_device(dcr, 0, dir) < 0) {    /* autoload if possible */
1201       return false;
1202    }
1203    return true;
1204 }
1205
1206 static void send_dir_busy_message(BSOCK *dir, DEVICE *dev)
1207 {
1208    if (dev->is_blocked()) {
1209       switch (dev->blocked()) {
1210       case BST_UNMOUNTED:
1211          dir->fsend(_("3931 Device %s is BLOCKED. user unmounted.\n"),
1212             dev->print_name());
1213          break;
1214       case BST_UNMOUNTED_WAITING_FOR_SYSOP:
1215          dir->fsend(_("3932 Device %s is BLOCKED. user unmounted during wait for media/mount.\n"),
1216              dev->print_name());
1217          break;
1218       case BST_WAITING_FOR_SYSOP:
1219          dir->fsend(_("3933 Device %s is BLOCKED waiting for media.\n"),
1220             dev->print_name());
1221          break;
1222       case BST_DOING_ACQUIRE:
1223          dir->fsend(_("3934 Device %s is being initialized.\n"),
1224             dev->print_name());
1225          break;
1226       case BST_WRITING_LABEL:
1227          dir->fsend(_("3935 Device %s is blocked labeling a Volume.\n"),
1228             dev->print_name());
1229          break;
1230       default:
1231          dir->fsend(_("3935 Device %s is blocked for unknown reason.\n"),
1232             dev->print_name());
1233          break;
1234       }
1235    } else if (dev->can_read()) {
1236        dir->fsend(_("3936 Device %s is busy reading.\n"),
1237                    dev->print_name());;
1238    } else {
1239        dir->fsend(_("3937 Device %s is busy with %d writer(s).\n"),
1240           dev->print_name(), dev->num_writers);
1241    }
1242 }