]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
kes Make find with no args in tree restore return error rather than
[bacula/bacula] / bacula / src / stored / block.c
1 /*
2  *
3  *   block.c -- tape block handling functions
4  *
5  *              Kern Sibbald, March MMI
6  *                 added BB02 format October MMII
7  *
8  *   Version $Id$
9  *
10  */
11 /*
12    Copyright (C) 2001-2006 Kern Sibbald
13
14    This program is free software; you can redistribute it and/or
15    modify it under the terms of the GNU General Public License
16    version 2 as amended with additional clauses defined in the
17    file LICENSE in the main source directory.
18
19    This program is distributed in the hope that it will be useful,
20    but WITHOUT ANY WARRANTY; without even the implied warranty of
21    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 
22    the file LICENSE for additional details.
23
24  */
25
26
27 #include "bacula.h"
28 #include "stored.h"
29
30 static bool terminate_writing_volume(DCR *dcr);
31 static bool do_new_file_bookkeeping(DCR *dcr);
32 static bool do_dvd_size_checks(DCR *dcr);
33 static void reread_last_block(DCR *dcr);
34
35 /*
36  * Dump the block header, then walk through
37  * the block printing out the record headers.
38  */
39 void dump_block(DEV_BLOCK *b, const char *msg)
40 {
41    ser_declare;
42    char *p;
43    char Id[BLKHDR_ID_LENGTH+1];
44    uint32_t CheckSum, BlockCheckSum;
45    uint32_t block_len;
46    uint32_t BlockNumber;
47    uint32_t VolSessionId, VolSessionTime, data_len;
48    int32_t  FileIndex;
49    int32_t  Stream;
50    int bhl, rhl;
51    char buf1[100], buf2[100];
52
53    unser_begin(b->buf, BLKHDR1_LENGTH);
54    unser_uint32(CheckSum);
55    unser_uint32(block_len);
56    unser_uint32(BlockNumber);
57    unser_bytes(Id, BLKHDR_ID_LENGTH);
58    ASSERT(unser_length(b->buf) == BLKHDR1_LENGTH);
59    Id[BLKHDR_ID_LENGTH] = 0;
60    if (Id[3] == '2') {
61       unser_uint32(VolSessionId);
62       unser_uint32(VolSessionTime);
63       bhl = BLKHDR2_LENGTH;
64       rhl = RECHDR2_LENGTH;
65    } else {
66       VolSessionId = VolSessionTime = 0;
67       bhl = BLKHDR1_LENGTH;
68       rhl = RECHDR1_LENGTH;
69    }
70
71    if (block_len > 100000) {
72       Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len);
73       return;
74    }
75
76    BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
77                          block_len-BLKHDR_CS_LENGTH);
78    Pmsg6(000, _("Dump block %s %x: size=%d BlkNum=%d\n"
79 "               Hdrcksum=%x cksum=%x\n"),
80       msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
81    p = b->buf + bhl;
82    while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) {
83       unser_begin(p, WRITE_RECHDR_LENGTH);
84       if (rhl == RECHDR1_LENGTH) {
85          unser_uint32(VolSessionId);
86          unser_uint32(VolSessionTime);
87       }
88       unser_int32(FileIndex);
89       unser_int32(Stream);
90       unser_uint32(data_len);
91       Pmsg6(000, _("   Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n"),
92            VolSessionId, VolSessionTime, FI_to_ascii(buf1, FileIndex),
93            stream_to_ascii(buf2, Stream, FileIndex), data_len, p);
94       p += data_len + rhl;
95   }
96 }
97
98 /*
99  * Create a new block structure.
100  * We pass device so that the block can inherit the
101  * min and max block sizes.
102  */
103 DEV_BLOCK *new_block(DEVICE *dev)
104 {
105    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
106
107    memset(block, 0, sizeof(DEV_BLOCK));
108
109    /* If the user has specified a max_block_size, use it as the default */
110    if (dev->max_block_size == 0) {
111       block->buf_len = DEFAULT_BLOCK_SIZE;
112    } else {
113       block->buf_len = dev->max_block_size;
114    }
115    block->dev = dev;
116    block->block_len = block->buf_len;  /* default block size */
117    block->buf = get_memory(block->buf_len);
118    empty_block(block);
119    block->BlockVer = BLOCK_VER;       /* default write version */
120    Dmsg1(650, "Returning new block=%x\n", block);
121    return block;
122 }
123
124
125 /*
126  * Duplicate an existing block (eblock)
127  */
128 DEV_BLOCK *dup_block(DEV_BLOCK *eblock)
129 {
130    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
131    int buf_len = sizeof_pool_memory(eblock->buf);
132
133    memcpy(block, eblock, sizeof(DEV_BLOCK));
134    block->buf = get_memory(buf_len);
135    memcpy(block->buf, eblock->buf, buf_len);
136    return block;
137 }
138
139
140 /*
141  * Only the first block checksum error was reported.
142  *   If there are more, report it now.
143  */
144 void print_block_read_errors(JCR *jcr, DEV_BLOCK *block)
145 {
146    if (block->read_errors > 1) {
147       Jmsg(jcr, M_ERROR, 0, _("%d block read errors not printed.\n"),
148          block->read_errors);
149    }
150 }
151
152 /*
153  * Free block
154  */
155 void free_block(DEV_BLOCK *block)
156 {
157    Dmsg1(999, "free_block buffer %x\n", block->buf);
158    free_memory(block->buf);
159    Dmsg1(999, "free_block block %x\n", block);
160    free_memory((POOLMEM *)block);
161 }
162
163 /* Empty the block -- for writing */
164 void empty_block(DEV_BLOCK *block)
165 {
166    block->binbuf = WRITE_BLKHDR_LENGTH;
167    block->bufp = block->buf + block->binbuf;
168    block->read_len = 0;
169    block->write_failed = false;
170    block->block_read = false;
171    block->FirstIndex = block->LastIndex = 0;
172 }
173
174 /*
175  * Create block header just before write. The space
176  * in the buffer should have already been reserved by
177  * init_block.
178  */
179 void ser_block_header(DEV_BLOCK *block)
180 {
181    ser_declare;
182    uint32_t CheckSum = 0;
183    uint32_t block_len = block->binbuf;
184
185    Dmsg1(1390, "ser_block_header: block_len=%d\n", block_len);
186    ser_begin(block->buf, BLKHDR2_LENGTH);
187    ser_uint32(CheckSum);
188    ser_uint32(block_len);
189    ser_uint32(block->BlockNumber);
190    ser_bytes(WRITE_BLKHDR_ID, BLKHDR_ID_LENGTH);
191    if (BLOCK_VER >= 2) {
192       ser_uint32(block->VolSessionId);
193       ser_uint32(block->VolSessionTime);
194    }
195
196    /* Checksum whole block except for the checksum */
197    CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
198                  block_len-BLKHDR_CS_LENGTH);
199    Dmsg1(1390, "ser_bloc_header: checksum=%x\n", CheckSum);
200    ser_begin(block->buf, BLKHDR2_LENGTH);
201    ser_uint32(CheckSum);              /* now add checksum to block header */
202 }
203
204 /*
205  * Unserialize the block header for reading block.
206  *  This includes setting all the buffer pointers correctly.
207  *
208  *  Returns: false on failure (not a block)
209  *           true  on success
210  */
211 static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
212 {
213    ser_declare;
214    char Id[BLKHDR_ID_LENGTH+1];
215    uint32_t CheckSum, BlockCheckSum;
216    uint32_t block_len;
217    uint32_t block_end;
218    uint32_t BlockNumber;
219    int bhl;
220
221    unser_begin(block->buf, BLKHDR_LENGTH);
222    unser_uint32(CheckSum);
223    unser_uint32(block_len);
224    unser_uint32(BlockNumber);
225    unser_bytes(Id, BLKHDR_ID_LENGTH);
226    ASSERT(unser_length(block->buf) == BLKHDR1_LENGTH);
227
228    Id[BLKHDR_ID_LENGTH] = 0;
229    if (Id[3] == '1') {
230       bhl = BLKHDR1_LENGTH;
231       block->BlockVer = 1;
232       block->bufp = block->buf + bhl;
233       if (strncmp(Id, BLKHDR1_ID, BLKHDR_ID_LENGTH) != 0) {
234          dev->dev_errno = EIO;
235          Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
236             dev->file, dev->block_num, BLKHDR1_ID, Id);
237          if (block->read_errors == 0 || verbose >= 2) {
238             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
239          }
240          block->read_errors++;
241          return false;
242       }
243    } else if (Id[3] == '2') {
244       unser_uint32(block->VolSessionId);
245       unser_uint32(block->VolSessionTime);
246       bhl = BLKHDR2_LENGTH;
247       block->BlockVer = 2;
248       block->bufp = block->buf + bhl;
249       if (strncmp(Id, BLKHDR2_ID, BLKHDR_ID_LENGTH) != 0) {
250          dev->dev_errno = EIO;
251          Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
252             dev->file, dev->block_num, BLKHDR2_ID, Id);
253          if (block->read_errors == 0 || verbose >= 2) {
254             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
255          }
256          block->read_errors++;
257          return false;
258       }
259    } else {
260       dev->dev_errno = EIO;
261       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
262           dev->file, dev->block_num, BLKHDR2_ID, Id);
263       if (block->read_errors == 0 || verbose >= 2) {
264          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
265       }
266       block->read_errors++;
267       unser_uint32(block->VolSessionId);
268       unser_uint32(block->VolSessionTime);
269       return false;
270    }
271
272    /* Sanity check */
273    if (block_len > MAX_BLOCK_LENGTH) {
274       dev->dev_errno = EIO;
275       Mmsg3(dev->errmsg,  _("Volume data error at %u:%u! Block length %u is insane (too large), probably due to a bad archive.\n"),
276          dev->file, dev->block_num, block_len);
277       if (block->read_errors == 0 || verbose >= 2) {
278          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
279       }
280       block->read_errors++;
281       return false;
282    }
283
284    Dmsg1(390, "unser_block_header block_len=%d\n", block_len);
285    /* Find end of block or end of buffer whichever is smaller */
286    if (block_len > block->read_len) {
287       block_end = block->read_len;
288    } else {
289       block_end = block_len;
290    }
291    block->binbuf = block_end - bhl;
292    block->block_len = block_len;
293    block->BlockNumber = BlockNumber;
294    Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
295       bhl, block_len);
296    if (block_len <= block->read_len) {
297       BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
298                          block_len-BLKHDR_CS_LENGTH);
299       if (BlockCheckSum != CheckSum) {
300          dev->dev_errno = EIO;
301          Mmsg6(dev->errmsg, _("Volume data error at %u:%u!\n" 
302             "Block checksum mismatch in block=%u len=%d: calc=%x blk=%x\n"),
303             dev->file, dev->block_num, (unsigned)BlockNumber, 
304             block_len, BlockCheckSum, CheckSum);
305          if (block->read_errors == 0 || verbose >= 2) {
306             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
307          }
308          block->read_errors++;
309          if (!forge_on) {
310             return false;
311          }
312       }
313    }
314    return true;
315 }
316
317 /*
318  * Write a block to the device, with locking and unlocking
319  *
320  * Returns: true  on success
321  *        : false on failure
322  *
323  */
324 bool write_block_to_device(DCR *dcr)
325 {
326    bool stat = true;
327    DEVICE *dev = dcr->dev;
328    JCR *jcr = dcr->jcr;
329
330    if (dcr->spooling) {
331       stat = write_block_to_spool_file(dcr);
332       return stat;
333    }
334
335    if (!dcr->dev_locked) {
336       lock_device(dev);
337    }
338
339    /*
340     * If a new volume has been mounted since our last write
341     *   Create a JobMedia record for the previous volume written,
342     *   and set new parameters to write this volume
343     * The same applies for if we are in a new file.
344     */
345    if (dcr->NewVol || dcr->NewFile) {
346       if (job_canceled(jcr)) {
347          stat = false;
348          goto bail_out;
349       }
350       /* Create a jobmedia record for this job */
351       if (!dir_create_jobmedia_record(dcr)) {
352          dev->dev_errno = EIO;
353          Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
354             dcr->VolCatInfo.VolCatName, jcr->Job);
355          set_new_volume_parameters(dcr);
356          stat = false;
357          goto bail_out;
358       }
359       if (dcr->NewVol) {
360          /* Note, setting a new volume also handles any pending new file */
361          set_new_volume_parameters(dcr);
362          dcr->NewFile = false;        /* this handled for new file too */
363       } else {
364          set_new_file_parameters(dcr);
365       }
366    }
367
368    if (!write_block_to_dev(dcr)) {
369        if (job_canceled(jcr) || jcr->JobType == JT_SYSTEM) {
370           stat = false;
371        } else {
372           stat = fixup_device_block_write_error(dcr);
373        }
374    }
375
376 bail_out:
377    if (!dcr->dev_locked) {
378       unlock_device(dev);
379    }
380    return stat;
381 }
382
383 /*
384  * Write a block to the device
385  *
386  *  Returns: true  on success or EOT
387  *           false on hard error
388  */
389 bool write_block_to_dev(DCR *dcr)
390 {
391    ssize_t stat = 0;
392    uint32_t wlen;                     /* length to write */
393    int hit_max1, hit_max2;
394    bool ok = true;
395    DEVICE *dev = dcr->dev;
396    JCR *jcr = dcr->jcr;
397    DEV_BLOCK *block = dcr->block;
398
399 #ifdef NO_TAPE_WRITE_TEST
400    empty_block(block);
401    return true;
402 #endif
403    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
404
405    /* dump_block(block, "before write"); */
406    if (dev->at_weot()) {
407       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
408       dev->dev_errno = ENOSPC;
409       Jmsg(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
410       return false;
411    }
412    if (!dev->can_append()) {
413       dev->dev_errno = EIO;
414       Jmsg(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume.\n"));
415       return false;
416    }
417    wlen = block->binbuf;
418    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
419       Dmsg0(100, "return write_block_to_dev no data to write\n");
420       return true;
421    }
422    /*
423     * Clear to the end of the buffer if it is not full,
424     *  and on tape devices, apply min and fixed blocking.
425     */
426    if (wlen != block->buf_len) {
427       uint32_t blen;                  /* current buffer length */
428
429       Dmsg2(200, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
430       blen = wlen;
431
432       /* Adjust write size to min/max for tapes only */
433       if (dev->is_tape()) {
434          /* check for fixed block size */
435          if (dev->min_block_size == dev->max_block_size) {
436             wlen = block->buf_len;    /* fixed block size already rounded */
437          /* Check for min block size */
438          } else if (wlen < dev->min_block_size) {
439             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
440          /* Ensure size is rounded */
441          } else {
442             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
443          }
444       }
445       if (wlen-blen > 0) {
446          memset(block->bufp, 0, wlen-blen); /* clear garbage */
447       }
448    }
449
450    ser_block_header(block);
451
452    /* Limit maximum Volume size to value specified by user */
453    hit_max1 = (dev->max_volume_size > 0) &&
454        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
455    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
456        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
457    if (hit_max1 || hit_max2) {
458       char ed1[50];
459       uint64_t max_cap;
460       Dmsg0(10, "==== Output bytes Triggered medium max capacity.\n");
461       if (hit_max1) {
462          max_cap = dev->max_volume_size;
463       } else {
464          max_cap = dev->VolCatInfo.VolCatMaxBytes;
465       }
466       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
467             edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
468       terminate_writing_volume(dcr);
469       reread_last_block(dcr);   /* DEBUG */
470       dev->dev_errno = ENOSPC;
471       return false;
472    }
473
474    /* Limit maximum File size on volume to user specified value */
475    if ((dev->max_file_size > 0) &&
476        (dev->file_size+block->binbuf) >= dev->max_file_size) {
477       dev->file_size = 0;             /* reset file size */
478
479       if (!dev->weof(1)) {            /* write eof */
480          Dmsg0(190, "WEOF error in max file size.\n");
481          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
482             dev->bstrerror());
483          terminate_writing_volume(dcr);
484          dev->dev_errno = ENOSPC;
485          return false;
486       }
487       if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
488          return false;
489       }
490
491       if (!do_new_file_bookkeeping(dcr)) {
492          /* Error message already sent */
493          return false;
494       }
495    }
496    
497    if (!do_dvd_size_checks(dcr)) {
498       /* Error message already sent */
499       return false;
500    }
501
502    dev->VolCatInfo.VolCatWrites++;
503    Dmsg1(1300, "Write block of %u bytes\n", wlen);
504 #ifdef DEBUG_BLOCK_ZEROING
505    uint32_t *bp = (uint32_t *)block->buf;
506    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
507       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
508    }
509 #endif
510
511    /*
512     * Do write here, make a somewhat feeble attempt to recover from 
513     *  I/O errors, or from the OS telling us it is busy.
514     */ 
515    int retry = 0;
516    do {
517       if (dev->is_tape()) {
518          stat = tape_write(dev->fd, block->buf, (size_t)wlen);
519       } else {
520          stat = write(dev->fd, block->buf, (size_t)wlen);
521       }
522       if (retry > 10) {
523          bmicrosleep(0, 100000);    /* pause a bit if lots of errors */
524       }
525    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 30);
526
527 #ifdef DEBUG_BLOCK_ZEROING
528    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
529       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
530    }
531 #endif
532
533    if (stat != (ssize_t)wlen) {
534       /* Some devices simply report EIO when the volume is full.
535        * With a little more thought we may be able to check
536        * capacity and distinguish real errors and EOT
537        * conditions.  In any case, we probably want to
538        * simulate an End of Medium.
539        */
540       if (stat == -1) {
541          berrno be;
542          dev->clrerror(-1);
543          if (dev->dev_errno == 0) {
544             dev->dev_errno = ENOSPC;        /* out of space */
545          }
546          if (dev->dev_errno != ENOSPC) {
547             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
548                dev->file, dev->block_num, dev->print_name(), be.strerror());
549          }
550       } else {
551         dev->dev_errno = ENOSPC;            /* out of space */
552       }
553       if (dev->dev_errno == ENOSPC) {
554          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
555             dev->VolCatInfo.VolCatName,
556             dev->file, dev->block_num, dev->print_name(), wlen, stat);
557       }
558       Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
559          dev->fd, wlen, stat, dev->block_num, block->BlockNumber, 
560          dev->dev_errno, strerror(dev->dev_errno));
561
562       ok = terminate_writing_volume(dcr);
563       if (!ok && !forge_on) {
564          return false;
565       }
566       if (ok) {
567          reread_last_block(dcr);
568       }
569       return false;
570    }
571
572    /* We successfully wrote the block, now do housekeeping */
573
574    dev->VolCatInfo.VolCatBytes += block->binbuf;
575    dev->VolCatInfo.VolCatBlocks++;
576    dev->EndBlock = dev->block_num;
577    dev->EndFile  = dev->file;
578    block->BlockNumber++;
579
580    /* Update dcr values */
581    if (dev->is_tape()) {
582       dcr->EndBlock = dev->EndBlock;
583       dcr->EndFile  = dev->EndFile;
584       dev->block_num++;
585    } else {
586       /* Save address of block just written */
587       uint64_t addr = dev->file_addr + wlen - 1;
588       dcr->EndBlock = (uint32_t)addr;
589       dcr->EndFile = (uint32_t)(addr >> 32);
590       dev->block_num = dcr->EndBlock;
591       dev->file = dcr->EndFile;
592    }
593    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
594       dcr->VolFirstIndex = block->FirstIndex;
595    }
596    if (block->LastIndex > 0) {
597       dcr->VolLastIndex = block->LastIndex;
598    }
599    dcr->WroteVol = true;
600    dev->file_addr += wlen;            /* update file address */
601    dev->file_size += wlen;
602    dev->part_size += wlen;
603
604    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
605    empty_block(block);
606    return true;
607 }
608
609 static void reread_last_block(DCR *dcr)
610 {
611 #define CHECK_LAST_BLOCK
612 #ifdef  CHECK_LAST_BLOCK
613    bool ok = true;
614    DEVICE *dev = dcr->dev;
615    JCR *jcr = dcr->jcr;
616    DEV_BLOCK *block = dcr->block;
617    /*
618     * If the device is a tape and it supports backspace record,
619     *   we backspace over one or two eof marks depending on
620     *   how many we just wrote, then over the last record,
621     *   then re-read it and verify that the block number is
622     *   correct.
623     */
624    if (dev->is_tape() && dev_cap(dev, CAP_BSR)) {
625       /* Now back up over what we wrote and read the last block */
626       if (!dev->bsf(1)) {
627          berrno be;
628          ok = false;
629          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
630               be.strerror(dev->dev_errno));
631       }
632       if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
633          berrno be;
634          ok = false;
635          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
636               be.strerror(dev->dev_errno));
637       }
638       /* Backspace over record */
639       if (ok && !dev->bsr(1)) {
640          berrno be;
641          ok = false;
642          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
643               be.strerror(dev->dev_errno));
644          /*
645           *  On FreeBSD systems, if the user got here, it is likely that his/her
646           *    tape drive is "frozen".  The correct thing to do is a
647           *    rewind(), but if we do that, higher levels in cleaning up, will
648           *    most likely write the EOS record over the beginning of the
649           *    tape.  The rewind *is* done later in mount.c when another
650           *    tape is requested. Note, the clrerror_dev() call in bsr()
651           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
652           */
653       }
654       if (ok) {
655          DEV_BLOCK *lblock = new_block(dev);
656          /* Note, this can destroy dev->errmsg */
657          dcr->block = lblock;
658          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
659             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
660                  dev->errmsg);
661          } else {
662             /*
663              * If we wrote block and the block numbers don't agree
664              *  we have a possible problem.
665              */
666             if (lblock->VolSessionId == block->VolSessionId &&
667                 lblock->BlockNumber+1 != block->BlockNumber) {
668                Jmsg(jcr, M_ERROR, 0, _(
669 "Re-read of last block OK, but block numbers differ. Last block=%u Current block=%u.\n"),
670                     lblock->BlockNumber, block->BlockNumber);
671             } else {
672                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
673             }
674          }
675          free_block(lblock);
676          dcr->block = block;
677       }
678    }
679 #endif
680 }
681
682 static bool terminate_writing_volume(DCR *dcr)
683 {
684    DEVICE *dev = dcr->dev;
685    bool ok = true;
686
687    /* Create a JobMedia record to indicated end of tape */
688    dev->VolCatInfo.VolCatFiles = dev->file;
689    if (!dir_create_jobmedia_record(dcr)) {
690       Dmsg0(190, "Error from create JobMedia\n");
691       dev->dev_errno = EIO;
692        Jmsg(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
693             dcr->VolCatInfo.VolCatName, dcr->jcr->Job);
694        ok = false;
695        goto bail_out;
696    }
697    dcr->block->write_failed = true;
698    if (!dev->weof(1)) {         /* end the tape */
699       dev->VolCatInfo.VolCatErrors++;
700       Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
701            "%s"), dev->errmsg);
702       ok = false;
703       Dmsg0(100, "WEOF error.\n");
704    }
705    if (ok) {
706       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
707    }
708    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
709    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
710    dev->VolCatInfo.VolCatJobs++;              /* increment number of jobs */
711    
712    if (dev->is_dvd()) {
713       if (!dvd_write_part(dcr)) {             /* write last part */
714          dev->VolCatInfo.VolCatErrors++;
715          Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
716                                  "This Volume may not be readable.\n%s"),
717                          dev->errmsg);
718          ok = false;
719          Dmsg0(100, "dvd_write_part error.\n");
720       }
721       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
722    }
723    
724    if (!dir_update_volume_info(dcr, false)) {
725       ok = false;
726    }
727    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
728
729    /*
730     * Walk through all attached dcrs setting flag to call
731     * set_new_file_parameters() when that dcr is next used.
732     */
733    DCR *mdcr;
734    foreach_dlist(mdcr, dev->attached_dcrs) {
735       if (mdcr->jcr->JobId == 0) {
736          continue;
737       }
738       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
739    }
740    /* Set new file/block parameters for current dcr */
741    set_new_file_parameters(dcr);
742
743    if (ok && dev_cap(dev, CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
744       dev->VolCatInfo.VolCatErrors++;
745       /* This may not be fatal since we already wrote an EOF */
746       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
747    }
748 bail_out:
749    dev->set_ateot();                  /* no more writing this tape */
750    Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
751    return ok;
752 }
753
754 /*
755  * Do bookkeeping when a new file is created on a Volume. This is
756  *  also done for disk files to generate the jobmedia records for
757  *  quick seeking.
758  */
759 static bool do_new_file_bookkeeping(DCR *dcr) 
760 {
761    DEVICE *dev = dcr->dev;
762    JCR *jcr = dcr->jcr;
763
764    /* Create a JobMedia record so restore can seek */
765    if (!dir_create_jobmedia_record(dcr)) {
766       Dmsg0(190, "Error from create_job_media.\n");
767       dev->dev_errno = EIO;
768        Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
769             dcr->VolCatInfo.VolCatName, jcr->Job);
770        terminate_writing_volume(dcr);
771        dev->dev_errno = EIO;
772        return false;
773    }
774    dev->VolCatInfo.VolCatFiles = dev->file;
775    if (!dir_update_volume_info(dcr, false)) {
776       Dmsg0(190, "Error from update_vol_info.\n");
777       terminate_writing_volume(dcr);
778       dev->dev_errno = EIO;
779       return false;
780    }
781    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
782
783    /*
784     * Walk through all attached dcrs setting flag to call
785     * set_new_file_parameters() when that dcr is next used.
786     */
787    DCR *mdcr;
788    foreach_dlist(mdcr, dev->attached_dcrs) {
789       if (mdcr->jcr->JobId == 0) {
790          continue;
791       }
792       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
793    }
794    /* Set new file/block parameters for current dcr */
795    set_new_file_parameters(dcr);
796    return true;
797 }
798
799 /*
800  * Do all checks for DVD sizes during writing.
801  */
802 static bool do_dvd_size_checks(DCR *dcr) 
803 {
804    DEVICE *dev = dcr->dev;
805    JCR *jcr = dcr->jcr;
806    DEV_BLOCK *block = dcr->block;
807
808    /* Don't go further if the device is not a dvd */
809    if (!dev->is_dvd()) {
810       return true;
811    }
812    
813    /* Limit maximum part size to value specified by user 
814     */
815    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
816       if (dev->part < dev->num_dvd_parts) {
817          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
818                " is less than the total number of parts (%d/%d, device=%s)\n"),
819                dev->part, dev->num_dvd_parts, dev->print_name());
820          dev->dev_errno = EIO;
821          return false;
822       }
823       
824       if (dvd_open_next_part(dcr) < 0) {
825          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
826                 dev->print_name(), dev->bstrerror());
827          dev->dev_errno = EIO;
828          return false;
829       }
830       
831       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
832             
833       if (!dir_update_volume_info(dcr, false)) {
834          Dmsg0(190, "Error from update_vol_info.\n");
835          dev->dev_errno = EIO;
836          return false;
837       }
838    }
839    
840    if (!dev->is_freespace_ok()) { /* Error while getting free space */
841       char ed1[50], ed2[50];
842       Dmsg1(10, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
843       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
844          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
845            dev->VolCatInfo.VolCatName,
846            dev->file, dev->block_num, dev->print_name(),
847            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
848            dev->free_space_errno, dev->errmsg);
849       dev->dev_errno = dev->free_space_errno;
850       return false;
851    }
852    
853    if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
854       char ed1[50], ed2[50];
855       Dmsg0(10, "==== Just enough free space on the device to write the current part...\n");
856       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
857          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
858             dev->VolCatInfo.VolCatName,
859             dev->file, dev->block_num, dev->print_name(),
860             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
861             dev->free_space_errno);
862       terminate_writing_volume(dcr);
863       dev->dev_errno = ENOSPC;
864       return false;
865    }   
866    return true;
867 }
868
869
870 /*
871  * Read block with locking
872  *
873  */
874 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
875 {
876    bool ok;
877    DEVICE *dev = dcr->dev;
878    Dmsg0(200, "Enter read_block_from_device\n");
879    lock_device(dev);
880    ok = read_block_from_dev(dcr, check_block_numbers);
881    unlock_device(dev);
882    Dmsg0(200, "Leave read_block_from_device\n");
883    return ok;
884 }
885
886 /*
887  * Read the next block into the block structure and unserialize
888  *  the block header.  For a file, the block may be partially
889  *  or completely in the current buffer.
890  */
891 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
892 {
893    ssize_t stat;
894    int looping;
895    uint32_t BlockNumber;
896    int retry;
897    JCR *jcr = dcr->jcr;
898    DEVICE *dev = dcr->dev;
899    DEV_BLOCK *block = dcr->block;
900    
901    if (dev->at_eot()) {
902       return false;
903    }
904    looping = 0;
905    Dmsg1(200, "Full read() in read_block_from_device() len=%d\n",
906          block->buf_len);
907 reread:
908    if (looping > 1) {
909       dev->dev_errno = EIO;
910       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
911          dev->print_name());
912       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
913       block->read_len = 0;
914       return false;
915    }
916    
917    /*Dmsg1(100, "dev->file_size=%u\n",(unsigned int)dev->file_size);
918    Dmsg1(100, "dev->file_addr=%u\n",(unsigned int)dev->file_addr);
919    Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd, 0, SEEK_CUR));
920    Dmsg1(100, "dev->part_start=%u\n",(unsigned int)dev->part_start);
921    Dmsg1(100, "dev->file_addr-dev->part_start=%u\n",(unsigned int)dev->file_addr-dev->part_start);
922    Dmsg1(100, "dev->file_size-dev->part_start=%u\n",(unsigned int)dev->file_size-dev->part_start);
923    Dmsg1(100, "dev->part_size=%u\n", (unsigned int)dev->part_size);
924    Dmsg1(100, "dev->part=%u\n", (unsigned int)dev->part);
925    Dmsg1(100, "dev->num_dvd_parts=%u\n", (unsigned int)dev->num_dvd_parts);
926    Dmsg1(100, "dev->VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
927    Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
928          ((dev->file_addr-dev->part_start) == dev->part_size), 
929          (dev->part <= dev->VolCatInfo.VolCatParts));*/
930
931    /* Check for DVD part file end */
932    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
933         dev->part < dev->num_dvd_parts) {
934       Dmsg0(400, "Call dvd_open_next_part\n");
935       if (dvd_open_next_part(dcr) < 0) {
936          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
937                dev->part, dev->print_name(), dev->bstrerror());
938          dev->dev_errno = EIO;
939          return false;
940       }
941    }
942    
943    retry = 0;
944    do {
945 //    uint32_t *bp = (uint32_t *)block->buf;
946 //    Pmsg3(000, "Read %p %u at %llu\n", block->buf, block->buf_len, lseek(dev->fd, 0, SEEK_CUR));
947
948       if (dev->is_tape()) {
949          stat = tape_read(dev->fd, block->buf, (size_t)block->buf_len);
950       } else {
951          stat = read(dev->fd, block->buf, (size_t)block->buf_len);
952       }
953
954 //    Pmsg8(000, "stat=%d Csum=%u blen=%u bnum=%u %c%c%c%c\n",stat, bp[0],bp[1],bp[2],
955 //      block->buf[12],block->buf[13],block->buf[14],block->buf[15]);
956
957       if (retry == 1) {
958          dev->VolCatInfo.VolCatErrors++;
959       }
960    } while (stat == -1 && (errno == EINTR || errno == EIO) && retry++ < 11);
961    if (stat < 0) {
962       berrno be;
963       dev->clrerror(-1);
964       Dmsg1(200, "Read device got: ERR=%s\n", be.strerror());
965       block->read_len = 0;
966       Mmsg4(dev->errmsg, _("Read error at file:blk %u:%u on device %s. ERR=%s.\n"),
967          dev->file, dev->block_num, dev->print_name(), be.strerror());
968       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
969       if (dev->at_eof()) {        /* EOF just seen? */
970          dev->set_eot();          /* yes, error => EOT */
971       }
972       return false;
973    }
974    Dmsg3(200, "Read device got %d bytes at %u:%u\n", stat,
975       dev->file, dev->block_num);
976    if (stat == 0) {             /* Got EOF ! */
977       dev->block_num = 0;
978       block->read_len = 0;
979       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
980          dev->file, dev->block_num, dev->print_name());
981       if (dev->at_eof()) {       /* EOF already read? */
982          dev->set_eot();         /* yes, 2 EOFs => EOT */
983          return 0;
984       }
985       dev->set_ateof();
986       return false;             /* return eof */
987    }
988    /* Continue here for successful read */
989    block->read_len = stat;      /* save length read */
990    if (block->read_len < BLKHDR2_LENGTH) {
991       dev->dev_errno = EIO;
992       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
993          dev->file, dev->block_num, block->read_len, dev->print_name());
994       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
995       dev->set_short_block();   
996       block->read_len = block->binbuf = 0;
997       return false;             /* return error */
998    }
999
1000    BlockNumber = block->BlockNumber + 1;
1001    if (!unser_block_header(jcr, dev, block)) {
1002       if (forge_on) {
1003          dev->file_addr += block->read_len;
1004          dev->file_size += block->read_len;
1005          goto reread;
1006       }
1007       return false;
1008    }
1009
1010    /*
1011     * If the block is bigger than the buffer, we reposition for
1012     *  re-reading the block, allocate a buffer of the correct size,
1013     *  and go re-read.
1014     */
1015    if (block->block_len > block->buf_len) {
1016       dev->dev_errno = EIO;
1017       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1018          block->block_len, block->buf_len);
1019       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1020       Pmsg1(000, "%s", dev->errmsg);
1021       /* Attempt to reposition to re-read the block */
1022       if (dev->is_tape()) {
1023          Dmsg0(200, "BSR for reread; block too big for buffer.\n");
1024          if (!dev->bsr(1)) {
1025             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1026             block->read_len = 0;
1027             return false;
1028          }
1029       } else {
1030          Dmsg0(200, "Seek to beginning of block for reread.\n");
1031          off_t pos = lseek_dev(dev, (off_t)0, SEEK_CUR); /* get curr pos */
1032          pos -= block->read_len;
1033          lseek_dev(dev, pos, SEEK_SET);
1034          dev->file_addr = pos;
1035       }
1036       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1037       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1038       Pmsg1(000, "%s", dev->errmsg);
1039       /* Set new block length */
1040       dev->max_block_size = block->block_len;
1041       block->buf_len = block->block_len;
1042       free_memory(block->buf);
1043       block->buf = get_memory(block->buf_len);
1044       empty_block(block);
1045       looping++;
1046       goto reread;                    /* re-read block with correct block size */
1047    }
1048
1049    if (block->block_len > block->read_len) {
1050       dev->dev_errno = EIO;
1051       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1052          dev->file, dev->block_num, block->read_len, dev->print_name());
1053       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1054       dev->set_short_block();
1055       block->read_len = block->binbuf = 0;
1056       return false;             /* return error */
1057    }
1058
1059    dev->clear_short_block();
1060    dev->clear_eof();
1061    dev->VolCatInfo.VolCatReads++;
1062    dev->VolCatInfo.VolCatRBytes += block->read_len;
1063
1064    dev->VolCatInfo.VolCatBytes += block->block_len;
1065    dev->VolCatInfo.VolCatBlocks++;
1066    dev->EndBlock = dev->block_num;
1067    dev->EndFile  = dev->file;
1068    dev->block_num++;
1069
1070    /* Update dcr values */
1071    if (dev->is_tape()) {
1072       dcr->EndBlock = dev->EndBlock;
1073       dcr->EndFile  = dev->EndFile;
1074    } else {
1075       uint64_t addr = dev->file_addr + block->read_len - 1;
1076       dcr->EndBlock = (uint32_t)addr;
1077       dcr->EndFile = (uint32_t)(addr >> 32);
1078       dev->block_num = dcr->EndBlock;
1079       dev->file = dcr->EndFile;
1080    }
1081    dev->file_addr += block->read_len;
1082    dev->file_size += block->read_len;
1083
1084    /*
1085     * If we read a short block on disk,
1086     * seek to beginning of next block. This saves us
1087     * from shuffling blocks around in the buffer. Take a
1088     * look at this from an efficiency stand point later, but
1089     * it should only happen once at the end of each job.
1090     *
1091     * I've been lseek()ing negative relative to SEEK_CUR for 30
1092     *   years now. However, it seems that with the new off_t definition,
1093     *   it is not possible to seek negative amounts, so we use two
1094     *   lseek(). One to get the position, then the second to do an
1095     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1096     */
1097    Dmsg0(200, "At end of read block\n");
1098    if (block->read_len > block->block_len && !dev->is_tape()) {
1099       char ed1[50];
1100       off_t pos = lseek_dev(dev, (off_t)0, SEEK_CUR); /* get curr pos */
1101       Dmsg1(200, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1102       pos -= (block->read_len - block->block_len);
1103       lseek_dev(dev, pos, SEEK_SET);
1104       Dmsg3(200, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1105          edit_int64(pos, ed1), block->block_len,
1106             block->read_len);
1107       dev->file_addr = pos;
1108       dev->file_size = pos;
1109    }
1110    Dmsg2(200, "Exit read_block read_len=%d block_len=%d\n",
1111       block->read_len, block->block_len);
1112    block->block_read = true;
1113    return true;
1114 }