]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
Fail job that attempts to read from closed device -- reported in bug 1885 but not...
[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       return false;
945    }
946    
947    if (dev->at_eot()) {
948       return false;
949    }
950    looping = 0;
951    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
952          block->buf_len);
953
954    if (!dev->is_open()) {
955       Mmsg4(dev->errmsg, _("Attempt to read closed device: fd=%d at file:blk %u:%u on device %s\n"),
956          dev->fd(), dev->file, dev->block_num, dev->print_name());
957       Jmsg(dcr->jcr, M_FATAL, 0, "%s", dev->errmsg);
958       block->read_len = 0;
959       return false;
960     }
961
962 reread:
963    if (looping > 1) {
964       dev->dev_errno = EIO;
965       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
966          dev->print_name());
967       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
968       block->read_len = 0;
969       return false;
970    }
971    
972    /* Check for DVD part file end */
973    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
974         dev->part <= dev->num_dvd_parts) {
975       Dmsg0(400, "Call dvd_open_next_part\n");
976       if (dvd_open_next_part(dcr) < 0) {
977          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
978                dev->part, dev->print_name(), dev->bstrerror());
979          dev->dev_errno = EIO;
980          return false;
981       }
982    }
983    
984    retry = 0;
985    errno = 0;
986    stat = 0;
987    do {
988       if ((retry > 0 && stat == -1 && errno == EBUSY)) {
989          berrno be;
990          Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
991                retry, stat, errno, be.bstrerror());
992          bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
993          dev->clrerror(-1);
994       }
995       stat = dev->read(block->buf, (size_t)block->buf_len);
996
997    } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
998    if (stat < 0) {
999       berrno be;
1000       dev->clrerror(-1);
1001       Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
1002       block->read_len = 0;
1003       Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
1004          dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
1005       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1006       if (dev->at_eof()) {        /* EOF just seen? */
1007          dev->set_eot();          /* yes, error => EOT */
1008       }
1009       return false;
1010    }
1011    Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
1012       dev->file, dev->block_num);
1013    if (stat == 0) {             /* Got EOF ! */
1014       dev->block_num = 0;
1015       block->read_len = 0;
1016       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1017          dev->file, dev->block_num, dev->print_name());
1018       if (dev->at_eof()) {       /* EOF already read? */
1019          dev->set_eot();         /* yes, 2 EOFs => EOT */
1020          return 0;
1021       }
1022       dev->set_ateof();
1023       return false;             /* return eof */
1024    }
1025
1026    /* Continue here for successful read */
1027
1028    block->read_len = stat;      /* save length read */
1029    if (block->read_len == 80 && 
1030         (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
1031          dcr->device->label_type != B_BACULA_LABEL)) {
1032       /* ***FIXME*** should check label */
1033       Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
1034       dev->clear_eof();
1035       goto reread;             /* skip ANSI/IBM label */
1036    }
1037                                           
1038    if (block->read_len < BLKHDR2_LENGTH) {
1039       dev->dev_errno = EIO;
1040       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1041          dev->file, dev->block_num, block->read_len, dev->print_name());
1042       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1043       dev->set_short_block();   
1044       block->read_len = block->binbuf = 0;
1045       return false;             /* return error */
1046    }
1047
1048 // BlockNumber = block->BlockNumber + 1;
1049    if (!unser_block_header(jcr, dev, block)) {
1050       if (forge_on) {
1051          dev->file_addr += block->read_len;
1052          dev->file_size += block->read_len;
1053          goto reread;
1054       }
1055       return false;
1056    }
1057
1058    /*
1059     * If the block is bigger than the buffer, we reposition for
1060     *  re-reading the block, allocate a buffer of the correct size,
1061     *  and go re-read.
1062     */
1063    if (block->block_len > block->buf_len) {
1064       dev->dev_errno = EIO;
1065       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1066          block->block_len, block->buf_len);
1067       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1068       Pmsg1(000, "%s", dev->errmsg);
1069       /* Attempt to reposition to re-read the block */
1070       if (dev->is_tape()) {
1071          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1072          if (!dev->bsr(1)) {
1073             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1074             block->read_len = 0;
1075             return false;
1076          }
1077       } else {
1078          Dmsg0(250, "Seek to beginning of block for reread.\n");
1079          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1080          pos -= block->read_len;
1081          dev->lseek(dcr, pos, SEEK_SET);
1082          dev->file_addr = pos;
1083       }
1084       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1085       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1086       Pmsg1(000, "%s", dev->errmsg);
1087       /* Set new block length */
1088       dev->max_block_size = block->block_len;
1089       block->buf_len = block->block_len;
1090       free_memory(block->buf);
1091       block->buf = get_memory(block->buf_len);
1092       empty_block(block);
1093       looping++;
1094       goto reread;                    /* re-read block with correct block size */
1095    }
1096
1097    if (block->block_len > block->read_len) {
1098       dev->dev_errno = EIO;
1099       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1100          dev->file, dev->block_num, block->read_len, dev->print_name());
1101       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1102       dev->set_short_block();
1103       block->read_len = block->binbuf = 0;
1104       return false;             /* return error */
1105    }
1106
1107    dev->clear_short_block();
1108    dev->clear_eof();
1109    dev->VolCatInfo.VolCatReads++;
1110    dev->VolCatInfo.VolCatRBytes += block->read_len;
1111
1112    dev->EndBlock = dev->block_num;
1113    dev->EndFile  = dev->file;
1114    dev->block_num++;
1115
1116    /* Update dcr values */
1117    if (dev->is_tape()) {
1118       dcr->EndBlock = dev->EndBlock;
1119       dcr->EndFile  = dev->EndFile;
1120    } else {
1121       /* We need to take care about a short block in EndBlock/File
1122        * computation 
1123        */
1124       uint32_t len = MIN(block->read_len, block->block_len);
1125       uint64_t addr = dev->file_addr + len - 1;
1126       dcr->EndBlock = (uint32_t)addr;
1127       dcr->EndFile = (uint32_t)(addr >> 32);
1128       dev->block_num = dev->EndBlock = dcr->EndBlock;
1129       dev->file = dev->EndFile = dcr->EndFile;
1130    }
1131    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
1132    dev->file_addr += block->read_len;
1133    dev->file_size += block->read_len;
1134
1135    /*
1136     * If we read a short block on disk,
1137     * seek to beginning of next block. This saves us
1138     * from shuffling blocks around in the buffer. Take a
1139     * look at this from an efficiency stand point later, but
1140     * it should only happen once at the end of each job.
1141     *
1142     * I've been lseek()ing negative relative to SEEK_CUR for 30
1143     *   years now. However, it seems that with the new off_t definition,
1144     *   it is not possible to seek negative amounts, so we use two
1145     *   lseek(). One to get the position, then the second to do an
1146     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1147     */
1148    Dmsg0(250, "At end of read block\n");
1149    if (block->read_len > block->block_len && !dev->is_tape()) {
1150       char ed1[50];
1151       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1152       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1153       pos -= (block->read_len - block->block_len);
1154       dev->lseek(dcr, pos, SEEK_SET);
1155       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1156          edit_int64(pos, ed1), block->block_len,
1157             block->read_len);
1158       dev->file_addr = pos;
1159       dev->file_size = pos;
1160    }
1161    Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1162       block->read_len, block->block_len);
1163    block->block_read = true;
1164    return true;
1165 }