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