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