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