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