]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
More tweaks to the mount volume routines to get everything
[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       Dmsg1(50, "%s", dev->errmsg);
277       if (block->read_errors == 0 || verbose >= 2) {
278          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
279       }
280       block->read_errors++;
281       unser_uint32(block->VolSessionId);
282       unser_uint32(block->VolSessionTime);
283       return false;
284    }
285
286    /* Sanity check */
287    if (block_len > MAX_BLOCK_LENGTH) {
288       dev->dev_errno = EIO;
289       Mmsg3(dev->errmsg,  _("Volume data error at %u:%u! Block length %u is insane (too large), probably due to a bad archive.\n"),
290          dev->file, dev->block_num, block_len);
291       if (block->read_errors == 0 || verbose >= 2) {
292          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
293       }
294       block->read_errors++;
295       return false;
296    }
297
298    Dmsg1(390, "unser_block_header block_len=%d\n", block_len);
299    /* Find end of block or end of buffer whichever is smaller */
300    if (block_len > block->read_len) {
301       block_end = block->read_len;
302    } else {
303       block_end = block_len;
304    }
305    block->binbuf = block_end - bhl;
306    block->block_len = block_len;
307    block->BlockNumber = BlockNumber;
308    Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
309       bhl, block_len);
310    if (block_len <= block->read_len) {
311       BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
312                          block_len-BLKHDR_CS_LENGTH);
313       if (BlockCheckSum != CheckSum) {
314          dev->dev_errno = EIO;
315          Mmsg6(dev->errmsg, _("Volume data error at %u:%u!\n" 
316             "Block checksum mismatch in block=%u len=%d: calc=%x blk=%x\n"),
317             dev->file, dev->block_num, (unsigned)BlockNumber, 
318             block_len, BlockCheckSum, CheckSum);
319          if (block->read_errors == 0 || verbose >= 2) {
320             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
321          }
322          block->read_errors++;
323          if (!forge_on) {
324             return false;
325          }
326       }
327    }
328    return true;
329 }
330
331 /*
332  * Write a block to the device, with locking and unlocking
333  *
334  * Returns: true  on success
335  *        : false on failure
336  *
337  */
338 bool write_block_to_device(DCR *dcr)
339 {
340    bool stat = true;
341    DEVICE *dev = dcr->dev;
342    JCR *jcr = dcr->jcr;
343
344    if (dcr->spooling) {
345       stat = write_block_to_spool_file(dcr);
346       return stat;
347    }
348
349    if (!dcr->is_dev_locked()) {        /* device already locked? */
350       /* note, do not change this to dcr->r_dlock */
351       dev->r_dlock();                  /* no, lock it */
352    }
353
354    /*
355     * If a new volume has been mounted since our last write
356     *   Create a JobMedia record for the previous volume written,
357     *   and set new parameters to write this volume
358     * The same applies for if we are in a new file.
359     */
360    if (dcr->NewVol || dcr->NewFile) {
361       if (job_canceled(jcr)) {
362          stat = false;
363          goto bail_out;
364       }
365       /* Create a jobmedia record for this job */
366       if (!dir_create_jobmedia_record(dcr)) {
367          dev->dev_errno = EIO;
368          Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
369             dcr->VolCatInfo.VolCatName, jcr->Job);
370          set_new_volume_parameters(dcr);
371          stat = false;
372          goto bail_out;
373       }
374       if (dcr->NewVol) {
375          /* Note, setting a new volume also handles any pending new file */
376          set_new_volume_parameters(dcr);
377          dcr->NewFile = false;        /* this handled for new file too */
378       } else {
379          set_new_file_parameters(dcr);
380       }
381    }
382
383    if (!write_block_to_dev(dcr)) {
384        if (job_canceled(jcr) || jcr->JobType == JT_SYSTEM) {
385           stat = false;
386        } else {
387           stat = fixup_device_block_write_error(dcr);
388        }
389    }
390
391 bail_out:
392    if (!dcr->is_dev_locked()) {        /* did we lock dev above? */
393       /* note, do not change this to dcr->dunlock */
394       dev->dunlock();                  /* unlock it now */
395    }
396    return stat;
397 }
398
399 /*
400  * Write a block to the device
401  *
402  *  Returns: true  on success or EOT
403  *           false on hard error
404  */
405 bool write_block_to_dev(DCR *dcr)
406 {
407    ssize_t stat = 0;
408    uint32_t wlen;                     /* length to write */
409    int hit_max1, hit_max2;
410    bool ok = true;
411    DEVICE *dev = dcr->dev;
412    JCR *jcr = dcr->jcr;
413    DEV_BLOCK *block = dcr->block;
414
415 #ifdef NO_TAPE_WRITE_TEST
416    empty_block(block);
417    return true;
418 #endif
419    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
420    ASSERT(dev->is_open());
421
422    /* dump_block(block, "before write"); */
423    if (dev->at_weot()) {
424       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
425       dev->dev_errno = ENOSPC;
426       Jmsg(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
427       return false;
428    }
429    if (!dev->can_append()) {
430       dev->dev_errno = EIO;
431       Jmsg(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume.\n"));
432       return false;
433    }
434    wlen = block->binbuf;
435    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
436       Dmsg0(100, "return write_block_to_dev no data to write\n");
437       return true;
438    }
439    /*
440     * Clear to the end of the buffer if it is not full,
441     *  and on tape devices, apply min and fixed blocking.
442     */
443    if (wlen != block->buf_len) {
444       uint32_t blen;                  /* current buffer length */
445
446       Dmsg2(250, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
447       blen = wlen;
448
449       /* Adjust write size to min/max for tapes only */
450       if (dev->is_tape()) {
451          /* check for fixed block size */
452          if (dev->min_block_size == dev->max_block_size) {
453             wlen = block->buf_len;    /* fixed block size already rounded */
454          /* Check for min block size */
455          } else if (wlen < dev->min_block_size) {
456             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
457          /* Ensure size is rounded */
458          } else {
459             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
460          }
461       }
462       if (wlen-blen > 0) {
463          memset(block->bufp, 0, wlen-blen); /* clear garbage */
464       }
465    }
466
467    ser_block_header(block);
468
469    /* Limit maximum Volume size to value specified by user */
470    hit_max1 = (dev->max_volume_size > 0) &&
471        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
472    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
473        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
474    if (hit_max1 || hit_max2) {
475       char ed1[50];
476       uint64_t max_cap;
477       Dmsg0(100, "==== Output bytes Triggered medium max capacity.\n");
478       if (hit_max1) {
479          max_cap = dev->max_volume_size;
480       } else {
481          max_cap = dev->VolCatInfo.VolCatMaxBytes;
482       }
483       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
484             edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
485       terminate_writing_volume(dcr);
486       reread_last_block(dcr);   /* DEBUG */
487       dev->dev_errno = ENOSPC;
488       return false;
489    }
490
491    /* Limit maximum File size on volume to user specified value */
492    if ((dev->max_file_size > 0) &&
493        (dev->file_size+block->binbuf) >= dev->max_file_size) {
494       dev->file_size = 0;             /* reset file size */
495
496       if (!dev->weof(1)) {            /* write eof */
497          Dmsg0(190, "WEOF error in max file size.\n");
498          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
499             dev->bstrerror());
500          terminate_writing_volume(dcr);
501          dev->dev_errno = ENOSPC;
502          return false;
503       }
504       if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
505          return false;
506       }
507
508       if (!do_new_file_bookkeeping(dcr)) {
509          /* Error message already sent */
510          return false;
511       }
512    }
513    
514    if (!do_dvd_size_checks(dcr)) {
515       /* Error message already sent */
516       return false;
517    }
518
519    dev->VolCatInfo.VolCatWrites++;
520    Dmsg1(1300, "Write block of %u bytes\n", wlen);
521 #ifdef DEBUG_BLOCK_ZEROING
522    uint32_t *bp = (uint32_t *)block->buf;
523    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
524       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
525    }
526 #endif
527
528    /*
529     * Do write here, make a somewhat feeble attempt to recover from 
530     *  I/O errors, or from the OS telling us it is busy.
531     */ 
532    int retry = 0;
533    errno = 0;
534    stat = 0;
535    do {
536       if (retry > 0 && stat == -1 && errno == EBUSY) {
537          berrno be;
538          Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
539                retry, stat, errno, be.bstrerror());
540          bmicrosleep(5, 0);    /* pause a bit if busy or lots of errors */
541          dev->clrerror(-1);
542       }
543       stat = dev->write(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.bstrerror());
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    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
616    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
617       dcr->VolFirstIndex = block->FirstIndex;
618    }
619    if (block->LastIndex > 0) {
620       dcr->VolLastIndex = block->LastIndex;
621    }
622    dcr->WroteVol = true;
623    dev->file_addr += wlen;            /* update file address */
624    dev->file_size += wlen;
625    dev->part_size += wlen;
626
627    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
628    empty_block(block);
629    return true;
630 }
631
632 static void reread_last_block(DCR *dcr)
633 {
634 #define CHECK_LAST_BLOCK
635 #ifdef  CHECK_LAST_BLOCK
636    bool ok = true;
637    DEVICE *dev = dcr->dev;
638    JCR *jcr = dcr->jcr;
639    DEV_BLOCK *block = dcr->block;
640    /*
641     * If the device is a tape and it supports backspace record,
642     *   we backspace over one or two eof marks depending on
643     *   how many we just wrote, then over the last record,
644     *   then re-read it and verify that the block number is
645     *   correct.
646     */
647    if (dev->is_tape() && dev->has_cap(CAP_BSR)) {
648       /* Now back up over what we wrote and read the last block */
649       if (!dev->bsf(1)) {
650          berrno be;
651          ok = false;
652          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
653               be.bstrerror(dev->dev_errno));
654       }
655       if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
656          berrno be;
657          ok = false;
658          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
659               be.bstrerror(dev->dev_errno));
660       }
661       /* Backspace over record */
662       if (ok && !dev->bsr(1)) {
663          berrno be;
664          ok = false;
665          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
666               be.bstrerror(dev->dev_errno));
667          /*
668           *  On FreeBSD systems, if the user got here, it is likely that his/her
669           *    tape drive is "frozen".  The correct thing to do is a
670           *    rewind(), but if we do that, higher levels in cleaning up, will
671           *    most likely write the EOS record over the beginning of the
672           *    tape.  The rewind *is* done later in mount.c when another
673           *    tape is requested. Note, the clrerror() call in bsr()
674           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
675           */
676       }
677       if (ok) {
678          DEV_BLOCK *lblock = new_block(dev);
679          /* Note, this can destroy dev->errmsg */
680          dcr->block = lblock;
681          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
682             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
683                  dev->errmsg);
684          } else {
685             /*
686              * If we wrote block and the block numbers don't agree
687              *  we have a possible problem.
688              */
689             if (lblock->VolSessionId == block->VolSessionId &&
690                 lblock->BlockNumber+1 != block->BlockNumber) {
691                Jmsg(jcr, M_ERROR, 0, _(
692 "Re-read of last block OK, but block numbers differ. Last block=%u Current block=%u.\n"),
693                     lblock->BlockNumber, block->BlockNumber);
694             } else {
695                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
696             }
697          }
698          free_block(lblock);
699          dcr->block = block;
700       }
701    }
702 #endif
703 }
704
705 static bool terminate_writing_volume(DCR *dcr)
706 {
707    DEVICE *dev = dcr->dev;
708    bool ok = true;
709
710    /* Create a JobMedia record to indicated end of tape */
711    dev->VolCatInfo.VolCatFiles = dev->file;
712    if (!dir_create_jobmedia_record(dcr)) {
713       Dmsg0(190, "Error from create JobMedia\n");
714       dev->dev_errno = EIO;
715        Jmsg(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
716             dcr->VolCatInfo.VolCatName, dcr->jcr->Job);
717        ok = false;
718        goto bail_out;
719    }
720    dcr->block->write_failed = true;
721    if (!dev->weof(1)) {         /* end the tape */
722       dev->VolCatInfo.VolCatErrors++;
723       Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
724            "%s"), dev->errmsg);
725       ok = false;
726       Dmsg0(100, "WEOF error.\n");
727    }
728    if (ok) {
729       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
730    }
731    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
732    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
733    
734    if (dev->is_dvd()) {
735       if (!dvd_write_part(dcr)) {             /* write last part */
736          dev->VolCatInfo.VolCatErrors++;
737          Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
738                                  "This Volume may not be readable.\n%s"),
739                          dev->errmsg);
740          ok = false;
741          Dmsg0(100, "dvd_write_part error.\n");
742       }
743       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
744    }
745    
746    if (!dir_update_volume_info(dcr, false)) {
747       ok = false;
748    }
749    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
750
751    /*
752     * Walk through all attached dcrs setting flag to call
753     * set_new_file_parameters() when that dcr is next used.
754     */
755    DCR *mdcr;
756    foreach_dlist(mdcr, dev->attached_dcrs) {
757       if (mdcr->jcr->JobId == 0) {
758          continue;
759       }
760       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
761    }
762    /* Set new file/block parameters for current dcr */
763    set_new_file_parameters(dcr);
764
765    if (ok && dev->has_cap(CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
766       dev->VolCatInfo.VolCatErrors++;
767       /* This may not be fatal since we already wrote an EOF */
768       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
769    }
770 bail_out:
771    dev->set_ateot();                  /* no more writing this tape */
772    Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
773    return ok;
774 }
775
776 /*
777  * Do bookkeeping when a new file is created on a Volume. This is
778  *  also done for disk files to generate the jobmedia records for
779  *  quick seeking.
780  */
781 static bool do_new_file_bookkeeping(DCR *dcr) 
782 {
783    DEVICE *dev = dcr->dev;
784    JCR *jcr = dcr->jcr;
785
786    /* Create a JobMedia record so restore can seek */
787    if (!dir_create_jobmedia_record(dcr)) {
788       Dmsg0(190, "Error from create_job_media.\n");
789       dev->dev_errno = EIO;
790       Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
791            dcr->VolCatInfo.VolCatName, jcr->Job);
792       terminate_writing_volume(dcr);
793       dev->dev_errno = EIO;
794       return false;
795    }
796    dev->VolCatInfo.VolCatFiles = dev->file;
797    if (!dir_update_volume_info(dcr, false)) {
798       Dmsg0(190, "Error from update_vol_info.\n");
799       terminate_writing_volume(dcr);
800       dev->dev_errno = EIO;
801       return false;
802    }
803    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
804
805    /*
806     * Walk through all attached dcrs setting flag to call
807     * set_new_file_parameters() when that dcr is next used.
808     */
809    DCR *mdcr;
810    foreach_dlist(mdcr, dev->attached_dcrs) {
811       if (mdcr->jcr->JobId == 0) {
812          continue;
813       }
814       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
815    }
816    /* Set new file/block parameters for current dcr */
817    set_new_file_parameters(dcr);
818    return true;
819 }
820
821 /*
822  * Do all checks for DVD sizes during writing.
823  */
824 static bool do_dvd_size_checks(DCR *dcr) 
825 {
826    DEVICE *dev = dcr->dev;
827    JCR *jcr = dcr->jcr;
828    DEV_BLOCK *block = dcr->block;
829
830    /* Don't go further if the device is not a dvd */
831    if (!dev->is_dvd()) {
832       return true;
833    }
834    
835    /* Limit maximum part size to value specified by user 
836     */
837    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
838       if (dev->part < dev->num_dvd_parts) {
839          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
840                " is less than the total number of parts (%d/%d, device=%s)\n"),
841                dev->part, dev->num_dvd_parts, dev->print_name());
842          dev->dev_errno = EIO;
843          return false;
844       }
845       
846       if (dvd_open_next_part(dcr) < 0) {
847          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
848                 dev->print_name(), dev->bstrerror());
849          dev->dev_errno = EIO;
850          return false;
851       }
852       
853       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
854             
855       if (!dir_update_volume_info(dcr, false)) {
856          Dmsg0(190, "Error from update_vol_info.\n");
857          dev->dev_errno = EIO;
858          return false;
859       }
860    }
861
862    dev->update_freespace();
863    
864    if (!dev->is_freespace_ok()) { /* Error while getting free space */
865       char ed1[50], ed2[50];
866       Dmsg1(100, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
867       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
868          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
869            dev->VolCatInfo.VolCatName,
870            dev->file, dev->block_num, dev->print_name(),
871            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
872            dev->free_space_errno, dev->errmsg);
873       dev->dev_errno = dev->free_space_errno;
874       return false;
875    }
876    
877    if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
878       char ed1[50], ed2[50];
879       Dmsg0(100, "==== Just enough free space on the device to write the current part...\n");
880       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
881          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
882             dev->VolCatInfo.VolCatName,
883             dev->file, dev->block_num, dev->print_name(),
884             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
885             dev->free_space_errno);
886       terminate_writing_volume(dcr);
887       dev->dev_errno = ENOSPC;
888       return false;
889    }   
890    return true;
891 }
892
893
894 /*
895  * Read block with locking
896  *
897  */
898 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
899 {
900    bool ok;
901    DEVICE *dev = dcr->dev;
902    Dmsg0(250, "Enter read_block_from_device\n");
903    dev->r_dlock();
904    ok = read_block_from_dev(dcr, check_block_numbers);
905    dev->dunlock();
906    Dmsg0(250, "Leave read_block_from_device\n");
907    return ok;
908 }
909
910 /*
911  * Read the next block into the block structure and unserialize
912  *  the block header.  For a file, the block may be partially
913  *  or completely in the current buffer.
914  */
915 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
916 {
917    ssize_t stat;
918    int looping;
919    uint32_t BlockNumber;
920    int retry;
921    JCR *jcr = dcr->jcr;
922    DEVICE *dev = dcr->dev;
923    DEV_BLOCK *block = dcr->block;
924
925    ASSERT(dev->is_open());
926    
927    if (dev->at_eot()) {
928       return false;
929    }
930    looping = 0;
931    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
932          block->buf_len);
933 reread:
934    if (looping > 1) {
935       dev->dev_errno = EIO;
936       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
937          dev->print_name());
938       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
939       block->read_len = 0;
940       return false;
941    }
942    
943 // #define lots_of_debug
944 #ifdef lots_of_debug
945    if (dev->at_eof() && dev->is_dvd()) {
946       Dmsg1(100, "file_size=%u\n",(unsigned int)dev->file_size);
947       Dmsg1(100, "file_addr=%u\n",(unsigned int)dev->file_addr);
948       Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd(), 0, SEEK_CUR));
949       Dmsg1(100, "part_start=%u\n",(unsigned int)dev->part_start);
950       Dmsg1(100, "part_size=%u\n", (unsigned int)dev->part_size);
951       Dmsg2(100, "part=%u num_dvd_parts=%u\n", dev->part, dev->num_dvd_parts);
952       Dmsg1(100, "VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
953       Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
954          ((dev->file_addr-dev->part_start) == dev->part_size), 
955          (dev->part <= dev->VolCatInfo.VolCatParts));
956   }
957 #endif
958
959    /* Check for DVD part file end */
960    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
961         dev->part <= dev->num_dvd_parts) {
962       Dmsg0(400, "Call dvd_open_next_part\n");
963       if (dvd_open_next_part(dcr) < 0) {
964          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
965                dev->part, dev->print_name(), dev->bstrerror());
966          dev->dev_errno = EIO;
967          return false;
968       }
969    }
970    
971    retry = 0;
972    errno = 0;
973    stat = 0;
974    do {
975       if ((retry > 0 && stat == -1 && errno == EBUSY)) {
976          berrno be;
977          Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
978                retry, stat, errno, be.bstrerror());
979          bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
980          dev->clrerror(-1);
981       }
982       stat = dev->read(block->buf, (size_t)block->buf_len);
983
984    } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
985    if (stat < 0) {
986       berrno be;
987       dev->clrerror(-1);
988       Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
989       block->read_len = 0;
990       Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
991          dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
992       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
993       if (dev->at_eof()) {        /* EOF just seen? */
994          dev->set_eot();          /* yes, error => EOT */
995       }
996       return false;
997    }
998    Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
999       dev->file, dev->block_num);
1000    if (stat == 0) {             /* Got EOF ! */
1001       dev->block_num = 0;
1002       block->read_len = 0;
1003       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1004          dev->file, dev->block_num, dev->print_name());
1005       if (dev->at_eof()) {       /* EOF already read? */
1006          dev->set_eot();         /* yes, 2 EOFs => EOT */
1007          return 0;
1008       }
1009       dev->set_ateof();
1010       return false;             /* return eof */
1011    }
1012
1013    /* Continue here for successful read */
1014
1015    block->read_len = stat;      /* save length read */
1016    if (block->read_len == 80 && 
1017         (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
1018          dcr->device->label_type != B_BACULA_LABEL)) {
1019       /* ***FIXME*** should check label */
1020       Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
1021       dev->clear_eof();
1022       goto reread;             /* skip ANSI/IBM label */
1023    }
1024                                           
1025    if (block->read_len < BLKHDR2_LENGTH) {
1026       dev->dev_errno = EIO;
1027       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1028          dev->file, dev->block_num, block->read_len, dev->print_name());
1029       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1030       dev->set_short_block();   
1031       block->read_len = block->binbuf = 0;
1032       return false;             /* return error */
1033    }
1034
1035    BlockNumber = block->BlockNumber + 1;
1036    if (!unser_block_header(jcr, dev, block)) {
1037       if (forge_on) {
1038          dev->file_addr += block->read_len;
1039          dev->file_size += block->read_len;
1040          goto reread;
1041       }
1042       return false;
1043    }
1044
1045    /*
1046     * If the block is bigger than the buffer, we reposition for
1047     *  re-reading the block, allocate a buffer of the correct size,
1048     *  and go re-read.
1049     */
1050    if (block->block_len > block->buf_len) {
1051       dev->dev_errno = EIO;
1052       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1053          block->block_len, block->buf_len);
1054       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1055       Pmsg1(000, "%s", dev->errmsg);
1056       /* Attempt to reposition to re-read the block */
1057       if (dev->is_tape()) {
1058          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1059          if (!dev->bsr(1)) {
1060             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1061             block->read_len = 0;
1062             return false;
1063          }
1064       } else {
1065          Dmsg0(250, "Seek to beginning of block for reread.\n");
1066          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1067          pos -= block->read_len;
1068          dev->lseek(dcr, pos, SEEK_SET);
1069          dev->file_addr = pos;
1070       }
1071       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1072       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1073       Pmsg1(000, "%s", dev->errmsg);
1074       /* Set new block length */
1075       dev->max_block_size = block->block_len;
1076       block->buf_len = block->block_len;
1077       free_memory(block->buf);
1078       block->buf = get_memory(block->buf_len);
1079       empty_block(block);
1080       looping++;
1081       goto reread;                    /* re-read block with correct block size */
1082    }
1083
1084    if (block->block_len > block->read_len) {
1085       dev->dev_errno = EIO;
1086       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1087          dev->file, dev->block_num, block->read_len, dev->print_name());
1088       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1089       dev->set_short_block();
1090       block->read_len = block->binbuf = 0;
1091       return false;             /* return error */
1092    }
1093
1094    dev->clear_short_block();
1095    dev->clear_eof();
1096    dev->VolCatInfo.VolCatReads++;
1097    dev->VolCatInfo.VolCatRBytes += block->read_len;
1098
1099    dev->EndBlock = dev->block_num;
1100    dev->EndFile  = dev->file;
1101    dev->block_num++;
1102
1103    /* Update dcr values */
1104    if (dev->is_tape()) {
1105       dcr->EndBlock = dev->EndBlock;
1106       dcr->EndFile  = dev->EndFile;
1107    } else {
1108       uint64_t addr = dev->file_addr + block->read_len - 1;
1109       dcr->EndBlock = (uint32_t)addr;
1110       dcr->EndFile = (uint32_t)(addr >> 32);
1111       dev->block_num = dcr->EndBlock;
1112       dev->file = dcr->EndFile;
1113    }
1114    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
1115    dev->file_addr += block->read_len;
1116    dev->file_size += block->read_len;
1117
1118    /*
1119     * If we read a short block on disk,
1120     * seek to beginning of next block. This saves us
1121     * from shuffling blocks around in the buffer. Take a
1122     * look at this from an efficiency stand point later, but
1123     * it should only happen once at the end of each job.
1124     *
1125     * I've been lseek()ing negative relative to SEEK_CUR for 30
1126     *   years now. However, it seems that with the new off_t definition,
1127     *   it is not possible to seek negative amounts, so we use two
1128     *   lseek(). One to get the position, then the second to do an
1129     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1130     */
1131    Dmsg0(250, "At end of read block\n");
1132    if (block->read_len > block->block_len && !dev->is_tape()) {
1133       char ed1[50];
1134       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1135       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1136       pos -= (block->read_len - block->block_len);
1137       dev->lseek(dcr, pos, SEEK_SET);
1138       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1139          edit_int64(pos, ed1), block->block_len,
1140             block->read_len);
1141       dev->file_addr = pos;
1142       dev->file_size = pos;
1143    }
1144    Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1145       block->read_len, block->block_len);
1146    block->block_read = true;
1147    return true;
1148 }