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