]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
Fix three-pool regress bug
[bacula/bacula] / bacula / src / stored / block.c
1 /*
2    Bacula® - The Network Backup Solution
3
4    Copyright (C) 2001-2010 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 Kern Sibbald.
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  */
36
37
38 #include "bacula.h"
39 #include "stored.h"
40
41 static bool terminate_writing_volume(DCR *dcr);
42 static bool do_new_file_bookkeeping(DCR *dcr);
43 static bool do_dvd_size_checks(DCR *dcr);
44 static void reread_last_block(DCR *dcr);
45
46 /*
47  * Dump the block header, then walk through
48  * the block printing out the record headers.
49  */
50 void dump_block(DEV_BLOCK *b, const char *msg)
51 {
52    ser_declare;
53    char *p;
54    char Id[BLKHDR_ID_LENGTH+1];
55    uint32_t CheckSum, BlockCheckSum;
56    uint32_t block_len;
57    uint32_t BlockNumber;
58    uint32_t VolSessionId, VolSessionTime, data_len;
59    int32_t  FileIndex;
60    int32_t  Stream;
61    int bhl, rhl;
62    char buf1[100], buf2[100];
63
64    unser_begin(b->buf, BLKHDR1_LENGTH);
65    unser_uint32(CheckSum);
66    unser_uint32(block_len);
67    unser_uint32(BlockNumber);
68    unser_bytes(Id, BLKHDR_ID_LENGTH);
69    ASSERT(unser_length(b->buf) == BLKHDR1_LENGTH);
70    Id[BLKHDR_ID_LENGTH] = 0;
71    if (Id[3] == '2') {
72       unser_uint32(VolSessionId);
73       unser_uint32(VolSessionTime);
74       bhl = BLKHDR2_LENGTH;
75       rhl = RECHDR2_LENGTH;
76    } else {
77       VolSessionId = VolSessionTime = 0;
78       bhl = BLKHDR1_LENGTH;
79       rhl = RECHDR1_LENGTH;
80    }
81
82    if (block_len > 100000) {
83       Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len);
84       return;
85    }
86
87    BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
88                          block_len-BLKHDR_CS_LENGTH);
89    Pmsg6(000, _("Dump block %s %x: size=%d BlkNum=%d\n"
90 "               Hdrcksum=%x cksum=%x\n"),
91       msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
92    p = b->buf + bhl;
93    while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) {
94       unser_begin(p, WRITE_RECHDR_LENGTH);
95       if (rhl == RECHDR1_LENGTH) {
96          unser_uint32(VolSessionId);
97          unser_uint32(VolSessionTime);
98       }
99       unser_int32(FileIndex);
100       unser_int32(Stream);
101       unser_uint32(data_len);
102       Pmsg6(000, _("   Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n"),
103            VolSessionId, VolSessionTime, FI_to_ascii(buf1, FileIndex),
104            stream_to_ascii(buf2, Stream, FileIndex), data_len, p);
105       p += data_len + rhl;
106   }
107 }
108
109 /*
110  * Create a new block structure.
111  * We pass device so that the block can inherit the
112  * min and max block sizes.
113  */
114 DEV_BLOCK *new_block(DEVICE *dev)
115 {
116    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
117
118    memset(block, 0, sizeof(DEV_BLOCK));
119
120    /* If the user has specified a max_block_size, use it as the default */
121    if (dev->max_block_size == 0) {
122       block->buf_len = DEFAULT_BLOCK_SIZE;
123    } else {
124       block->buf_len = dev->max_block_size;
125    }
126    block->dev = dev;
127    block->block_len = block->buf_len;  /* default block size */
128    block->buf = get_memory(block->buf_len);
129    empty_block(block);
130    block->BlockVer = BLOCK_VER;       /* default write version */
131    Dmsg1(650, "Returning new block=%x\n", block);
132    return block;
133 }
134
135
136 /*
137  * Duplicate an existing block (eblock)
138  */
139 DEV_BLOCK *dup_block(DEV_BLOCK *eblock)
140 {
141    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
142    int buf_len = sizeof_pool_memory(eblock->buf);
143
144    memcpy(block, eblock, sizeof(DEV_BLOCK));
145    block->buf = get_memory(buf_len);
146    memcpy(block->buf, eblock->buf, buf_len);
147    return block;
148 }
149
150
151 /*
152  * Only the first block checksum error was reported.
153  *   If there are more, report it now.
154  */
155 void print_block_read_errors(JCR *jcr, DEV_BLOCK *block)
156 {
157    if (block->read_errors > 1) {
158       Jmsg(jcr, M_ERROR, 0, _("%d block read errors not printed.\n"),
159          block->read_errors);
160    }
161 }
162
163 /*
164  * Free block
165  */
166 void free_block(DEV_BLOCK *block)
167 {
168    Dmsg1(999, "free_block buffer %x\n", block->buf);
169    free_memory(block->buf);
170    Dmsg1(999, "free_block block %x\n", block);
171    free_memory((POOLMEM *)block);
172 }
173
174 /* Empty the block -- for writing */
175 void empty_block(DEV_BLOCK *block)
176 {
177    block->binbuf = WRITE_BLKHDR_LENGTH;
178    block->bufp = block->buf + block->binbuf;
179    block->read_len = 0;
180    block->write_failed = false;
181    block->block_read = false;
182    block->FirstIndex = block->LastIndex = 0;
183 }
184
185 /*
186  * Create block header just before write. The space
187  * in the buffer should have already been reserved by
188  * init_block.
189  */
190 static void ser_block_header(DEV_BLOCK *block, bool do_checksum)
191 {
192    ser_declare;
193    uint32_t CheckSum = 0;
194    uint32_t block_len = block->binbuf;
195
196    Dmsg1(1390, "ser_block_header: block_len=%d\n", block_len);
197    ser_begin(block->buf, BLKHDR2_LENGTH);
198    ser_uint32(CheckSum);
199    ser_uint32(block_len);
200    ser_uint32(block->BlockNumber);
201    ser_bytes(WRITE_BLKHDR_ID, BLKHDR_ID_LENGTH);
202    if (BLOCK_VER >= 2) {
203       ser_uint32(block->VolSessionId);
204       ser_uint32(block->VolSessionTime);
205    }
206
207    /* Checksum whole block except for the checksum */
208    if (do_checksum) {
209       CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
210                     block_len-BLKHDR_CS_LENGTH);
211    }
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 && dev->do_checksum()) {
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          Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
369             dcr->getVolCatName(), 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       } else {
378          set_new_file_parameters(dcr);
379       }
380    }
381
382    if (!write_block_to_dev(dcr)) {
383        if (job_canceled(jcr) || jcr->getJobType() == 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    if (job_canceled(jcr)) {
419       return false;
420    }
421    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
422    ASSERT(dev->is_open());
423
424    /* dump_block(block, "before write"); */
425    if (dev->at_weot()) {
426       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
427       dev->dev_errno = ENOSPC;
428       Jmsg0(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
429       return false;
430    }
431    if (!dev->can_append()) {
432       dev->dev_errno = EIO;
433       Jmsg(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume.\n"));
434       return false;
435    }
436    wlen = block->binbuf;
437    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
438       Dmsg0(100, "return write_block_to_dev no data to write\n");
439       return true;
440    }
441    /*
442     * Clear to the end of the buffer if it is not full,
443     *  and on tape devices, apply min and fixed blocking.
444     */
445    if (wlen != block->buf_len) {
446       uint32_t blen;                  /* current buffer length */
447
448       Dmsg2(250, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
449       blen = wlen;
450
451       /* Adjust write size to min/max for tapes only */
452       if (dev->is_tape()) {
453          /* check for fixed block size */
454          if (dev->min_block_size == dev->max_block_size) {
455             wlen = block->buf_len;    /* fixed block size already rounded */
456          /* Check for min block size */
457          } else if (wlen < dev->min_block_size) {
458             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
459          /* Ensure size is rounded */
460          } else {
461             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
462          }
463       }
464       if (wlen-blen > 0) {
465          memset(block->bufp, 0, wlen-blen); /* clear garbage */
466       }
467    }
468
469    ser_block_header(block, dev->do_checksum());
470
471    /* Limit maximum Volume size to value specified by user */
472    hit_max1 = (dev->max_volume_size > 0) &&
473        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
474    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
475        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
476    if (hit_max1 || hit_max2) {
477       char ed1[50];
478       uint64_t max_cap;
479       Dmsg0(100, "==== Output bytes Triggered medium max capacity.\n");
480       if (hit_max1) {
481          max_cap = dev->max_volume_size;
482       } else {
483          max_cap = dev->VolCatInfo.VolCatMaxBytes;
484       }
485       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
486             edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
487       terminate_writing_volume(dcr);
488       reread_last_block(dcr);   /* DEBUG */
489       dev->dev_errno = ENOSPC;
490       return false;
491    }
492
493    /* Limit maximum File size on volume to user specified value */
494    if ((dev->max_file_size > 0) &&
495        (dev->file_size+block->binbuf) >= dev->max_file_size) {
496       dev->file_size = 0;             /* reset file size */
497
498       if (!dev->weof(1)) {            /* write eof */
499          Dmsg0(190, "WEOF error in max file size.\n");
500          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
501             dev->bstrerror());
502          terminate_writing_volume(dcr);
503          dev->dev_errno = ENOSPC;
504          return false;
505       }
506       if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
507          return false;
508       }
509
510       if (!do_new_file_bookkeeping(dcr)) {
511          /* Error message already sent */
512          return false;
513       }
514    }
515    
516    if (!do_dvd_size_checks(dcr)) {
517       /* Error message already sent */
518       return false;
519    }
520
521    dev->VolCatInfo.VolCatWrites++;
522    Dmsg1(1300, "Write block of %u bytes\n", wlen);
523 #ifdef DEBUG_BLOCK_ZEROING
524    uint32_t *bp = (uint32_t *)block->buf;
525    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
526       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
527    }
528 #endif
529
530    /*
531     * Do write here, make a somewhat feeble attempt to recover from 
532     *  I/O errors, or from the OS telling us it is busy.
533     */ 
534    int retry = 0;
535    errno = 0;
536    stat = 0;
537    do {
538       if (retry > 0 && stat == -1 && errno == EBUSY) {
539          berrno be;
540          Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
541                retry, stat, errno, be.bstrerror());
542          bmicrosleep(5, 0);    /* pause a bit if busy or lots of errors */
543          dev->clrerror(-1);
544       }
545       stat = dev->write(block->buf, (size_t)wlen);
546
547    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
548
549 #ifdef DEBUG_BLOCK_ZEROING
550    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
551       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
552    }
553 #endif
554
555    if (stat != (ssize_t)wlen) {
556       /* Some devices simply report EIO when the volume is full.
557        * With a little more thought we may be able to check
558        * capacity and distinguish real errors and EOT
559        * conditions.  In any case, we probably want to
560        * simulate an End of Medium.
561        */
562       if (stat == -1) {
563          berrno be;
564          dev->clrerror(-1);
565          if (dev->dev_errno == 0) {
566             dev->dev_errno = ENOSPC;        /* out of space */
567          }
568          if (dev->dev_errno != ENOSPC) {
569             dev->VolCatInfo.VolCatErrors++;
570             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
571                dev->file, dev->block_num, dev->print_name(), be.bstrerror());
572          }
573       } else {
574         dev->dev_errno = ENOSPC;            /* out of space */
575       }
576       if (dev->dev_errno == ENOSPC) {
577          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
578             dev->getVolCatName(),
579             dev->file, dev->block_num, dev->print_name(), wlen, stat);
580       }
581       if (debug_level >= 100) {
582          berrno be;
583          Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
584             dev->fd(), wlen, stat, dev->block_num, block->BlockNumber, 
585             dev->dev_errno, be.bstrerror(dev->dev_errno));
586       }
587
588       ok = terminate_writing_volume(dcr);
589       if (!ok && !forge_on) {
590          return false;
591       }
592       if (ok) {
593          reread_last_block(dcr);
594       }
595       return false;
596    }
597
598    /* We successfully wrote the block, now do housekeeping */
599    Dmsg2(1300, "VolCatBytes=%d newVolCatBytes=%d\n", (int)dev->VolCatInfo.VolCatBytes,
600       (int)(dev->VolCatInfo.VolCatBytes+wlen));
601    dev->VolCatInfo.VolCatBytes += wlen;         
602    dev->VolCatInfo.VolCatBlocks++;
603    dev->EndBlock = dev->block_num;
604    dev->EndFile  = dev->file;
605    dev->LastBlock = block->BlockNumber;
606    block->BlockNumber++;
607
608    /* Update dcr values */
609    if (dev->is_tape()) {
610       dcr->EndBlock = dev->EndBlock;
611       dcr->EndFile  = dev->EndFile;
612       dev->block_num++;
613    } else {
614       /* Save address of block just written */
615       uint64_t addr = dev->file_addr + wlen - 1;
616       dcr->EndBlock = (uint32_t)addr;
617       dcr->EndFile = (uint32_t)(addr >> 32);
618       dev->block_num = dcr->EndBlock;
619       dev->file = dcr->EndFile;
620    }
621    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
622    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
623       dcr->VolFirstIndex = block->FirstIndex;
624    }
625    if (block->LastIndex > 0) {
626       dcr->VolLastIndex = block->LastIndex;
627    }
628    dcr->WroteVol = true;
629    dev->file_addr += wlen;            /* update file address */
630    dev->file_size += wlen;
631    dev->part_size += wlen;
632
633    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
634    empty_block(block);
635    return true;
636 }
637
638 static void reread_last_block(DCR *dcr)
639 {
640 #define CHECK_LAST_BLOCK
641 #ifdef  CHECK_LAST_BLOCK
642    bool ok = true;
643    DEVICE *dev = dcr->dev;
644    JCR *jcr = dcr->jcr;
645    DEV_BLOCK *block = dcr->block;
646    /*
647     * If the device is a tape and it supports backspace record,
648     *   we backspace over one or two eof marks depending on
649     *   how many we just wrote, then over the last record,
650     *   then re-read it and verify that the block number is
651     *   correct.
652     */
653    if (dev->is_tape() && dev->has_cap(CAP_BSR)) {
654       /* Now back up over what we wrote and read the last block */
655       if (!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       if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
662          berrno be;
663          ok = false;
664          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
665               be.bstrerror(dev->dev_errno));
666       }
667       /* Backspace over record */
668       if (ok && !dev->bsr(1)) {
669          berrno be;
670          ok = false;
671          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
672               be.bstrerror(dev->dev_errno));
673          /*
674           *  On FreeBSD systems, if the user got here, it is likely that his/her
675           *    tape drive is "frozen".  The correct thing to do is a
676           *    rewind(), but if we do that, higher levels in cleaning up, will
677           *    most likely write the EOS record over the beginning of the
678           *    tape.  The rewind *is* done later in mount.c when another
679           *    tape is requested. Note, the clrerror() call in bsr()
680           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
681           */
682       }
683       if (ok) {
684          DEV_BLOCK *lblock = new_block(dev);
685          /* Note, this can destroy dev->errmsg */
686          dcr->block = lblock;
687          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
688             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
689                  dev->errmsg);
690          } else {
691             /*
692              * If we wrote block and the block numbers don't agree
693              *  we have a possible problem.
694              */
695             if (lblock->BlockNumber != dev->LastBlock) {
696                 if (dev->LastBlock > (lblock->BlockNumber + 1)) {
697                    Jmsg(jcr, M_FATAL, 0, _(
698 "Re-read of last block: block numbers differ by more than one.\n"
699 "Probable tape misconfiguration and data loss. Read block=%u Want block=%u.\n"),
700                        lblock->BlockNumber, dev->LastBlock);
701                  } else {
702                    Jmsg(jcr, M_ERROR, 0, _(
703 "Re-read of last block OK, but block numbers differ. Read block=%u Want block=%u.\n"),
704                        lblock->BlockNumber, dev->LastBlock);
705                  }
706             } else {
707                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
708             }
709          }
710          free_block(lblock);
711          dcr->block = block;
712       }
713    }
714 #endif
715 }
716
717 /*
718  * If this routine is called, we do our bookkeeping and
719  *   then assure that the volume will not be written any
720  *   more.
721  */
722 static bool terminate_writing_volume(DCR *dcr)
723 {
724    DEVICE *dev = dcr->dev;
725    bool ok = true;
726
727    /* Create a JobMedia record to indicated end of tape */
728    dev->VolCatInfo.VolCatFiles = dev->file;
729    if (!dir_create_jobmedia_record(dcr)) {
730       Dmsg0(190, "Error from create JobMedia\n");
731       dev->dev_errno = EIO;
732        Jmsg2(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
733             dcr->getVolCatName(), dcr->jcr->Job);
734        ok = false;
735    }
736    dcr->block->write_failed = true;
737    if (!dev->weof(1)) {         /* end the tape */
738       dev->VolCatInfo.VolCatErrors++;
739       Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
740            "%s"), dev->errmsg);
741       ok = false;
742       Dmsg0(100, "WEOF error.\n");
743    }
744    if (ok) {
745       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
746    }
747    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
748    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
749    
750    if (dev->is_dvd()) {
751       if (!dvd_write_part(dcr)) {             /* write last part */
752          dev->VolCatInfo.VolCatErrors++;
753          Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
754                                  "This Volume may not be readable.\n%s"),
755                          dev->errmsg);
756          ok = false;
757          Dmsg0(100, "dvd_write_part error.\n");
758       }
759       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
760    }
761    
762    if (!dir_update_volume_info(dcr, false, true)) {
763       ok = false;
764    }
765    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
766
767    /*
768     * Walk through all attached dcrs setting flag to call
769     * set_new_file_parameters() when that dcr is next used.
770     */
771    DCR *mdcr;
772    foreach_dlist(mdcr, dev->attached_dcrs) {
773       if (mdcr->jcr->JobId == 0) {
774          continue;
775       }
776       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
777    }
778    /* Set new file/block parameters for current dcr */
779    set_new_file_parameters(dcr);
780
781    if (ok && dev->has_cap(CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
782       dev->VolCatInfo.VolCatErrors++;
783       /* This may not be fatal since we already wrote an EOF */
784       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
785    }
786
787    dev->set_ateot();                  /* no more writing this tape */
788    Dmsg1(50, "*** Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
789    return ok;
790 }
791
792 /*
793  * Do bookkeeping when a new file is created on a Volume. This is
794  *  also done for disk files to generate the jobmedia records for
795  *  quick seeking.
796  */
797 static bool do_new_file_bookkeeping(DCR *dcr) 
798 {
799    DEVICE *dev = dcr->dev;
800    JCR *jcr = dcr->jcr;
801
802    /* Create a JobMedia record so restore can seek */
803    if (!dir_create_jobmedia_record(dcr)) {
804       Dmsg0(190, "Error from create_job_media.\n");
805       dev->dev_errno = EIO;
806       Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
807            dcr->getVolCatName(), jcr->Job);
808       terminate_writing_volume(dcr);
809       dev->dev_errno = EIO;
810       return false;
811    }
812    dev->VolCatInfo.VolCatFiles = dev->file;
813    if (!dir_update_volume_info(dcr, false, false)) {
814       Dmsg0(190, "Error from update_vol_info.\n");
815       terminate_writing_volume(dcr);
816       dev->dev_errno = EIO;
817       return false;
818    }
819    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
820
821    /*
822     * Walk through all attached dcrs setting flag to call
823     * set_new_file_parameters() when that dcr is next used.
824     */
825    DCR *mdcr;
826    foreach_dlist(mdcr, dev->attached_dcrs) {
827       if (mdcr->jcr->JobId == 0) {
828          continue;
829       }
830       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
831    }
832    /* Set new file/block parameters for current dcr */
833    set_new_file_parameters(dcr);
834    return true;
835 }
836
837 /*
838  * Do all checks for DVD sizes during writing.
839  */
840 static bool do_dvd_size_checks(DCR *dcr) 
841 {
842    DEVICE *dev = dcr->dev;
843    JCR *jcr = dcr->jcr;
844    DEV_BLOCK *block = dcr->block;
845
846    /* Don't go further if the device is not a dvd */
847    if (!dev->is_dvd()) {
848       return true;
849    }
850    
851    /* Limit maximum part size to value specified by user 
852     */
853    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
854       if (dev->part < dev->num_dvd_parts) {
855          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
856                " is less than the total number of parts (%d/%d, device=%s)\n"),
857                dev->part, dev->num_dvd_parts, dev->print_name());
858          dev->dev_errno = EIO;
859          return false;
860       }
861       
862       if (dvd_open_next_part(dcr) < 0) {
863          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
864                 dev->print_name(), dev->bstrerror());
865          dev->dev_errno = EIO;
866          return false;
867       }
868       
869       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
870             
871       if (!dir_update_volume_info(dcr, false, false)) {
872          Dmsg0(190, "Error from update_vol_info.\n");
873          dev->dev_errno = EIO;
874          return false;
875       }
876    }
877
878    dev->update_freespace();
879    
880    if (!dev->is_freespace_ok()) { /* Error while getting free space */
881       char ed1[50], ed2[50];
882       Dmsg1(100, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
883       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
884          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
885            dev->getVolCatName(),
886            dev->file, dev->block_num, dev->print_name(),
887            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
888            dev->free_space_errno, dev->errmsg);
889       dev->dev_errno = dev->free_space_errno;
890       return false;
891    }
892    
893    if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
894       char ed1[50], ed2[50];
895       Dmsg0(100, "==== Just enough free space on the device to write the current part...\n");
896       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
897          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
898             dev->getVolCatName(),
899             dev->file, dev->block_num, dev->print_name(),
900             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
901             dev->free_space_errno);
902       terminate_writing_volume(dcr);
903       dev->dev_errno = ENOSPC;
904       return false;
905    }   
906    return true;
907 }
908
909
910 /*
911  * Read block with locking
912  *
913  */
914 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
915 {
916    bool ok;
917    DEVICE *dev = dcr->dev;
918    Dmsg0(250, "Enter read_block_from_device\n");
919    dev->r_dlock();
920    ok = read_block_from_dev(dcr, check_block_numbers);
921    dev->dunlock();
922    Dmsg0(250, "Leave read_block_from_device\n");
923    return ok;
924 }
925
926 /*
927  * Read the next block into the block structure and unserialize
928  *  the block header.  For a file, the block may be partially
929  *  or completely in the current buffer.
930  */
931 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
932 {
933    ssize_t stat;
934    int looping;
935    uint32_t BlockNumber;
936    int retry;
937    JCR *jcr = dcr->jcr;
938    DEVICE *dev = dcr->dev;
939    DEV_BLOCK *block = dcr->block;
940
941    if (job_canceled(jcr)) {
942       return false;
943    }
944    ASSERT(dev->is_open());
945    
946    if (dev->at_eot()) {
947       return false;
948    }
949    looping = 0;
950    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
951          block->buf_len);
952 reread:
953    if (looping > 1) {
954       dev->dev_errno = EIO;
955       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
956          dev->print_name());
957       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
958       block->read_len = 0;
959       return false;
960    }
961    
962 // #define lots_of_debug
963 #ifdef lots_of_debug
964    if (dev->at_eof() && dev->is_dvd()) {
965       Dmsg1(100, "file_size=%u\n",(unsigned int)dev->file_size);
966       Dmsg1(100, "file_addr=%u\n",(unsigned int)dev->file_addr);
967       Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd(), 0, SEEK_CUR));
968       Dmsg1(100, "part_start=%u\n",(unsigned int)dev->part_start);
969       Dmsg1(100, "part_size=%u\n", (unsigned int)dev->part_size);
970       Dmsg2(100, "part=%u num_dvd_parts=%u\n", dev->part, dev->num_dvd_parts);
971       Dmsg1(100, "VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
972       Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
973          ((dev->file_addr-dev->part_start) == dev->part_size), 
974          (dev->part <= dev->VolCatInfo.VolCatParts));
975   }
976 #endif
977
978    /* Check for DVD part file end */
979    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
980         dev->part <= dev->num_dvd_parts) {
981       Dmsg0(400, "Call dvd_open_next_part\n");
982       if (dvd_open_next_part(dcr) < 0) {
983          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
984                dev->part, dev->print_name(), dev->bstrerror());
985          dev->dev_errno = EIO;
986          return false;
987       }
988    }
989    
990    retry = 0;
991    errno = 0;
992    stat = 0;
993    do {
994       if ((retry > 0 && stat == -1 && errno == EBUSY)) {
995          berrno be;
996          Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
997                retry, stat, errno, be.bstrerror());
998          bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
999          dev->clrerror(-1);
1000       }
1001       stat = dev->read(block->buf, (size_t)block->buf_len);
1002
1003    } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
1004    if (stat < 0) {
1005       berrno be;
1006       dev->clrerror(-1);
1007       Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
1008       block->read_len = 0;
1009       Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
1010          dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
1011       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1012       if (dev->at_eof()) {        /* EOF just seen? */
1013          dev->set_eot();          /* yes, error => EOT */
1014       }
1015       return false;
1016    }
1017    Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
1018       dev->file, dev->block_num);
1019    if (stat == 0) {             /* Got EOF ! */
1020       dev->block_num = 0;
1021       block->read_len = 0;
1022       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1023          dev->file, dev->block_num, dev->print_name());
1024       if (dev->at_eof()) {       /* EOF already read? */
1025          dev->set_eot();         /* yes, 2 EOFs => EOT */
1026          return 0;
1027       }
1028       dev->set_ateof();
1029       return false;             /* return eof */
1030    }
1031
1032    /* Continue here for successful read */
1033
1034    block->read_len = stat;      /* save length read */
1035    if (block->read_len == 80 && 
1036         (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
1037          dcr->device->label_type != B_BACULA_LABEL)) {
1038       /* ***FIXME*** should check label */
1039       Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
1040       dev->clear_eof();
1041       goto reread;             /* skip ANSI/IBM label */
1042    }
1043                                           
1044    if (block->read_len < BLKHDR2_LENGTH) {
1045       dev->dev_errno = EIO;
1046       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1047          dev->file, dev->block_num, block->read_len, dev->print_name());
1048       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1049       dev->set_short_block();   
1050       block->read_len = block->binbuf = 0;
1051       return false;             /* return error */
1052    }
1053
1054    BlockNumber = block->BlockNumber + 1;
1055    if (!unser_block_header(jcr, dev, block)) {
1056       if (forge_on) {
1057          dev->file_addr += block->read_len;
1058          dev->file_size += block->read_len;
1059          goto reread;
1060       }
1061       return false;
1062    }
1063
1064    /*
1065     * If the block is bigger than the buffer, we reposition for
1066     *  re-reading the block, allocate a buffer of the correct size,
1067     *  and go re-read.
1068     */
1069    if (block->block_len > block->buf_len) {
1070       dev->dev_errno = EIO;
1071       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1072          block->block_len, block->buf_len);
1073       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1074       Pmsg1(000, "%s", dev->errmsg);
1075       /* Attempt to reposition to re-read the block */
1076       if (dev->is_tape()) {
1077          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1078          if (!dev->bsr(1)) {
1079             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1080             block->read_len = 0;
1081             return false;
1082          }
1083       } else {
1084          Dmsg0(250, "Seek to beginning of block for reread.\n");
1085          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1086          pos -= block->read_len;
1087          dev->lseek(dcr, pos, SEEK_SET);
1088          dev->file_addr = pos;
1089       }
1090       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1091       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1092       Pmsg1(000, "%s", dev->errmsg);
1093       /* Set new block length */
1094       dev->max_block_size = block->block_len;
1095       block->buf_len = block->block_len;
1096       free_memory(block->buf);
1097       block->buf = get_memory(block->buf_len);
1098       empty_block(block);
1099       looping++;
1100       goto reread;                    /* re-read block with correct block size */
1101    }
1102
1103    if (block->block_len > block->read_len) {
1104       dev->dev_errno = EIO;
1105       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1106          dev->file, dev->block_num, block->read_len, dev->print_name());
1107       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1108       dev->set_short_block();
1109       block->read_len = block->binbuf = 0;
1110       return false;             /* return error */
1111    }
1112
1113    dev->clear_short_block();
1114    dev->clear_eof();
1115    dev->VolCatInfo.VolCatReads++;
1116    dev->VolCatInfo.VolCatRBytes += block->read_len;
1117
1118    dev->EndBlock = dev->block_num;
1119    dev->EndFile  = dev->file;
1120    dev->block_num++;
1121
1122    /* Update dcr values */
1123    if (dev->is_tape()) {
1124       dcr->EndBlock = dev->EndBlock;
1125       dcr->EndFile  = dev->EndFile;
1126    } else {
1127       /* We need to take care about a short block in EndBlock/File
1128        * computation 
1129        */
1130       uint32_t len = MIN(block->read_len, block->block_len);
1131       uint64_t addr = dev->file_addr + len - 1;
1132       dcr->EndBlock = (uint32_t)addr;
1133       dcr->EndFile = (uint32_t)(addr >> 32);
1134       dev->block_num = dev->EndBlock = dcr->EndBlock;
1135       dev->file = dev->EndFile = dcr->EndFile;
1136    }
1137    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
1138    dev->file_addr += block->read_len;
1139    dev->file_size += block->read_len;
1140
1141    /*
1142     * If we read a short block on disk,
1143     * seek to beginning of next block. This saves us
1144     * from shuffling blocks around in the buffer. Take a
1145     * look at this from an efficiency stand point later, but
1146     * it should only happen once at the end of each job.
1147     *
1148     * I've been lseek()ing negative relative to SEEK_CUR for 30
1149     *   years now. However, it seems that with the new off_t definition,
1150     *   it is not possible to seek negative amounts, so we use two
1151     *   lseek(). One to get the position, then the second to do an
1152     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1153     */
1154    Dmsg0(250, "At end of read block\n");
1155    if (block->read_len > block->block_len && !dev->is_tape()) {
1156       char ed1[50];
1157       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1158       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1159       pos -= (block->read_len - block->block_len);
1160       dev->lseek(dcr, pos, SEEK_SET);
1161       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1162          edit_int64(pos, ed1), block->block_len,
1163             block->read_len);
1164       dev->file_addr = pos;
1165       dev->file_size = pos;
1166    }
1167    Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1168       block->read_len, block->block_len);
1169    block->block_read = true;
1170    return true;
1171 }