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