git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c

   1 /*
   2    Bacula(R) - The Network Backup Solution
   3
   4    Copyright (C) 2000-2017 Kern Sibbald
   5
   6    The original author of Bacula is Kern Sibbald, with contributions
   7    from many others, a complete list can be found in the file AUTHORS.
   8
   9    You may use this file and others of this release according to the
  10    license defined in the LICENSE file, which includes the Affero General
  11    Public License, v3.0 ("AGPLv3") and some additional permissions and
  12    terms pursuant to its AGPLv3 Section 7.
  13
  14    This notice must be preserved when any source code is
  15    conveyed and/or propagated.
  16
  17    Bacula(R) is a registered trademark of Kern Sibbald.
  18 */
  19 /*
  20  *
  21  *   block.c -- tape block handling functions
  22  *
  23  *              Kern Sibbald, March MMI
  24  *                 added BB02 format October MMII
  25  */
  26
  27
  28 #include "bacula.h"
  29 #include "stored.h"
  30
  31 #ifdef DEBUG_BLOCK_CHECKSUM
  32 static const bool debug_block_checksum = true;
  33 #else
  34 static const bool debug_block_checksum = false;
  35 #endif
  36
  37 static int debug_io_error = 0;    /* # blocks to write before creating I/O error */
  38
  39 #ifdef NO_TAPE_WRITE_TEST
  40 static const bool no_tape_write_test = true;
  41 #else
  42 static const bool no_tape_write_test = false;
  43 #endif
  44
  45
  46 uint32_t get_len_and_clear_block(DEV_BLOCK *block, DEVICE *dev, uint32_t &pad);
  47 uint32_t ser_block_header(DEV_BLOCK *block, bool do_checksum);
  48 bool unser_block_header(DCR *dcr, DEVICE *dev, DEV_BLOCK *block);
  49
  50 /*
  51  * Write a block to the device, with locking and unlocking
  52  *
  53  * Returns: true  on success
  54  *        : false on failure
  55  *
  56  */
  57 bool DCR::write_block_to_device(bool final)
  58 {
  59    bool ok = true;
  60    DCR *dcr = this;
  61
  62    if (dcr->spooling) {
  63       Dmsg0(250, "Write to spool\n");
  64       ok = write_block_to_spool_file(dcr);
  65       return ok;
  66    }
  67
  68    if (!is_dev_locked()) {        /* device already locked? */
  69       /* note, do not change this to dcr->rLock */
  70       dev->rLock(false);          /* no, lock it */
  71    }
  72
  73    if (!check_for_newvol_or_newfile(dcr)) {
  74       ok = false;
  75       goto bail_out;   /* fatal error */
  76    }
  77
  78    Dmsg1(500, "Write block to dev=%p\n", dcr->dev);
  79    if (!write_block_to_dev()) {
  80       Dmsg2(40, "*** Failed write_block_to_dev adata=%d block=%p\n",
  81          block->adata, block);
  82       if (job_canceled(jcr) || jcr->getJobType() == JT_SYSTEM) {
  83          ok = false;
  84          Dmsg2(40, "cancel=%d or SYSTEM=%d\n", job_canceled(jcr),
  85             jcr->getJobType() == JT_SYSTEM);
  86       } else {
  87          bool was_adata = false;
  88          if (was_adata) {
  89             dcr->set_ameta();
  90             was_adata = true;
  91          }
  92          /* Flush any existing JobMedia info */
  93          if (!(ok = dir_create_jobmedia_record(dcr))) {
  94             Jmsg(jcr, M_FATAL, 0, _("Error writing JobMedia record to catalog.\n"));
  95          } else {
  96             Dmsg1(40, "Calling fixup_device was_adata=%d...\n", was_adata);
  97             ok = fixup_device_block_write_error(dcr);
  98          }
  99          if (was_adata) {
 100             dcr->set_adata();
 101          }
 102       }
 103    }
 104    if (ok && final && !dir_create_jobmedia_record(dcr)) {
 105       Jmsg(jcr, M_FATAL, 0, _("Error writing final JobMedia record to catalog.\n"));
 106    }
 107
 108 bail_out:
 109    if (!dcr->is_dev_locked()) {        /* did we lock dev above? */
 110       /* note, do not change this to dcr->dunlock */
 111       dev->Unlock();                  /* unlock it now */
 112    }
 113    return ok;
 114 }
 115
 116 /*
 117  * Write a block to the device
 118  *
 119  *  Returns: true  on success or EOT
 120  *           false on hard error
 121  */
 122 bool DCR::write_block_to_dev()
 123 {
 124    ssize_t stat = 0;
 125    uint32_t wlen;                     /* length to write */
 126    bool ok = true;
 127    DCR *dcr = this;
 128    uint32_t checksum;
 129    uint32_t pad;                      /* padding or zeros written */
 130    boffset_t pos;
 131    char ed1[50];
 132
 133    if (no_tape_write_test) {
 134       empty_block(block);
 135       return true;
 136    }
 137    if (job_canceled(jcr)) {
 138       return false;
 139    }
 140    if (!dev->enabled) {
 141       Jmsg1(jcr, M_FATAL, 0,  _("Cannot write block. Device is disabled. dev=%s\n"), dev->print_name());
 142       return false;
 143    }
 144
 145    ASSERT2(block->adata == dev->adata, "Block and dev adata not same");
 146    Dmsg4(200, "fd=%d adata=%d bufp-buf=%d binbuf=%d\n", dev->fd(), block->adata,
 147       block->bufp-block->buf, block->binbuf);
 148    ASSERT2(block->binbuf == ((uint32_t)(block->bufp - block->buf)), "binbuf badly set");
 149
 150    if (is_block_empty(block)) {  /* Does block have data in it? */
 151       Dmsg1(50, "return write_block_to_dev no adata=%d data to write\n", block->adata);
 152       return true;
 153    }
 154
 155    if (dev->at_weot()) {
 156       Dmsg1(50, "==== FATAL: At EOM with ST_WEOT. adata=%d.\n", dev->adata);
 157       dev->dev_errno = ENOSPC;
 158       Jmsg1(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM. dev=%s\n"), dev->print_name());
 159       return false;
 160    }
 161    if (!dev->can_append()) {
 162       dev->dev_errno = EIO;
 163       Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume. dev=%s\n"), dev->print_name());
 164       Dmsg1(50, "Attempt to write on read-only Volume. dev=%s\n", dev->print_name());
 165       return false;
 166    }
 167
 168    if (!dev->is_open()) {
 169       Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on closed device=%s\n"), dev->print_name());
 170       Dmsg1(50, "Attempt to write on closed device=%s\n", dev->print_name());
 171       return false;
 172    }
 173
 174    wlen = get_len_and_clear_block(block, dev, pad);
 175    block->block_len = wlen;
 176    dev->updateVolCatPadding(pad);
 177
 178    checksum = ser_block_header(block, dev->do_checksum());
 179
 180    if (!dev->do_size_checks(dcr, block)) {
 181       Dmsg0(50, "Size check triggered.  Cannot write block.\n");
 182       return false;
 183    }
 184
 185    dev->updateVolCatWrites(1);
 186
 187    dump_block(dev, block, "before write");
 188
 189 #ifdef DEBUG_BLOCK_ZEROING
 190    uint32_t *bp = (uint32_t *)block->buf;
 191    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
 192       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
 193    }
 194 #endif
 195
 196    /*
 197     * If Adata block, we must seek to the correct address
 198     */
 199    if (block->adata) {
 200       ASSERT(dcr->dev->adata);
 201       uint64_t cur = dev->lseek(dcr, 0, SEEK_CUR);
 202       /* If we are going to create a hole, record it */
 203       if (block->BlockAddr != cur) {
 204          dev->lseek(dcr, block->BlockAddr, SEEK_SET);
 205          Dmsg4(100, "Adata seek BlockAddr from %lld to %lld = %lld bytes adata_addr=%lld\n",
 206             cur, block->BlockAddr, block->BlockAddr - cur, dev->adata_addr);
 207          /* Insanity check */
 208          if (block->BlockAddr > cur) {
 209             dev->updateVolCatHoleBytes(block->BlockAddr - cur);
 210          } else if (block->BlockAddr < cur) {
 211            Pmsg5(000, "Vol=%s cur=%lld BlockAddr=%lld adata=%d block=%p\n",
 212               dev->getVolCatName(), cur, block->BlockAddr, block->adata, block);
 213            Jmsg3(jcr, M_FATAL, 0, "Bad seek on adata Vol=%s BlockAddr=%lld DiskAddr=%lld. Multiple simultaneous Jobs?\n",
 214               dev->getVolCatName(), block->BlockAddr, cur);
 215            //Pmsg2(000, "HoleBytes would go negative cur=%lld blkaddr=%lld\n", cur, block->BlockAddr);
 216          }
 217       }
 218    }
 219
 220    /*
 221     * Do write here, make a somewhat feeble attempt to recover from
 222     *  I/O errors, or from the OS telling us it is busy.
 223     */
 224    int retry = 0;
 225    errno = 0;
 226    stat = 0;
 227    /* ***FIXME**** remove next line debug */
 228    pos =  dev->lseek(dcr, 0, SEEK_CUR);
 229    do {
 230       if (retry > 0 && stat == -1 && errno == EBUSY) {
 231          berrno be;
 232          Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
 233                retry, stat, errno, be.bstrerror());
 234          bmicrosleep(5, 0);    /* pause a bit if busy or lots of errors */
 235          dev->clrerror(-1);
 236       }
 237       stat = dev->write(block->buf, (size_t)wlen);
 238       Dmsg4(100, "%s write() BlockAddr=%lld wlen=%d Vol=%s wlen=%d\n",
 239          block->adata?"Adata":"Ameta", block->BlockAddr, wlen,
 240          dev->VolHdr.VolumeName);
 241    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
 242
 243    /* ***FIXME*** remove 2 lines debug */
 244    Dmsg2(100, "Wrote %d bytes at %s\n", wlen, dev->print_addr(ed1, sizeof(ed1), pos));
 245    dump_block(dev, block, "After write");
 246
 247    if (debug_block_checksum) {
 248       uint32_t achecksum = ser_block_header(block, dev->do_checksum());
 249       if (checksum != achecksum) {
 250          Jmsg2(jcr, M_ERROR, 0, _("Block checksum changed during write: before=%u after=%u\n"),
 251             checksum, achecksum);
 252          dump_block(dev, block, "with checksum error");
 253       }
 254    }
 255
 256 #ifdef DEBUG_BLOCK_ZEROING
 257    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
 258       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
 259    }
 260 #endif
 261
 262    if (debug_io_error) {
 263       debug_io_error--;
 264       if (debug_io_error == 1) {  /* trigger error */
 265          stat = -1;
 266          dev->dev_errno = EIO;
 267          errno = EIO;
 268          debug_io_error = 0;      /* turn off trigger */
 269       }
 270    }
 271
 272    if (stat != (ssize_t)wlen) {
 273       /* Some devices simply report EIO when the volume is full.
 274        * With a little more thought we may be able to check
 275        * capacity and distinguish real errors and EOT
 276        * conditions.  In any case, we probably want to
 277        * simulate an End of Medium.
 278        */
 279       if (stat == -1) {
 280          berrno be;
 281          dev->clrerror(-1);                 /* saves errno in dev->dev_errno */
 282          if (dev->dev_errno == 0) {
 283             dev->dev_errno = ENOSPC;        /* out of space */
 284          }
 285          if (dev->dev_errno != ENOSPC) {
 286             int etype = M_ERROR;
 287             if (block->adata) {
 288                etype = M_FATAL;
 289             }
 290             dev->VolCatInfo.VolCatErrors++;
 291             Jmsg4(jcr, etype, 0, _("Write error at %s on device %s Vol=%s. ERR=%s.\n"),
 292                dev->print_addr(ed1, sizeof(ed1)), dev->print_name(),
 293                dev->getVolCatName(), be.bstrerror());
 294             if (dev->get_tape_alerts(this)) {
 295                dev->show_tape_alerts(this, list_long, list_last, alert_callback);
 296             }
 297          }
 298       } else {
 299         dev->dev_errno = ENOSPC;            /* out of space */
 300       }
 301       if (dev->dev_errno == ENOSPC) {
 302          dev->update_freespace();
 303          if (dev->is_freespace_ok() && dev->free_space < dev->min_free_space) {
 304             int mtype = M_FATAL;
 305             dev->set_nospace();
 306             if (dev->is_removable()) {
 307                mtype = M_INFO;
 308             }
 309             Jmsg(jcr, mtype, 0, _("Out of freespace caused End of Volume \"%s\" at %s on device %s. Write of %u bytes got %d.\n"),
 310                dev->getVolCatName(),
 311                dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), wlen, stat);
 312          } else {
 313             dev->clear_nospace();
 314             Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %s on device %s. Write of %u bytes got %d.\n"),
 315                dev->getVolCatName(),
 316                dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), wlen, stat);
 317          }
 318       }
 319       if (chk_dbglvl(100)) {
 320          berrno be;
 321          Dmsg7(90, "==== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
 322             dev->fd(), wlen, stat, dev->block_num, block->BlockNumber,
 323             dev->dev_errno, be.bstrerror(dev->dev_errno));
 324       }
 325
 326       Dmsg0(40, "Calling terminate_writing_volume\n");
 327       ok = terminate_writing_volume(dcr);
 328       if (ok) {
 329          reread_last_block(dcr);
 330       }
 331       return false;
 332    }
 333
 334    /* We successfully wrote the block, now do housekeeping */
 335    Dmsg2(1300, "VolCatBytes=%lld newVolCatBytes=%lld\n", dev->VolCatInfo.VolCatBytes,
 336       (dev->VolCatInfo.VolCatBytes+wlen));
 337    if (!dev->setVolCatAdataBytes(block->BlockAddr + wlen)) {
 338       dev->updateVolCatBytes(wlen);
 339       Dmsg3(200, "AmetaBytes=%lld AdataBytes=%lld Bytes=%lld\n",
 340          dev->VolCatInfo.VolCatAmetaBytes, dev->VolCatInfo.VolCatAdataBytes, dev->VolCatInfo.VolCatBytes);
 341    }
 342    dev->updateVolCatBlocks(1);
 343    dev->LastBlock = block->BlockNumber;
 344    block->BlockNumber++;
 345
 346    /* Update dcr values */
 347    if (dev->is_tape()) {
 348       dev->EndAddr = dev->get_full_addr();
 349       if (dcr->EndAddr < dev->EndAddr) {
 350          dcr->EndAddr = dev->EndAddr;
 351       }
 352       dev->block_num++;
 353    } else {
 354       /* Save address of byte just written */
 355       uint64_t addr = dev->file_addr + wlen - 1;
 356       if (dev->is_indexed()) {
 357          uint64_t full_addr = dev->get_full_addr(addr);
 358          if (full_addr < dcr->EndAddr) {
 359             Pmsg2(000, "Possible incorrect EndAddr oldEndAddr=%llu newEndAddr=%llu\n",
 360                dcr->EndAddr, full_addr);
 361          }
 362          dcr->EndAddr = full_addr;
 363       }
 364
 365       if (dev->adata) {
 366          /* We really should use file_addr, but I am not sure it is correctly set */
 367          Dmsg3(100, "Set BlockAddr from %lld to %lld adata_addr=%lld\n",
 368             block->BlockAddr, block->BlockAddr + wlen, dev->adata_addr);
 369          block->BlockAddr += wlen;
 370          dev->adata_addr = block->BlockAddr;
 371       } else {
 372          block->BlockAddr = dev->get_full_addr() + wlen;
 373       }
 374    }
 375    if (dev->is_indexed()) {
 376       if (dcr->VolMediaId != dev->VolCatInfo.VolMediaId) {
 377          Dmsg7(100, "JobMedia Vol=%s wrote=%d MediaId=%lld FI=%lu LI=%lu StartAddr=%lld EndAddr=%lld Wrote\n",
 378             dcr->VolumeName, dcr->WroteVol, dcr->VolMediaId,
 379             dcr->VolFirstIndex, dcr->VolLastIndex, dcr->StartAddr, dcr->EndAddr);
 380       }
 381       dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
 382       Dmsg3(150, "VolFirstIndex=%d blockFirstIndex=%d Vol=%s\n",
 383          dcr->VolFirstIndex, block->FirstIndex, dcr->VolumeName);
 384       if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
 385          dcr->VolFirstIndex = block->FirstIndex;
 386       }
 387       if (block->LastIndex > (int32_t)dcr->VolLastIndex) {
 388          dcr->VolLastIndex = block->LastIndex;
 389       }
 390       dcr->WroteVol = true;
 391    }
 392
 393    dev->file_addr += wlen;            /* update file address */
 394    dev->file_size += wlen;
 395    dev->usage += wlen;                /* update usage counter */
 396    if (dev->part > 0) {
 397       dev->part_size += wlen;
 398    }
 399    dev->setVolCatInfo(false);         /* Needs update */
 400
 401    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
 402    empty_block(block);
 403    return true;
 404 }
 405
 406
 407 /*
 408  * Read block with locking
 409  *
 410  */
 411 bool DCR::read_block_from_device(bool check_block_numbers)
 412 {
 413    bool ok;
 414
 415    Dmsg0(250, "Enter read_block_from_device\n");
 416    dev->rLock(false);
 417    ok = read_block_from_dev(check_block_numbers);
 418    dev->rUnlock();
 419    Dmsg1(250, "Leave read_block_from_device. ok=%d\n", ok);
 420    return ok;
 421 }
 422
 423 static void set_block_position(DCR *dcr, DEVICE *dev, DEV_BLOCK *block)
 424 {
 425    /* Used also by the Single Item Restore code to locate a particular block */
 426    if (dev->is_tape()) {
 427       block->BlockAddr = dev->get_full_addr();
 428
 429    } else if (!dev->adata) {    /* TODO: See if we just use !dev->adata for tapes */
 430       /* Note: we only update the DCR values for ameta blocks
 431        * because all the indexing (JobMedia) is done with
 432        * ameta blocks/records, which may point to adata.
 433        */
 434       block->BlockAddr = dev->get_full_addr();
 435    }
 436    block->RecNum = 0;
 437 }
 438
 439 /*
 440  * Read the next block into the block structure and unserialize
 441  *  the block header.  For a file, the block may be partially
 442  *  or completely in the current buffer.
 443  * Note: in order for bscan to generate correct JobMedia records
 444  *  we must be careful to update the EndAddr of the last byte read.
 445  */
 446 bool DCR::read_block_from_dev(bool check_block_numbers)
 447 {
 448    ssize_t stat;
 449    int looping;
 450    int retry;
 451    DCR *dcr = this;
 452    boffset_t pos;
 453    char ed1[50];
 454    uint32_t data_len;
 455
 456    if (job_canceled(jcr)) {
 457       Mmsg(dev->errmsg, _("Job failed or canceled.\n"));
 458       Dmsg1(000, "%s", dev->errmsg);
 459       block->read_len = 0;
 460       return false;
 461    }
 462    if (!dev->enabled) {
 463       Mmsg(dev->errmsg, _("Cannot write block. Device is disabled. dev=%s\n"), dev->print_name());
 464       Jmsg1(jcr, M_FATAL, 0, "%s", dev->errmsg);
 465       return false;
 466    }
 467
 468    if (dev->at_eot()) {
 469       Mmsg(dev->errmsg, _("At EOT: attempt to read past end of Volume.\n"));
 470       Dmsg1(000, "%s", dev->errmsg);
 471       block->read_len = 0;
 472       return false;
 473    }
 474    looping = 0;
 475
 476    if (!dev->is_open()) {
 477       Mmsg4(dev->errmsg, _("Attempt to read closed device: fd=%d at file:blk %u:%u on device %s\n"),
 478          dev->fd(), dev->file, dev->block_num, dev->print_name());
 479       Jmsg(dcr->jcr, M_FATAL, 0, "%s", dev->errmsg);
 480       Pmsg4(000, "Fatal: dev=%p dcr=%p adata=%d bytes=%lld\n", dev, dcr, dev->adata,
 481          VolCatInfo.VolCatAdataRBytes);
 482       Pmsg1(000, "%s", dev->errmsg);
 483       block->read_len = 0;
 484       return false;
 485    }
 486
 487    set_block_position(dcr, dev, block);
 488
 489 reread:
 490    if (looping > 1) {
 491       dev->dev_errno = EIO;
 492       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
 493          dev->print_name());
 494       Dmsg1(000, "%s", dev->errmsg);
 495       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
 496       block->read_len = 0;
 497       return false;
 498    }
 499
 500    /* See if we must open another part */
 501    if (dev->at_eof() && !dev->open_next_part(dcr)) {
 502       if (dev->at_eof()) {        /* EOF just seen? */
 503          dev->set_eot();          /* yes, error => EOT */
 504       }
 505       return false;
 506    }
 507
 508    retry = 0;
 509    errno = 0;
 510    stat = 0;
 511
 512    if (dev->adata) {
 513       dev->lseek(dcr, dcr->block->BlockAddr, SEEK_SET);
 514    }
 515    {  /* debug block */
 516       pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
 517       Dmsg2(200, "Pos for read=%s %lld\n",
 518          dev->print_addr(ed1, sizeof(ed1), pos), pos);
 519    }
 520
 521    data_len = 0;
 522
 523    do {
 524       retry = 0;
 525
 526       do {
 527          if ((retry > 0 && stat == -1 && errno == EBUSY)) {
 528             berrno be;
 529             Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
 530                   retry, stat, errno, be.bstrerror());
 531             bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
 532             dev->clrerror(-1);
 533          }
 534          stat = dev->read(block->buf + data_len, (size_t)(block->buf_len - data_len));
 535          if (stat > 0)
 536             data_len += stat;
 537
 538       } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
 539
 540    } while (data_len < block->buf_len && stat > 0 && dev->dev_type == B_FIFO_DEV);
 541
 542    Dmsg4(110, "Read() adata=%d vol=%s nbytes=%d pos=%lld\n",
 543       block->adata, dev->VolHdr.VolumeName, stat < 0 ? stat : data_len, pos);
 544    if (stat < 0) {
 545       berrno be;
 546       dev->clrerror(-1);
 547       Dmsg2(90, "Read device fd=%d got: ERR=%s\n", dev->fd(), be.bstrerror());
 548       block->read_len = 0;
 549       if (reading_label) {      /* Trying to read Volume label */
 550          Mmsg(dev->errmsg, _("The %sVolume=%s on device=%s appears to be unlabeled.%s\n"),
 551             dev->adata?"adata ":"", VolumeName, dev->print_name(),
 552             dev->is_fs_nearly_full(1048576)?" Notice that the filesystem is nearly full.":"");
 553       } else {
 554          Mmsg4(dev->errmsg, _("Read error on fd=%d at addr=%s on device %s. ERR=%s.\n"),
 555             dev->fd(), dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), be.bstrerror());
 556       }
 557       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
 558       if (dev->get_tape_alerts(this)) {
 559          dev->show_tape_alerts(this, list_long, list_last, alert_callback);
 560       }
 561       if (dev->at_eof()) {        /* EOF just seen? */
 562          dev->set_eot();          /* yes, error => EOT */
 563       }
 564       return false;
 565    }
 566
 567    stat = data_len;
 568
 569    if (stat == 0) {             /* Got EOF ! */
 570       pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
 571       pos = dev->get_full_addr(pos);
 572       if (reading_label) {      /* Trying to read Volume label */
 573          Mmsg4(dev->errmsg, _("The %sVolume=%s on device=%s appears to be unlabeled.%s\n"),
 574             dev->adata?"adata ":"", VolumeName, dev->print_name(),
 575             dev->is_fs_nearly_full(1048576)?" Notice tha the filesystem is nearly full.":"");
 576       } else {
 577          Mmsg4(dev->errmsg, _("Read zero %sbytes Vol=%s at %s on device %s.\n"),
 578                dev->adata?"adata ":"", dev->VolCatInfo.VolCatName,
 579                dev->print_addr(ed1, sizeof(ed1), pos), dev->print_name());
 580       }
 581       block->read_len = 0;
 582       Dmsg1(100, "%s", dev->errmsg);
 583       if (dev->at_eof()) {        /* EOF just seen? */
 584          dev->set_eot();          /* yes, error => EOT */
 585       }
 586       dev->set_ateof();
 587       dev->file_addr = 0;
 588       dev->EndAddr = pos;
 589       if (dcr->EndAddr < dev->EndAddr) {
 590          dcr->EndAddr = dev->EndAddr;
 591       }
 592       Dmsg3(150, "==== Read zero bytes. adata=%d vol=%s at %s\n", dev->adata,
 593          dev->VolCatInfo.VolCatName, dev->print_addr(ed1, sizeof(ed1), pos));
 594       return false;             /* return eof */
 595    }
 596
 597    /* Continue here for successful read */
 598
 599    block->read_len = stat;      /* save length read */
 600    if (block->adata) {
 601       block->binbuf = block->read_len;
 602       block->block_len = block->read_len;
 603    } else {
 604       if (block->read_len == 80 &&
 605            (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
 606             dcr->device->label_type != B_BACULA_LABEL)) {
 607          /* ***FIXME*** should check label */
 608          Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
 609          dev->clear_eof();
 610          goto reread;             /* skip ANSI/IBM label */
 611       }
 612
 613       if (block->read_len < BLKHDR2_LENGTH) {
 614          dev->dev_errno = EIO;
 615          Mmsg3(dev->errmsg, _("Volume data error at %s! Very short block of %d bytes on device %s discarded.\n"),
 616             dev->print_addr(ed1, sizeof(ed1)), block->read_len, dev->print_name());
 617          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
 618          dev->set_short_block();
 619          block->read_len = block->binbuf = 0;
 620          Dmsg2(50, "set block=%p binbuf=%d\n", block, block->binbuf);
 621          return false;             /* return error */
 622       }
 623
 624       if (!unser_block_header(this, dev, block)) {
 625          if (forge_on) {
 626             dev->file_addr += block->read_len;
 627             dev->file_size += block->read_len;
 628             goto reread;
 629          }
 630          return false;
 631       }
 632    }
 633
 634    /*
 635     * If the block is bigger than the buffer, we reposition for
 636     *  re-reading the block, allocate a buffer of the correct size,
 637     *  and go re-read.
 638     */
 639    Dmsg3(150, "adata=%d block_len=%d buf_len=%d\n", block->adata, block->block_len, block->buf_len);
 640    if (block->block_len > block->buf_len) {
 641       dev->dev_errno = EIO;
 642       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
 643          block->block_len, block->buf_len);
 644       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
 645       Pmsg1(000, "%s", dev->errmsg);
 646       /* Attempt to reposition to re-read the block */
 647       if (dev->is_tape()) {
 648          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
 649          if (!dev->bsr(1)) {
 650             Mmsg(dev->errmsg, "%s", dev->bstrerror());
 651             if (dev->errmsg[0]) {
 652                Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
 653             }
 654             block->read_len = 0;
 655             return false;
 656          }
 657       } else {
 658          Dmsg0(250, "Seek to beginning of block for reread.\n");
 659          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
 660          pos -= block->read_len;
 661          dev->lseek(dcr, pos, SEEK_SET);
 662          dev->file_addr = pos;
 663       }
 664       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
 665       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
 666       Pmsg1(000, "%s", dev->errmsg);
 667       /* Set new block length */
 668       dev->max_block_size = block->block_len;
 669       block->buf_len = block->block_len;
 670       free_memory(block->buf);
 671       block->buf = get_memory(block->buf_len);
 672       empty_block(block);
 673       looping++;
 674       goto reread;                    /* re-read block with correct block size */
 675    }
 676
 677    if (block->block_len > block->read_len) {
 678       dev->dev_errno = EIO;
 679       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
 680          dev->file, dev->block_num, block->read_len, dev->print_name());
 681       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
 682       dev->set_short_block();
 683       block->read_len = block->binbuf = 0;
 684       return false;             /* return error */
 685    }
 686
 687    dev->clear_short_block();
 688    dev->clear_eof();
 689    dev->updateVolCatReads(1);
 690    dev->updateVolCatReadBytes(block->read_len);
 691
 692    /* Update dcr values */
 693    if (dev->is_tape()) {
 694       dev->EndAddr = dev->get_full_addr();
 695       if (dcr->EndAddr <  dev->EndAddr) {
 696          dcr->EndAddr = dev->EndAddr;
 697       }
 698       dev->block_num++;
 699    } else {
 700       /* We need to take care about a short block in EndBlock/File
 701        * computation
 702        */
 703       uint32_t len = MIN(block->read_len, block->block_len);
 704       uint64_t addr = dev->get_full_addr() + len - 1;
 705       if (dev->is_indexed()) {
 706          if (addr > dcr->EndAddr) {
 707             dcr->EndAddr = addr;
 708          }
 709       }
 710       dev->EndAddr = addr;
 711    }
 712    if (dev->is_indexed()) {
 713       dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
 714    }
 715    dev->file_addr += block->read_len;
 716    dev->file_size += block->read_len;
 717    dev->usage     += block->read_len;      /* update usage counter */
 718
 719    /*
 720     * If we read a short block on disk,
 721     * seek to beginning of next block. This saves us
 722     * from shuffling blocks around in the buffer. Take a
 723     * look at this from an efficiency stand point later, but
 724     * it should only happen once at the end of each job.
 725     *
 726     * I've been lseek()ing negative relative to SEEK_CUR for 30
 727     *   years now. However, it seems that with the new off_t definition,
 728     *   it is not possible to seek negative amounts, so we use two
 729     *   lseek(). One to get the position, then the second to do an
 730     *   absolute positioning -- so much for efficiency.  KES Sep 02.
 731     */
 732    Dmsg0(250, "At end of read block\n");
 733    if (block->read_len > block->block_len && !dev->is_tape()) {
 734       char ed1[50];
 735       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
 736       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
 737       pos -= (block->read_len - block->block_len);
 738       dev->lseek(dcr, pos, SEEK_SET);
 739       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n",
 740          edit_int64(pos, ed1), block->block_len,
 741             block->read_len);
 742       dev->file_addr = pos;
 743       dev->file_size = pos;
 744    }
 745    Dmsg3(150, "Exit read_block read_len=%d block_len=%d binbuf=%d\n",
 746       block->read_len, block->block_len, block->binbuf);
 747    block->block_read = true;
 748    return true;
 749 }