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