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