]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
- Fix the same state variable problem in open_next_part().
[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 ammended 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
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(FileIndex),
93            stream_to_ascii(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(350, "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(199, "free_block buffer %x\n", block->buf);
158    free_memory(block->buf);
159    Dmsg1(199, "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(390, "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(390, "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->dev_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 (weof_dev(dev, 1) != 0) {            /* 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             strerror_dev(dev));
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.VolName)) {
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(300, "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
513     */ 
514    stat = write(dev->fd, block->buf, (size_t)wlen);
515
516 #ifdef DEBUG_BLOCK_ZEROING
517    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
518       Jmsg0(jcr, M_ABORT, 0, "Write block header zeroed.\n");
519    }
520 #endif
521
522    if (stat != (ssize_t)wlen) {
523       /* Some devices simply report EIO when the volume is full.
524        * With a little more thought we may be able to check
525        * capacity and distinguish real errors and EOT
526        * conditions.  In any case, we probably want to
527        * simulate an End of Medium.
528        */
529       if (stat == -1) {
530          berrno be;
531          clrerror_dev(dev, -1);
532          if (dev->dev_errno == 0) {
533             dev->dev_errno = ENOSPC;        /* out of space */
534          }
535          if (dev->dev_errno != ENOSPC) {
536             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
537                dev->file, dev->block_num, dev->dev_name, be.strerror());
538          }
539       } else {
540         dev->dev_errno = ENOSPC;            /* out of space */
541       }
542       if (dev->dev_errno == ENOSPC) {
543          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
544             dev->VolCatInfo.VolCatName,
545             dev->file, dev->block_num, dev->print_name(), wlen, stat);
546       }
547       Dmsg6(100, "=== Write error. size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
548          wlen, stat, dev->block_num, block->BlockNumber, dev->dev_errno, strerror(dev->dev_errno));
549
550       ok = terminate_writing_volume(dcr);
551       if (!ok && !forge_on) {
552          return false;
553       }
554       if (ok) {
555          reread_last_block(dcr);
556       }
557       return false;
558    }
559
560    /* We successfully wrote the block, now do housekeeping */
561
562    dev->VolCatInfo.VolCatBytes += block->binbuf;
563    dev->VolCatInfo.VolCatBlocks++;
564    dev->EndBlock = dev->block_num;
565    dev->EndFile  = dev->file;
566    dev->block_num++;
567    block->BlockNumber++;
568
569    /* Update dcr values */
570    if (dev->is_tape()) {
571       dcr->EndBlock = dev->EndBlock;
572       dcr->EndFile  = dev->EndFile;
573    } else {
574       /* Save address of start of block just written */
575       dcr->EndBlock = (uint32_t)dev->file_addr;
576       dcr->EndFile = (uint32_t)(dev->file_addr >> 32);
577    }
578    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
579       dcr->VolFirstIndex = block->FirstIndex;
580    }
581    if (block->LastIndex > 0) {
582       dcr->VolLastIndex = block->LastIndex;
583    }
584    dcr->WroteVol = true;
585    dev->file_addr += wlen;            /* update file address */
586    dev->file_size += wlen;
587    dev->part_size += wlen;
588
589    Dmsg2(300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
590    empty_block(block);
591    return true;
592 }
593
594 static void reread_last_block(DCR *dcr)
595 {
596 #define CHECK_LAST_BLOCK
597 #ifdef  CHECK_LAST_BLOCK
598    bool ok = true;
599    DEVICE *dev = dcr->dev;
600    JCR *jcr = dcr->jcr;
601    DEV_BLOCK *block = dcr->block;
602    /*
603     * If the device is a tape and it supports backspace record,
604     *   we backspace over one or two eof marks depending on
605     *   how many we just wrote, then over the last record,
606     *   then re-read it and verify that the block number is
607     *   correct.
608     */
609    if (dev->is_tape() && dev_cap(dev, CAP_BSR)) {
610       /* Now back up over what we wrote and read the last block */
611       if (!bsf_dev(dev, 1)) {
612          berrno be;
613          ok = false;
614          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
615               be.strerror(dev->dev_errno));
616       }
617       if (ok && dev_cap(dev, CAP_TWOEOF) && !bsf_dev(dev, 1)) {
618          berrno be;
619          ok = false;
620          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
621               be.strerror(dev->dev_errno));
622       }
623       /* Backspace over record */
624       if (ok && !bsr_dev(dev, 1)) {
625          berrno be;
626          ok = false;
627          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
628               be.strerror(dev->dev_errno));
629          /*
630           *  On FreeBSD systems, if the user got here, it is likely that his/her
631           *    tape drive is "frozen".  The correct thing to do is a
632           *    rewind(), but if we do that, higher levels in cleaning up, will
633           *    most likely write the EOS record over the beginning of the
634           *    tape.  The rewind *is* done later in mount.c when another
635           *    tape is requested. Note, the clrerror_dev() call in bsr_dev()
636           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
637           */
638       }
639       if (ok) {
640          DEV_BLOCK *lblock = new_block(dev);
641          /* Note, this can destroy dev->errmsg */
642          dcr->block = lblock;
643          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
644             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
645                  dev->errmsg);
646          } else {
647             if (lblock->BlockNumber+1 == block->BlockNumber) {
648                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
649             } else {
650                Jmsg(jcr, M_ERROR, 0, _(
651 "Re-read of last block failed. Last block=%u Current block=%u.\n"),
652                     lblock->BlockNumber, block->BlockNumber);
653             }
654          }
655          free_block(lblock);
656          dcr->block = block;
657       }
658    }
659 #endif
660 }
661
662 static bool terminate_writing_volume(DCR *dcr)
663 {
664    DEVICE *dev = dcr->dev;
665    bool ok = true;
666
667    /* Create a JobMedia record to indicated end of tape */
668    dev->VolCatInfo.VolCatFiles = dev->file;
669    if (!dir_create_jobmedia_record(dcr)) {
670       Dmsg0(190, "Error from create JobMedia\n");
671       dev->dev_errno = EIO;
672        Jmsg(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
673             dcr->VolCatInfo.VolCatName, dcr->jcr->Job);
674        ok = false;
675        goto bail_out;
676    }
677    dcr->block->write_failed = true;
678    if (weof_dev(dev, 1) != 0) {         /* end the tape */
679       dev->VolCatInfo.VolCatErrors++;
680       Jmsg(dcr->jcr, M_ERROR, 0, "Error writing final EOF to tape. This tape may not be readable.\n"
681            "%s", dev->errmsg);
682       ok = false;
683       Dmsg0(100, "WEOF error.\n");
684    }
685    if (ok) {
686       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolName);
687    }
688    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
689    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
690    dev->VolCatInfo.VolCatJobs++;              /* increment number of jobs */
691    
692    if (dev->is_dvd()) { /* Write the current (and last) part. */
693       open_next_part(dev);
694    }
695    
696    if (!dir_update_volume_info(dcr, false)) {
697       ok = false;
698    }
699    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
700
701    /*
702     * Walk through all attached dcrs setting flag to call
703     * set_new_file_parameters() when that dcr is next used.
704     */
705    DCR *mdcr;
706    foreach_dlist(mdcr, dev->attached_dcrs) {
707       if (mdcr->jcr->JobId == 0) {
708          continue;
709       }
710       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
711    }
712    /* Set new file/block parameters for current dcr */
713    set_new_file_parameters(dcr);
714
715    if (ok && dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {  /* end the tape */
716       dev->VolCatInfo.VolCatErrors++;
717       /* This may not be fatal since we already wrote an EOF */
718       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
719    }
720 bail_out:
721    dev->set_ateot();                  /* no more writing this tape */
722    Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
723    return ok;
724 }
725
726 /*
727  * Do bookkeeping when a new file is created on a Volume. This is
728  *  also done for disk files to generate the jobmedia records for
729  *  quick seeking.
730  */
731 static bool do_new_file_bookkeeping(DCR *dcr) 
732 {
733    DEVICE *dev = dcr->dev;
734    JCR *jcr = dcr->jcr;
735
736    /* Create a JobMedia record so restore can seek */
737    if (!dir_create_jobmedia_record(dcr)) {
738       Dmsg0(190, "Error from create_job_media.\n");
739       dev->dev_errno = EIO;
740        Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
741             dcr->VolCatInfo.VolCatName, jcr->Job);
742        terminate_writing_volume(dcr);
743        dev->dev_errno = EIO;
744        return false;
745    }
746    dev->VolCatInfo.VolCatFiles = dev->file;
747    if (!dir_update_volume_info(dcr, false)) {
748       Dmsg0(190, "Error from update_vol_info.\n");
749       terminate_writing_volume(dcr);
750       dev->dev_errno = EIO;
751       return false;
752    }
753    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
754
755    /*
756     * Walk through all attached dcrs setting flag to call
757     * set_new_file_parameters() when that dcr is next used.
758     */
759    DCR *mdcr;
760    foreach_dlist(mdcr, dev->attached_dcrs) {
761       if (mdcr->jcr->JobId == 0) {
762          continue;
763       }
764       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
765    }
766    /* Set new file/block parameters for current dcr */
767    set_new_file_parameters(dcr);
768    return true;
769 }
770
771 /*
772  * Do all checks for DVD sizes during writing.
773  */
774 static bool do_dvd_size_checks(DCR *dcr) 
775 {
776    DEVICE *dev = dcr->dev;
777    JCR *jcr = dcr->jcr;
778    DEV_BLOCK *block = dcr->block;
779
780    /* Limit maximum part size to value specified by user 
781     * (not applicable to tapes/fifos)   
782     */
783    if (!(dev->is_tape() || dev->is_fifo()) && dev->max_part_size > 0 &&
784         (dev->part_size + block->binbuf) >= dev->max_part_size) {
785       if (dev->part < dev->num_parts) {
786          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number is less than the total number of parts (%d/%d, device=%s)\n"),
787                dev->part, dev->num_parts, dev->print_name());
788          dev->dev_errno = EIO;
789          return false;
790       }
791       
792       if (open_next_part(dev) < 0) {
793          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
794                 dev->print_name(), strerror_dev(dev));
795          dev->dev_errno = EIO;
796          return false;
797       }
798       
799       dev->VolCatInfo.VolCatParts = dev->num_parts;
800             
801       if (!dir_update_volume_info(dcr, false)) {
802          Dmsg0(190, "Error from update_vol_info.\n");
803          dev->dev_errno = EIO;
804          return false;
805       }
806    }
807    
808    if (dev->free_space_errno < 0) { /* Error while getting free space */
809       char ed1[50], ed2[50];
810       Dmsg1(10, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
811       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s (part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
812            dev->VolCatInfo.VolCatName,
813            dev->file, dev->block_num, dev->print_name(),
814            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
815            dev->free_space_errno, dev->errmsg);
816       dev->dev_errno = -dev->free_space_errno;
817       return false;
818    }
819    
820    if ((dev->free_space_errno > 0 && (dev->part_size + block->binbuf) >= dev->free_space)) {
821       char ed1[50], ed2[50];
822       Dmsg0(10, "==== Just enough free space on the device to write the current part...\n");
823       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s (part_size=%s, free_space=%s, free_space_errno=%d).\n"),
824             dev->VolCatInfo.VolCatName,
825             dev->file, dev->block_num, dev->print_name(),
826             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
827             dev->free_space_errno);
828       terminate_writing_volume(dcr);
829       dev->dev_errno = ENOSPC;
830       return false;
831    }   
832    return true;
833 }
834
835
836 /*
837  * Read block with locking
838  *
839  */
840 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
841 {
842    bool ok;
843    DEVICE *dev = dcr->dev;
844    Dmsg0(200, "Enter read_block_from_device\n");
845    lock_device(dev);
846    ok = read_block_from_dev(dcr, check_block_numbers);
847    unlock_device(dev);
848    Dmsg0(200, "Leave read_block_from_device\n");
849    return ok;
850 }
851
852 /*
853  * Read the next block into the block structure and unserialize
854  *  the block header.  For a file, the block may be partially
855  *  or completely in the current buffer.
856  */
857 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
858 {
859    ssize_t stat;
860    int looping;
861    uint32_t BlockNumber;
862    int retry;
863    JCR *jcr = dcr->jcr;
864    DEVICE *dev = dcr->dev;
865    DEV_BLOCK *block = dcr->block;
866    
867    if (dev->at_eot()) {
868       return false;
869    }
870    looping = 0;
871    Dmsg1(200, "Full read() in read_block_from_device() len=%d\n",
872          block->buf_len);
873 reread:
874    if (looping > 1) {
875       dev->dev_errno = EIO;
876       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
877          dev->dev_name);
878       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
879       block->read_len = 0;
880       return false;
881    }
882    
883    /*Dmsg1(200, "dev->file_size=%u\n",(unsigned int)dev->file_size);
884    Dmsg1(200, "lseek=%u\n",(unsigned int)lseek(dev->fd, 0, SEEK_CUR));
885    Dmsg1(200, "dev->part_start=%u\n",(unsigned int)dev->part_start);
886    Dmsg1(200, "dev->file_size-dev->part_start=%u\n",(unsigned int)dev->file_size-dev->part_start);
887    Dmsg1(200, "dev->part_size=%u\n", (unsigned int)dev->part_size);
888    Dmsg1(200, "dev->part=%u\n", (unsigned int)dev->part);
889    Dmsg1(200, "dev->VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
890    Dmsg3(200, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), ((dev->file_size-dev->part_start) == dev->part_size), (dev->part <= dev->VolCatInfo.VolCatParts));*/
891    /* Check for part file end */
892    if ((dev->num_parts > 0) &&
893         ((dev->file_size-dev->part_start) == dev->part_size) && 
894         (dev->part < dev->num_parts)) {
895       if (open_next_part(dev) < 0) {
896          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
897                dev->print_name(), strerror_dev(dev));
898          dev->dev_errno = EIO;
899          return false;
900       }
901    }
902    
903    retry = 0;
904    do {
905 //    uint32_t *bp = (uint32_t *)block->buf;
906 //    Pmsg3(000, "Read %p %u at %llu\n", block->buf, block->buf_len, lseek(dev->fd, 0, SEEK_CUR));
907
908       stat = read(dev->fd, block->buf, (size_t)block->buf_len);
909
910 //    Pmsg8(000, "stat=%d Csum=%u blen=%u bnum=%u %c%c%c%c\n",stat, bp[0],bp[1],bp[2],
911 //      block->buf[12],block->buf[13],block->buf[14],block->buf[15]);
912
913       if (retry == 1) {
914          dev->VolCatInfo.VolCatErrors++;
915       }
916    } while (stat == -1 && (errno == EINTR || errno == EIO) && retry++ < 11);
917    if (stat < 0) {
918       berrno be;
919       clrerror_dev(dev, -1);
920       Dmsg1(200, "Read device got: ERR=%s\n", be.strerror());
921       block->read_len = 0;
922       Mmsg4(dev->errmsg, _("Read error at file:blk %u:%u on device %s. ERR=%s.\n"),
923          dev->file, dev->block_num, dev->dev_name, be.strerror());
924       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
925       if (dev->at_eof()) {        /* EOF just seen? */
926          dev->set_eot();          /* yes, error => EOT */
927       }
928       return false;
929    }
930    Dmsg3(200, "Read device got %d bytes at %u:%u\n", stat,
931       dev->file, dev->block_num);
932    if (stat == 0) {             /* Got EOF ! */
933       dev->block_num = 0;
934       block->read_len = 0;
935       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
936          dev->file, dev->block_num, dev->dev_name);
937       if (dev->at_eof()) {       /* EOF already read? */
938          dev->set_eot();         /* yes, 2 EOFs => EOT */
939          return 0;
940       }
941       dev->set_ateof();
942       return false;             /* return eof */
943    }
944    /* Continue here for successful read */
945    block->read_len = stat;      /* save length read */
946    if (block->read_len < BLKHDR2_LENGTH) {
947       dev->dev_errno = EIO;
948       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
949          dev->file, dev->block_num, block->read_len, dev->dev_name);
950       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
951       dev->set_short_block();   
952       block->read_len = block->binbuf = 0;
953       return false;             /* return error */
954    }
955
956    BlockNumber = block->BlockNumber + 1;
957    if (!unser_block_header(jcr, dev, block)) {
958       if (forge_on) {
959          dev->file_addr += block->read_len;
960          dev->file_size += block->read_len;
961          goto reread;
962       }
963       return false;
964    }
965
966    /*
967     * If the block is bigger than the buffer, we reposition for
968     *  re-reading the block, allocate a buffer of the correct size,
969     *  and go re-read.
970     */
971    if (block->block_len > block->buf_len) {
972       dev->dev_errno = EIO;
973       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
974          block->block_len, block->buf_len);
975       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
976       Pmsg1(000, "%s", dev->errmsg);
977       /* Attempt to reposition to re-read the block */
978       if (dev->is_tape()) {
979          Dmsg0(200, "BSR for reread; block too big for buffer.\n");
980          if (!bsr_dev(dev, 1)) {
981             Jmsg(jcr, M_ERROR, 0, "%s", strerror_dev(dev));
982             block->read_len = 0;
983             return false;
984          }
985       } else {
986          Dmsg0(200, "Seek to beginning of block for reread.\n");
987          off_t pos = lseek_dev(dev, (off_t)0, SEEK_CUR); /* get curr pos */
988          pos -= block->read_len;
989          lseek_dev(dev, pos, SEEK_SET);
990          dev->file_addr = pos;
991       }
992       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
993       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
994       Pmsg1(000, "%s", dev->errmsg);
995       /* Set new block length */
996       dev->max_block_size = block->block_len;
997       block->buf_len = block->block_len;
998       free_memory(block->buf);
999       block->buf = get_memory(block->buf_len);
1000       empty_block(block);
1001       looping++;
1002       goto reread;                    /* re-read block with correct block size */
1003    }
1004
1005    if (block->block_len > block->read_len) {
1006       dev->dev_errno = EIO;
1007       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1008          dev->file, dev->block_num, block->read_len, dev->dev_name);
1009       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1010       dev->set_short_block();
1011       block->read_len = block->binbuf = 0;
1012       return false;             /* return error */
1013    }
1014
1015    dev->clear_short_block();
1016    dev->clear_eof();
1017    dev->VolCatInfo.VolCatReads++;
1018    dev->VolCatInfo.VolCatRBytes += block->read_len;
1019
1020    dev->VolCatInfo.VolCatBytes += block->block_len;
1021    dev->VolCatInfo.VolCatBlocks++;
1022    dev->EndBlock = dev->block_num;
1023    dev->EndFile  = dev->file;
1024    dev->block_num++;
1025
1026    /* Update dcr values */
1027    if (dev->is_tape()) {
1028       dcr->EndBlock = dev->EndBlock;
1029       dcr->EndFile  = dev->EndFile;
1030    } else {
1031       dcr->EndBlock = (uint32_t)dev->file_addr;
1032       dcr->EndFile = (uint32_t)(dev->file_addr >> 32);
1033       dev->block_num = dcr->EndBlock;
1034       dev->file = dcr->EndFile;
1035    }
1036    dev->file_addr += block->block_len;
1037    dev->file_size += block->block_len;
1038
1039    /*
1040     * If we read a short block on disk,
1041     * seek to beginning of next block. This saves us
1042     * from shuffling blocks around in the buffer. Take a
1043     * look at this from an efficiency stand point later, but
1044     * it should only happen once at the end of each job.
1045     *
1046     * I've been lseek()ing negative relative to SEEK_CUR for 30
1047     *   years now. However, it seems that with the new off_t definition,
1048     *   it is not possible to seek negative amounts, so we use two
1049     *   lseek(). One to get the position, then the second to do an
1050     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1051     */
1052    Dmsg0(200, "At end of read block\n");
1053    if (block->read_len > block->block_len && !dev->is_tape()) {
1054       char ed1[50];
1055       off_t pos = lseek_dev(dev, (off_t)0, SEEK_CUR); /* get curr pos */
1056       pos -= (block->read_len - block->block_len);
1057       lseek_dev(dev, pos, SEEK_SET);
1058       Dmsg3(200, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1059          edit_uint64(pos, ed1), block->block_len,
1060             block->read_len);
1061       dev->file_addr = pos;
1062       dev->file_size = pos;
1063    }
1064    Dmsg2(200, "Exit read_block read_len=%d block_len=%d\n",
1065       block->read_len, block->block_len);
1066    block->block_read = true;
1067    return true;
1068 }