]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
447d57b5da765401833384c4d0bb500363887cb7
[bacula/bacula] / bacula / src / stored / block.c
1 /*
2    Bacula® - The Network Backup Solution
3
4    Copyright (C) 2001-2007 Free Software Foundation Europe e.V.
5
6    The main author of Bacula is Kern Sibbald, with contributions from
7    many others, a complete list can be found in the file AUTHORS.
8    This program is Free Software; you can redistribute it and/or
9    modify it under the terms of version two of the GNU General Public
10    License as published by the Free Software Foundation and included
11    in the file LICENSE.
12
13    This program is distributed in the hope that it will be useful, but
14    WITHOUT ANY WARRANTY; without even the implied warranty of
15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
16    General Public License for more details.
17
18    You should have received a copy of the GNU General Public License
19    along with this program; if not, write to the Free Software
20    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
21    02110-1301, USA.
22
23    Bacula® is a registered trademark of John Walker.
24    The licensor of Bacula is the Free Software Foundation Europe
25    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
26    Switzerland, email:ftf@fsfeurope.org.
27 */
28 /*
29  *
30  *   block.c -- tape block handling functions
31  *
32  *              Kern Sibbald, March MMI
33  *                 added BB02 format October MMII
34  *
35  *   Version $Id$
36  *
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->is_dev_locked()) {        /* device already locked? */
349       /* note, do not change this to dcr->r_dlock */
350       dev->r_dlock();                  /* no, lock it */
351    }
352
353    /*
354     * If a new volume has been mounted since our last write
355     *   Create a JobMedia record for the previous volume written,
356     *   and set new parameters to write this volume
357     * The same applies for if we are in a new file.
358     */
359    if (dcr->NewVol || dcr->NewFile) {
360       if (job_canceled(jcr)) {
361          stat = false;
362          goto bail_out;
363       }
364       /* Create a jobmedia record for this job */
365       if (!dir_create_jobmedia_record(dcr)) {
366          dev->dev_errno = EIO;
367          Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
368             dcr->VolCatInfo.VolCatName, jcr->Job);
369          set_new_volume_parameters(dcr);
370          stat = false;
371          goto bail_out;
372       }
373       if (dcr->NewVol) {
374          /* Note, setting a new volume also handles any pending new file */
375          set_new_volume_parameters(dcr);
376          dcr->NewFile = false;        /* this handled for new file too */
377       } else {
378          set_new_file_parameters(dcr);
379       }
380    }
381
382    if (!write_block_to_dev(dcr)) {
383        if (job_canceled(jcr) || jcr->JobType == JT_SYSTEM) {
384           stat = false;
385        } else {
386           stat = fixup_device_block_write_error(dcr);
387        }
388    }
389
390 bail_out:
391    if (!dcr->is_dev_locked()) {        /* did we lock dev above? */
392       /* note, do not change this to dcr->dunlock */
393       dev->dunlock();                  /* unlock it now */
394    }
395    return stat;
396 }
397
398 /*
399  * Write a block to the device
400  *
401  *  Returns: true  on success or EOT
402  *           false on hard error
403  */
404 bool write_block_to_dev(DCR *dcr)
405 {
406    ssize_t stat = 0;
407    uint32_t wlen;                     /* length to write */
408    int hit_max1, hit_max2;
409    bool ok = true;
410    DEVICE *dev = dcr->dev;
411    JCR *jcr = dcr->jcr;
412    DEV_BLOCK *block = dcr->block;
413
414 #ifdef NO_TAPE_WRITE_TEST
415    empty_block(block);
416    return true;
417 #endif
418    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
419    ASSERT(dev->is_open());
420
421    /* dump_block(block, "before write"); */
422    if (dev->at_weot()) {
423       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
424       dev->dev_errno = ENOSPC;
425       Jmsg(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
426       return false;
427    }
428    if (!dev->can_append()) {
429       dev->dev_errno = EIO;
430       Jmsg(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume.\n"));
431       return false;
432    }
433    wlen = block->binbuf;
434    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
435       Dmsg0(100, "return write_block_to_dev no data to write\n");
436       return true;
437    }
438    /*
439     * Clear to the end of the buffer if it is not full,
440     *  and on tape devices, apply min and fixed blocking.
441     */
442    if (wlen != block->buf_len) {
443       uint32_t blen;                  /* current buffer length */
444
445       Dmsg2(250, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
446       blen = wlen;
447
448       /* Adjust write size to min/max for tapes only */
449       if (dev->is_tape()) {
450          /* check for fixed block size */
451          if (dev->min_block_size == dev->max_block_size) {
452             wlen = block->buf_len;    /* fixed block size already rounded */
453          /* Check for min block size */
454          } else if (wlen < dev->min_block_size) {
455             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
456          /* Ensure size is rounded */
457          } else {
458             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
459          }
460       }
461       if (wlen-blen > 0) {
462          memset(block->bufp, 0, wlen-blen); /* clear garbage */
463       }
464    }
465
466    ser_block_header(block);
467
468    /* Limit maximum Volume size to value specified by user */
469    hit_max1 = (dev->max_volume_size > 0) &&
470        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
471    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
472        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
473    if (hit_max1 || hit_max2) {
474       char ed1[50];
475       uint64_t max_cap;
476       Dmsg0(100, "==== Output bytes Triggered medium max capacity.\n");
477       if (hit_max1) {
478          max_cap = dev->max_volume_size;
479       } else {
480          max_cap = dev->VolCatInfo.VolCatMaxBytes;
481       }
482       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
483             edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
484       terminate_writing_volume(dcr);
485       reread_last_block(dcr);   /* DEBUG */
486       dev->dev_errno = ENOSPC;
487       return false;
488    }
489
490    /* Limit maximum File size on volume to user specified value */
491    if ((dev->max_file_size > 0) &&
492        (dev->file_size+block->binbuf) >= dev->max_file_size) {
493       dev->file_size = 0;             /* reset file size */
494
495       if (!dev->weof(1)) {            /* write eof */
496          Dmsg0(190, "WEOF error in max file size.\n");
497          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
498             dev->bstrerror());
499          terminate_writing_volume(dcr);
500          dev->dev_errno = ENOSPC;
501          return false;
502       }
503       if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
504          return false;
505       }
506
507       if (!do_new_file_bookkeeping(dcr)) {
508          /* Error message already sent */
509          return false;
510       }
511    }
512    
513    if (!do_dvd_size_checks(dcr)) {
514       /* Error message already sent */
515       return false;
516    }
517
518    dev->VolCatInfo.VolCatWrites++;
519    Dmsg1(1300, "Write block of %u bytes\n", wlen);
520 #ifdef DEBUG_BLOCK_ZEROING
521    uint32_t *bp = (uint32_t *)block->buf;
522    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
523       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
524    }
525 #endif
526
527    /*
528     * Do write here, make a somewhat feeble attempt to recover from 
529     *  I/O errors, or from the OS telling us it is busy.
530     */ 
531    int retry = 0;
532    errno = 0;
533    stat = 0;
534    do {
535       if (retry > 0 && stat == -1 && errno == EBUSY) {
536          berrno be;
537          Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
538                retry, stat, errno, be.bstrerror());
539          bmicrosleep(5, 0);    /* pause a bit if busy or lots of errors */
540          dev->clrerror(-1);
541       }
542       stat = dev->write(block->buf, (size_t)wlen);
543
544    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
545
546 #ifdef DEBUG_BLOCK_ZEROING
547    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
548       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
549    }
550 #endif
551
552    if (stat != (ssize_t)wlen) {
553       /* Some devices simply report EIO when the volume is full.
554        * With a little more thought we may be able to check
555        * capacity and distinguish real errors and EOT
556        * conditions.  In any case, we probably want to
557        * simulate an End of Medium.
558        */
559       if (stat == -1) {
560          berrno be;
561          dev->clrerror(-1);
562          if (dev->dev_errno == 0) {
563             dev->dev_errno = ENOSPC;        /* out of space */
564          }
565          if (dev->dev_errno != ENOSPC) {
566             dev->VolCatInfo.VolCatErrors++;
567             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
568                dev->file, dev->block_num, dev->print_name(), be.bstrerror());
569          }
570       } else {
571         dev->dev_errno = ENOSPC;            /* out of space */
572       }
573       if (dev->dev_errno == ENOSPC) {
574          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
575             dev->VolCatInfo.VolCatName,
576             dev->file, dev->block_num, dev->print_name(), wlen, stat);
577       }
578       Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
579          dev->fd(), wlen, stat, dev->block_num, block->BlockNumber, 
580          dev->dev_errno, strerror(dev->dev_errno));
581
582       ok = terminate_writing_volume(dcr);
583       if (!ok && !forge_on) {
584          return false;
585       }
586       if (ok) {
587          reread_last_block(dcr);
588       }
589       return false;
590    }
591
592    /* We successfully wrote the block, now do housekeeping */
593    Dmsg2(1300, "VolCatBytes=%d newVolCatBytes=%d\n", (int)dev->VolCatInfo.VolCatBytes,
594       (int)(dev->VolCatInfo.VolCatBytes+wlen));
595    dev->VolCatInfo.VolCatBytes += wlen;         
596    dev->VolCatInfo.VolCatBlocks++;
597    dev->EndBlock = dev->block_num;
598    dev->EndFile  = dev->file;
599    block->BlockNumber++;
600
601    /* Update dcr values */
602    if (dev->is_tape()) {
603       dcr->EndBlock = dev->EndBlock;
604       dcr->EndFile  = dev->EndFile;
605       dev->block_num++;
606    } else {
607       /* Save address of block just written */
608       uint64_t addr = dev->file_addr + wlen - 1;
609       dcr->EndBlock = (uint32_t)addr;
610       dcr->EndFile = (uint32_t)(addr >> 32);
611       dev->block_num = dcr->EndBlock;
612       dev->file = dcr->EndFile;
613    }
614    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
615       dcr->VolFirstIndex = block->FirstIndex;
616    }
617    if (block->LastIndex > 0) {
618       dcr->VolLastIndex = block->LastIndex;
619    }
620    dcr->WroteVol = true;
621    dev->file_addr += wlen;            /* update file address */
622    dev->file_size += wlen;
623    dev->part_size += wlen;
624
625    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
626    empty_block(block);
627    return true;
628 }
629
630 static void reread_last_block(DCR *dcr)
631 {
632 #define CHECK_LAST_BLOCK
633 #ifdef  CHECK_LAST_BLOCK
634    bool ok = true;
635    DEVICE *dev = dcr->dev;
636    JCR *jcr = dcr->jcr;
637    DEV_BLOCK *block = dcr->block;
638    /*
639     * If the device is a tape and it supports backspace record,
640     *   we backspace over one or two eof marks depending on
641     *   how many we just wrote, then over the last record,
642     *   then re-read it and verify that the block number is
643     *   correct.
644     */
645    if (dev->is_tape() && dev->has_cap(CAP_BSR)) {
646       /* Now back up over what we wrote and read the last block */
647       if (!dev->bsf(1)) {
648          berrno be;
649          ok = false;
650          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
651               be.bstrerror(dev->dev_errno));
652       }
653       if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
654          berrno be;
655          ok = false;
656          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
657               be.bstrerror(dev->dev_errno));
658       }
659       /* Backspace over record */
660       if (ok && !dev->bsr(1)) {
661          berrno be;
662          ok = false;
663          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
664               be.bstrerror(dev->dev_errno));
665          /*
666           *  On FreeBSD systems, if the user got here, it is likely that his/her
667           *    tape drive is "frozen".  The correct thing to do is a
668           *    rewind(), but if we do that, higher levels in cleaning up, will
669           *    most likely write the EOS record over the beginning of the
670           *    tape.  The rewind *is* done later in mount.c when another
671           *    tape is requested. Note, the clrerror() call in bsr()
672           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
673           */
674       }
675       if (ok) {
676          DEV_BLOCK *lblock = new_block(dev);
677          /* Note, this can destroy dev->errmsg */
678          dcr->block = lblock;
679          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
680             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
681                  dev->errmsg);
682          } else {
683             /*
684              * If we wrote block and the block numbers don't agree
685              *  we have a possible problem.
686              */
687             if (lblock->VolSessionId == block->VolSessionId &&
688                 lblock->BlockNumber+1 != block->BlockNumber) {
689                Jmsg(jcr, M_ERROR, 0, _(
690 "Re-read of last block OK, but block numbers differ. Last block=%u Current block=%u.\n"),
691                     lblock->BlockNumber, block->BlockNumber);
692             } else {
693                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
694             }
695          }
696          free_block(lblock);
697          dcr->block = block;
698       }
699    }
700 #endif
701 }
702
703 static bool terminate_writing_volume(DCR *dcr)
704 {
705    DEVICE *dev = dcr->dev;
706    bool ok = true;
707
708    /* Create a JobMedia record to indicated end of tape */
709    dev->VolCatInfo.VolCatFiles = dev->file;
710    if (!dir_create_jobmedia_record(dcr)) {
711       Dmsg0(190, "Error from create JobMedia\n");
712       dev->dev_errno = EIO;
713        Jmsg(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
714             dcr->VolCatInfo.VolCatName, dcr->jcr->Job);
715        ok = false;
716        goto bail_out;
717    }
718    dcr->block->write_failed = true;
719    if (!dev->weof(1)) {         /* end the tape */
720       dev->VolCatInfo.VolCatErrors++;
721       Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
722            "%s"), dev->errmsg);
723       ok = false;
724       Dmsg0(100, "WEOF error.\n");
725    }
726    if (ok) {
727       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
728    }
729    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
730    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
731    
732    if (dev->is_dvd()) {
733       if (!dvd_write_part(dcr)) {             /* write last part */
734          dev->VolCatInfo.VolCatErrors++;
735          Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
736                                  "This Volume may not be readable.\n%s"),
737                          dev->errmsg);
738          ok = false;
739          Dmsg0(100, "dvd_write_part error.\n");
740       }
741       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
742    }
743    
744    if (!dir_update_volume_info(dcr, false)) {
745       ok = false;
746    }
747    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
748
749    /*
750     * Walk through all attached dcrs setting flag to call
751     * set_new_file_parameters() when that dcr is next used.
752     */
753    DCR *mdcr;
754    foreach_dlist(mdcr, dev->attached_dcrs) {
755       if (mdcr->jcr->JobId == 0) {
756          continue;
757       }
758       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
759    }
760    /* Set new file/block parameters for current dcr */
761    set_new_file_parameters(dcr);
762
763    if (ok && dev->has_cap(CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
764       dev->VolCatInfo.VolCatErrors++;
765       /* This may not be fatal since we already wrote an EOF */
766       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
767    }
768 bail_out:
769    dev->set_ateot();                  /* no more writing this tape */
770    Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
771    return ok;
772 }
773
774 /*
775  * Do bookkeeping when a new file is created on a Volume. This is
776  *  also done for disk files to generate the jobmedia records for
777  *  quick seeking.
778  */
779 static bool do_new_file_bookkeeping(DCR *dcr) 
780 {
781    DEVICE *dev = dcr->dev;
782    JCR *jcr = dcr->jcr;
783
784    /* Create a JobMedia record so restore can seek */
785    if (!dir_create_jobmedia_record(dcr)) {
786       Dmsg0(190, "Error from create_job_media.\n");
787       dev->dev_errno = EIO;
788       Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
789            dcr->VolCatInfo.VolCatName, jcr->Job);
790       terminate_writing_volume(dcr);
791       dev->dev_errno = EIO;
792       return false;
793    }
794    dev->VolCatInfo.VolCatFiles = dev->file;
795    if (!dir_update_volume_info(dcr, false)) {
796       Dmsg0(190, "Error from update_vol_info.\n");
797       terminate_writing_volume(dcr);
798       dev->dev_errno = EIO;
799       return false;
800    }
801    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
802
803    /*
804     * Walk through all attached dcrs setting flag to call
805     * set_new_file_parameters() when that dcr is next used.
806     */
807    DCR *mdcr;
808    foreach_dlist(mdcr, dev->attached_dcrs) {
809       if (mdcr->jcr->JobId == 0) {
810          continue;
811       }
812       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
813    }
814    /* Set new file/block parameters for current dcr */
815    set_new_file_parameters(dcr);
816    return true;
817 }
818
819 /*
820  * Do all checks for DVD sizes during writing.
821  */
822 static bool do_dvd_size_checks(DCR *dcr) 
823 {
824    DEVICE *dev = dcr->dev;
825    JCR *jcr = dcr->jcr;
826    DEV_BLOCK *block = dcr->block;
827
828    /* Don't go further if the device is not a dvd */
829    if (!dev->is_dvd()) {
830       return true;
831    }
832    
833    /* Limit maximum part size to value specified by user 
834     */
835    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
836       if (dev->part < dev->num_dvd_parts) {
837          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
838                " is less than the total number of parts (%d/%d, device=%s)\n"),
839                dev->part, dev->num_dvd_parts, dev->print_name());
840          dev->dev_errno = EIO;
841          return false;
842       }
843       
844       if (dvd_open_next_part(dcr) < 0) {
845          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
846                 dev->print_name(), dev->bstrerror());
847          dev->dev_errno = EIO;
848          return false;
849       }
850       
851       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
852             
853       if (!dir_update_volume_info(dcr, false)) {
854          Dmsg0(190, "Error from update_vol_info.\n");
855          dev->dev_errno = EIO;
856          return false;
857       }
858    }
859
860    dev->update_freespace();
861    
862    if (!dev->is_freespace_ok()) { /* Error while getting free space */
863       char ed1[50], ed2[50];
864       Dmsg1(100, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
865       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
866          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
867            dev->VolCatInfo.VolCatName,
868            dev->file, dev->block_num, dev->print_name(),
869            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
870            dev->free_space_errno, dev->errmsg);
871       dev->dev_errno = dev->free_space_errno;
872       return false;
873    }
874    
875    if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
876       char ed1[50], ed2[50];
877       Dmsg0(100, "==== Just enough free space on the device to write the current part...\n");
878       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
879          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
880             dev->VolCatInfo.VolCatName,
881             dev->file, dev->block_num, dev->print_name(),
882             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
883             dev->free_space_errno);
884       terminate_writing_volume(dcr);
885       dev->dev_errno = ENOSPC;
886       return false;
887    }   
888    return true;
889 }
890
891
892 /*
893  * Read block with locking
894  *
895  */
896 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
897 {
898    bool ok;
899    DEVICE *dev = dcr->dev;
900    Dmsg0(250, "Enter read_block_from_device\n");
901    dev->r_dlock();
902    ok = read_block_from_dev(dcr, check_block_numbers);
903    dev->dunlock();
904    Dmsg0(250, "Leave read_block_from_device\n");
905    return ok;
906 }
907
908 /*
909  * Read the next block into the block structure and unserialize
910  *  the block header.  For a file, the block may be partially
911  *  or completely in the current buffer.
912  */
913 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
914 {
915    ssize_t stat;
916    int looping;
917    uint32_t BlockNumber;
918    int retry;
919    JCR *jcr = dcr->jcr;
920    DEVICE *dev = dcr->dev;
921    DEV_BLOCK *block = dcr->block;
922
923    ASSERT(dev->is_open());
924    
925    if (dev->at_eot()) {
926       return false;
927    }
928    looping = 0;
929    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
930          block->buf_len);
931 reread:
932    if (looping > 1) {
933       dev->dev_errno = EIO;
934       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
935          dev->print_name());
936       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
937       block->read_len = 0;
938       return false;
939    }
940    
941 // #define lots_of_debug
942 #ifdef lots_of_debug
943    if (dev->at_eof() && dev->is_dvd()) {
944       Dmsg1(100, "file_size=%u\n",(unsigned int)dev->file_size);
945       Dmsg1(100, "file_addr=%u\n",(unsigned int)dev->file_addr);
946       Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd(), 0, SEEK_CUR));
947       Dmsg1(100, "part_start=%u\n",(unsigned int)dev->part_start);
948       Dmsg1(100, "part_size=%u\n", (unsigned int)dev->part_size);
949       Dmsg2(100, "part=%u num_dvd_parts=%u\n", dev->part, dev->num_dvd_parts);
950       Dmsg1(100, "VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
951       Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
952          ((dev->file_addr-dev->part_start) == dev->part_size), 
953          (dev->part <= dev->VolCatInfo.VolCatParts));
954   }
955 #endif
956
957    /* Check for DVD part file end */
958    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
959         dev->part <= dev->num_dvd_parts) {
960       Dmsg0(400, "Call dvd_open_next_part\n");
961       if (dvd_open_next_part(dcr) < 0) {
962          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
963                dev->part, dev->print_name(), dev->bstrerror());
964          dev->dev_errno = EIO;
965          return false;
966       }
967    }
968    
969    retry = 0;
970    errno = 0;
971    stat = 0;
972    do {
973       if ((retry > 0 && stat == -1 && errno == EBUSY)) {
974          berrno be;
975          Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
976                retry, stat, errno, be.bstrerror());
977          bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
978          dev->clrerror(-1);
979       }
980       stat = dev->read(block->buf, (size_t)block->buf_len);
981
982    } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
983    if (stat < 0) {
984       berrno be;
985       dev->clrerror(-1);
986       Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
987       block->read_len = 0;
988       Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
989          dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
990       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
991       if (dev->at_eof()) {        /* EOF just seen? */
992          dev->set_eot();          /* yes, error => EOT */
993       }
994       return false;
995    }
996    Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
997       dev->file, dev->block_num);
998    if (stat == 0) {             /* Got EOF ! */
999       dev->block_num = 0;
1000       block->read_len = 0;
1001       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1002          dev->file, dev->block_num, dev->print_name());
1003       if (dev->at_eof()) {       /* EOF already read? */
1004          dev->set_eot();         /* yes, 2 EOFs => EOT */
1005          return 0;
1006       }
1007       dev->set_ateof();
1008       return false;             /* return eof */
1009    }
1010    /* Continue here for successful read */
1011    block->read_len = stat;      /* save length read */
1012    if (block->read_len < BLKHDR2_LENGTH) {
1013       dev->dev_errno = EIO;
1014       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1015          dev->file, dev->block_num, block->read_len, dev->print_name());
1016       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1017       dev->set_short_block();   
1018       block->read_len = block->binbuf = 0;
1019       return false;             /* return error */
1020    }
1021
1022    BlockNumber = block->BlockNumber + 1;
1023    if (!unser_block_header(jcr, dev, block)) {
1024       if (forge_on) {
1025          dev->file_addr += block->read_len;
1026          dev->file_size += block->read_len;
1027          goto reread;
1028       }
1029       return false;
1030    }
1031
1032    /*
1033     * If the block is bigger than the buffer, we reposition for
1034     *  re-reading the block, allocate a buffer of the correct size,
1035     *  and go re-read.
1036     */
1037    if (block->block_len > block->buf_len) {
1038       dev->dev_errno = EIO;
1039       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1040          block->block_len, block->buf_len);
1041       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1042       Pmsg1(000, "%s", dev->errmsg);
1043       /* Attempt to reposition to re-read the block */
1044       if (dev->is_tape()) {
1045          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1046          if (!dev->bsr(1)) {
1047             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1048             block->read_len = 0;
1049             return false;
1050          }
1051       } else {
1052          Dmsg0(250, "Seek to beginning of block for reread.\n");
1053          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1054          pos -= block->read_len;
1055          dev->lseek(dcr, pos, SEEK_SET);
1056          dev->file_addr = pos;
1057       }
1058       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1059       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1060       Pmsg1(000, "%s", dev->errmsg);
1061       /* Set new block length */
1062       dev->max_block_size = block->block_len;
1063       block->buf_len = block->block_len;
1064       free_memory(block->buf);
1065       block->buf = get_memory(block->buf_len);
1066       empty_block(block);
1067       looping++;
1068       goto reread;                    /* re-read block with correct block size */
1069    }
1070
1071    if (block->block_len > block->read_len) {
1072       dev->dev_errno = EIO;
1073       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1074          dev->file, dev->block_num, block->read_len, dev->print_name());
1075       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1076       dev->set_short_block();
1077       block->read_len = block->binbuf = 0;
1078       return false;             /* return error */
1079    }
1080
1081    dev->clear_short_block();
1082    dev->clear_eof();
1083    dev->VolCatInfo.VolCatReads++;
1084    dev->VolCatInfo.VolCatRBytes += block->read_len;
1085
1086    dev->EndBlock = dev->block_num;
1087    dev->EndFile  = dev->file;
1088    dev->block_num++;
1089
1090    /* Update dcr values */
1091    if (dev->is_tape()) {
1092       dcr->EndBlock = dev->EndBlock;
1093       dcr->EndFile  = dev->EndFile;
1094    } else {
1095       uint64_t addr = dev->file_addr + block->read_len - 1;
1096       dcr->EndBlock = (uint32_t)addr;
1097       dcr->EndFile = (uint32_t)(addr >> 32);
1098       dev->block_num = dcr->EndBlock;
1099       dev->file = dcr->EndFile;
1100    }
1101    dev->file_addr += block->read_len;
1102    dev->file_size += block->read_len;
1103
1104    /*
1105     * If we read a short block on disk,
1106     * seek to beginning of next block. This saves us
1107     * from shuffling blocks around in the buffer. Take a
1108     * look at this from an efficiency stand point later, but
1109     * it should only happen once at the end of each job.
1110     *
1111     * I've been lseek()ing negative relative to SEEK_CUR for 30
1112     *   years now. However, it seems that with the new off_t definition,
1113     *   it is not possible to seek negative amounts, so we use two
1114     *   lseek(). One to get the position, then the second to do an
1115     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1116     */
1117    Dmsg0(250, "At end of read block\n");
1118    if (block->read_len > block->block_len && !dev->is_tape()) {
1119       char ed1[50];
1120       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1121       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1122       pos -= (block->read_len - block->block_len);
1123       dev->lseek(dcr, pos, SEEK_SET);
1124       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1125          edit_int64(pos, ed1), block->block_len,
1126             block->read_len);
1127       dev->file_addr = pos;
1128       dev->file_size = pos;
1129    }
1130    Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1131       block->read_len, block->block_len);
1132    block->block_read = true;
1133    return true;
1134 }