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