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