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

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