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