]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/block.c
Start adding back removed code.
[bacula/bacula] / bacula / src / stored / block.c
index 3e97f73c7d8c405589310c70a941d663a43f38d9..fb36d5a888d24f77a7fe24d8c8d075a861410257 100644 (file)
@@ -9,11 +9,11 @@
  *
  */
 /*
  *
  */
 /*
-   Copyright (C) 2001-2005 Kern Sibbald
+   Copyright (C) 2001-2006 Kern Sibbald
 
    This program is free software; you can redistribute it and/or
    modify it under the terms of the GNU General Public License
 
    This program is free software; you can redistribute it and/or
    modify it under the terms of the GNU General Public License
-   version 2 as ammended with additional clauses defined in the
+   version 2 as amended with additional clauses defined in the
    file LICENSE in the main source directory.
 
    This program is distributed in the hope that it will be useful,
    file LICENSE in the main source directory.
 
    This program is distributed in the hope that it will be useful,
@@ -27,7 +27,6 @@
 #include "bacula.h"
 #include "stored.h"
 
 #include "bacula.h"
 #include "stored.h"
 
-extern int debug_level;
 static bool terminate_writing_volume(DCR *dcr);
 static bool do_new_file_bookkeeping(DCR *dcr);
 static bool do_dvd_size_checks(DCR *dcr);
 static bool terminate_writing_volume(DCR *dcr);
 static bool do_new_file_bookkeeping(DCR *dcr);
 static bool do_dvd_size_checks(DCR *dcr);
@@ -49,6 +48,7 @@ void dump_block(DEV_BLOCK *b, const char *msg)
    int32_t  FileIndex;
    int32_t  Stream;
    int bhl, rhl;
    int32_t  FileIndex;
    int32_t  Stream;
    int bhl, rhl;
+   char buf1[100], buf2[100];
 
    unser_begin(b->buf, BLKHDR1_LENGTH);
    unser_uint32(CheckSum);
 
    unser_begin(b->buf, BLKHDR1_LENGTH);
    unser_uint32(CheckSum);
@@ -75,8 +75,8 @@ void dump_block(DEV_BLOCK *b, const char *msg)
 
    BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
                          block_len-BLKHDR_CS_LENGTH);
 
    BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
                          block_len-BLKHDR_CS_LENGTH);
-   Pmsg6(000, "Dump block %s %x: size=%d BlkNum=%d\n"
-"               Hdrcksum=%x cksum=%x\n",
+   Pmsg6(000, _("Dump block %s %x: size=%d BlkNum=%d\n"
+"               Hdrcksum=%x cksum=%x\n"),
       msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
    p = b->buf + bhl;
    while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) {
       msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
    p = b->buf + bhl;
    while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) {
@@ -88,9 +88,9 @@ void dump_block(DEV_BLOCK *b, const char *msg)
       unser_int32(FileIndex);
       unser_int32(Stream);
       unser_uint32(data_len);
       unser_int32(FileIndex);
       unser_int32(Stream);
       unser_uint32(data_len);
-      Pmsg6(000, "   Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n",
-           VolSessionId, VolSessionTime, FI_to_ascii(FileIndex),
-           stream_to_ascii(Stream, FileIndex), data_len, p);
+      Pmsg6(000, _("   Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n"),
+           VolSessionId, VolSessionTime, FI_to_ascii(buf1, FileIndex),
+           stream_to_ascii(buf2, Stream, FileIndex), data_len, p);
       p += data_len + rhl;
   }
 }
       p += data_len + rhl;
   }
 }
@@ -117,7 +117,7 @@ DEV_BLOCK *new_block(DEVICE *dev)
    block->buf = get_memory(block->buf_len);
    empty_block(block);
    block->BlockVer = BLOCK_VER;       /* default write version */
    block->buf = get_memory(block->buf_len);
    empty_block(block);
    block->BlockVer = BLOCK_VER;       /* default write version */
-   Dmsg1(350, "Returning new block=%x\n", block);
+   Dmsg1(650, "Returning new block=%x\n", block);
    return block;
 }
 
    return block;
 }
 
@@ -182,7 +182,7 @@ void ser_block_header(DEV_BLOCK *block)
    uint32_t CheckSum = 0;
    uint32_t block_len = block->binbuf;
 
    uint32_t CheckSum = 0;
    uint32_t block_len = block->binbuf;
 
-   Dmsg1(390, "ser_block_header: block_len=%d\n", block_len);
+   Dmsg1(1390, "ser_block_header: block_len=%d\n", block_len);
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);
    ser_uint32(block_len);
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);
    ser_uint32(block_len);
@@ -196,7 +196,7 @@ void ser_block_header(DEV_BLOCK *block)
    /* Checksum whole block except for the checksum */
    CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
                  block_len-BLKHDR_CS_LENGTH);
    /* Checksum whole block except for the checksum */
    CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
                  block_len-BLKHDR_CS_LENGTH);
-   Dmsg1(390, "ser_bloc_header: checksum=%x\n", CheckSum);
+   Dmsg1(1390, "ser_bloc_header: checksum=%x\n", CheckSum);
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);              /* now add checksum to block header */
 }
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);              /* now add checksum to block header */
 }
@@ -401,6 +401,7 @@ bool write_block_to_dev(DCR *dcr)
    return true;
 #endif
    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
    return true;
 #endif
    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
+   ASSERT(dev->is_open());
 
    /* dump_block(block, "before write"); */
    if (dev->at_weot()) {
 
    /* dump_block(block, "before write"); */
    if (dev->at_weot()) {
@@ -464,7 +465,7 @@ bool write_block_to_dev(DCR *dcr)
          max_cap = dev->VolCatInfo.VolCatMaxBytes;
       }
       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
          max_cap = dev->VolCatInfo.VolCatMaxBytes;
       }
       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
-            edit_uint64_with_commas(max_cap, ed1),  dev->dev_name);
+            edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
       terminate_writing_volume(dcr);
       reread_last_block(dcr);   /* DEBUG */
       dev->dev_errno = ENOSPC;
       terminate_writing_volume(dcr);
       reread_last_block(dcr);   /* DEBUG */
       dev->dev_errno = ENOSPC;
@@ -476,10 +477,10 @@ bool write_block_to_dev(DCR *dcr)
        (dev->file_size+block->binbuf) >= dev->max_file_size) {
       dev->file_size = 0;             /* reset file size */
 
        (dev->file_size+block->binbuf) >= dev->max_file_size) {
       dev->file_size = 0;             /* reset file size */
 
-      if (weof_dev(dev, 1) != 0) {            /* write eof */
+      if (!dev->weof(1)) {            /* write eof */
          Dmsg0(190, "WEOF error in max file size.\n");
          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
          Dmsg0(190, "WEOF error in max file size.\n");
          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
-            strerror_dev(dev));
+            dev->bstrerror());
          terminate_writing_volume(dcr);
          dev->dev_errno = ENOSPC;
          return false;
          terminate_writing_volume(dcr);
          dev->dev_errno = ENOSPC;
          return false;
@@ -500,22 +501,39 @@ bool write_block_to_dev(DCR *dcr)
    }
 
    dev->VolCatInfo.VolCatWrites++;
    }
 
    dev->VolCatInfo.VolCatWrites++;
-   Dmsg1(300, "Write block of %u bytes\n", wlen);
+   Dmsg1(1300, "Write block of %u bytes\n", wlen);
 #ifdef DEBUG_BLOCK_ZEROING
    uint32_t *bp = (uint32_t *)block->buf;
    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
 #ifdef DEBUG_BLOCK_ZEROING
    uint32_t *bp = (uint32_t *)block->buf;
    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
-      Jmsg0(jcr, M_ABORT, 0, "Write block header zeroed.\n");
+      Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
    }
 #endif
 
    /*
    }
 #endif
 
    /*
-    * Do write here
+    * Do write here, make a somewhat feeble attempt to recover from 
+    *  I/O errors, or from the OS telling us it is busy.
     */ 
     */ 
-   stat = write(dev->fd, block->buf, (size_t)wlen);
+   int retry = 0;
+   errno = 0;
+   stat = 0;
+   do {
+      if ((retry > 0 && stat == -1 && errno == EBUSY) || retry > 10) {
+         berrno be;
+         Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
+               retry, stat, errno, be.strerror());
+         bmicrosleep(0, 100000);    /* pause a bit if busy or lots of errors */
+         dev->clrerror(-1);
+      }
+      if (dev->is_tape()) {
+         stat = tape_write(dev->fd, block->buf, (size_t)wlen);
+      } else {
+         stat = write(dev->fd, block->buf, (size_t)wlen);
+      }
+   } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 30);
 
 #ifdef DEBUG_BLOCK_ZEROING
    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
 
 #ifdef DEBUG_BLOCK_ZEROING
    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
-      Jmsg0(jcr, M_ABORT, 0, "Write block header zeroed.\n");
+      Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
    }
 #endif
 
    }
 #endif
 
@@ -528,13 +546,14 @@ bool write_block_to_dev(DCR *dcr)
        */
       if (stat == -1) {
          berrno be;
        */
       if (stat == -1) {
          berrno be;
-         clrerror_dev(dev, -1);
+         dev->clrerror(-1);
          if (dev->dev_errno == 0) {
             dev->dev_errno = ENOSPC;        /* out of space */
          }
          if (dev->dev_errno != ENOSPC) {
          if (dev->dev_errno == 0) {
             dev->dev_errno = ENOSPC;        /* out of space */
          }
          if (dev->dev_errno != ENOSPC) {
+            dev->VolCatInfo.VolCatErrors++;
             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
-               dev->file, dev->block_num, dev->dev_name, be.strerror());
+               dev->file, dev->block_num, dev->print_name(), be.strerror());
          }
       } else {
         dev->dev_errno = ENOSPC;            /* out of space */
          }
       } else {
         dev->dev_errno = ENOSPC;            /* out of space */
@@ -544,8 +563,9 @@ bool write_block_to_dev(DCR *dcr)
             dev->VolCatInfo.VolCatName,
             dev->file, dev->block_num, dev->print_name(), wlen, stat);
       }
             dev->VolCatInfo.VolCatName,
             dev->file, dev->block_num, dev->print_name(), wlen, stat);
       }
-      Dmsg6(100, "=== Write error. size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
-         wlen, stat, dev->block_num, block->BlockNumber, dev->dev_errno, strerror(dev->dev_errno));
+      Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
+         dev->fd, wlen, stat, dev->block_num, block->BlockNumber, 
+         dev->dev_errno, strerror(dev->dev_errno));
 
       ok = terminate_writing_volume(dcr);
       if (!ok && !forge_on) {
 
       ok = terminate_writing_volume(dcr);
       if (!ok && !forge_on) {
@@ -558,22 +578,26 @@ bool write_block_to_dev(DCR *dcr)
    }
 
    /* We successfully wrote the block, now do housekeeping */
    }
 
    /* We successfully wrote the block, now do housekeeping */
-
-   dev->VolCatInfo.VolCatBytes += block->binbuf;
+   Dmsg2(1300, "VolCatBytes=%d newVolCatBytes=%d\n", (int)dev->VolCatInfo.VolCatBytes,
+      (int)(dev->VolCatInfo.VolCatBytes+wlen));
+   dev->VolCatInfo.VolCatBytes += wlen;         
    dev->VolCatInfo.VolCatBlocks++;
    dev->EndBlock = dev->block_num;
    dev->EndFile  = dev->file;
    dev->VolCatInfo.VolCatBlocks++;
    dev->EndBlock = dev->block_num;
    dev->EndFile  = dev->file;
-   dev->block_num++;
    block->BlockNumber++;
 
    /* Update dcr values */
    if (dev->is_tape()) {
       dcr->EndBlock = dev->EndBlock;
       dcr->EndFile  = dev->EndFile;
    block->BlockNumber++;
 
    /* Update dcr values */
    if (dev->is_tape()) {
       dcr->EndBlock = dev->EndBlock;
       dcr->EndFile  = dev->EndFile;
+      dev->block_num++;
    } else {
    } else {
-      /* Save address of start of block just written */
-      dcr->EndBlock = (uint32_t)dev->file_addr;
-      dcr->EndFile = (uint32_t)(dev->file_addr >> 32);
+      /* Save address of block just written */
+      uint64_t addr = dev->file_addr + wlen - 1;
+      dcr->EndBlock = (uint32_t)addr;
+      dcr->EndFile = (uint32_t)(addr >> 32);
+      dev->block_num = dcr->EndBlock;
+      dev->file = dcr->EndFile;
    }
    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
       dcr->VolFirstIndex = block->FirstIndex;
    }
    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
       dcr->VolFirstIndex = block->FirstIndex;
@@ -586,7 +610,7 @@ bool write_block_to_dev(DCR *dcr)
    dev->file_size += wlen;
    dev->part_size += wlen;
 
    dev->file_size += wlen;
    dev->part_size += wlen;
 
-   Dmsg2(300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
+   Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
    empty_block(block);
    return true;
 }
    empty_block(block);
    return true;
 }
@@ -608,20 +632,20 @@ static void reread_last_block(DCR *dcr)
     */
    if (dev->is_tape() && dev_cap(dev, CAP_BSR)) {
       /* Now back up over what we wrote and read the last block */
     */
    if (dev->is_tape() && dev_cap(dev, CAP_BSR)) {
       /* Now back up over what we wrote and read the last block */
-      if (!bsf_dev(dev, 1)) {
+      if (!dev->bsf(1)) {
          berrno be;
          ok = false;
          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
               be.strerror(dev->dev_errno));
       }
          berrno be;
          ok = false;
          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
               be.strerror(dev->dev_errno));
       }
-      if (ok && dev_cap(dev, CAP_TWOEOF) && !bsf_dev(dev, 1)) {
+      if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
          berrno be;
          ok = false;
          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
               be.strerror(dev->dev_errno));
       }
       /* Backspace over record */
          berrno be;
          ok = false;
          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
               be.strerror(dev->dev_errno));
       }
       /* Backspace over record */
-      if (ok && !bsr_dev(dev, 1)) {
+      if (ok && !dev->bsr(1)) {
          berrno be;
          ok = false;
          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
          berrno be;
          ok = false;
          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
@@ -632,7 +656,7 @@ static void reread_last_block(DCR *dcr)
           *    rewind(), but if we do that, higher levels in cleaning up, will
           *    most likely write the EOS record over the beginning of the
           *    tape.  The rewind *is* done later in mount.c when another
           *    rewind(), but if we do that, higher levels in cleaning up, will
           *    most likely write the EOS record over the beginning of the
           *    tape.  The rewind *is* done later in mount.c when another
-          *    tape is requested. Note, the clrerror_dev() call in bsr_dev()
+          *    tape is requested. Note, the clrerror() call in bsr()
           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
           */
       }
           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
           */
       }
@@ -644,12 +668,17 @@ static void reread_last_block(DCR *dcr)
             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
                  dev->errmsg);
          } else {
             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
                  dev->errmsg);
          } else {
-            if (lblock->BlockNumber+1 == block->BlockNumber) {
-               Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
-            } else {
+            /*
+             * If we wrote block and the block numbers don't agree
+             *  we have a possible problem.
+             */
+            if (lblock->VolSessionId == block->VolSessionId &&
+                lblock->BlockNumber+1 != block->BlockNumber) {
                Jmsg(jcr, M_ERROR, 0, _(
                Jmsg(jcr, M_ERROR, 0, _(
-"Re-read of last block failed. Last block=%u Current block=%u.\n"),
+"Re-read of last block OK, but block numbers differ. Last block=%u Current block=%u.\n"),
                     lblock->BlockNumber, block->BlockNumber);
                     lblock->BlockNumber, block->BlockNumber);
+            } else {
+               Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
             }
          }
          free_block(lblock);
             }
          }
          free_block(lblock);
@@ -675,10 +704,10 @@ static bool terminate_writing_volume(DCR *dcr)
        goto bail_out;
    }
    dcr->block->write_failed = true;
        goto bail_out;
    }
    dcr->block->write_failed = true;
-   if (weof_dev(dev, 1) != 0) {         /* end the tape */
+   if (!dev->weof(1)) {         /* end the tape */
       dev->VolCatInfo.VolCatErrors++;
       dev->VolCatInfo.VolCatErrors++;
-      Jmsg(dcr->jcr, M_ERROR, 0, "Error writing final EOF to tape. This tape may not be readable.\n"
-           "%s", dev->errmsg);
+      Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
+           "%s"), dev->errmsg);
       ok = false;
       Dmsg0(100, "WEOF error.\n");
    }
       ok = false;
       Dmsg0(100, "WEOF error.\n");
    }
@@ -689,8 +718,16 @@ static bool terminate_writing_volume(DCR *dcr)
    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
    dev->VolCatInfo.VolCatJobs++;              /* increment number of jobs */
    
    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
    dev->VolCatInfo.VolCatJobs++;              /* increment number of jobs */
    
-   if (dev->is_dvd()) { /* Write the current (and last) part. */
-      open_next_part(dcr);
+   if (dev->is_dvd()) {
+      if (!dvd_write_part(dcr)) {             /* write last part */
+         dev->VolCatInfo.VolCatErrors++;
+         Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
+                                 "This Volume may not be readable.\n%s"),
+                         dev->errmsg);
+         ok = false;
+         Dmsg0(100, "dvd_write_part error.\n");
+      }
+      dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
    }
    
    if (!dir_update_volume_info(dcr, false)) {
    }
    
    if (!dir_update_volume_info(dcr, false)) {
@@ -712,7 +749,7 @@ static bool terminate_writing_volume(DCR *dcr)
    /* Set new file/block parameters for current dcr */
    set_new_file_parameters(dcr);
 
    /* Set new file/block parameters for current dcr */
    set_new_file_parameters(dcr);
 
-   if (ok && dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {  /* end the tape */
+   if (ok && dev_cap(dev, CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
       dev->VolCatInfo.VolCatErrors++;
       /* This may not be fatal since we already wrote an EOF */
       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
       dev->VolCatInfo.VolCatErrors++;
       /* This may not be fatal since we already wrote an EOF */
       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
@@ -777,27 +814,30 @@ static bool do_dvd_size_checks(DCR *dcr)
    JCR *jcr = dcr->jcr;
    DEV_BLOCK *block = dcr->block;
 
    JCR *jcr = dcr->jcr;
    DEV_BLOCK *block = dcr->block;
 
+   /* Don't go further if the device is not a dvd */
+   if (!dev->is_dvd()) {
+      return true;
+   }
+   
    /* Limit maximum part size to value specified by user 
    /* Limit maximum part size to value specified by user 
-    * (not applicable to tapes/fifos)   
     */
     */
-   if (!(dev->is_tape() || dev->is_fifo()) && dev->max_part_size > 0 &&
-        (dev->part_size + block->binbuf) >= dev->max_part_size) {
-      if (dev->part < dev->num_parts) {
+   if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
+      if (dev->part < dev->num_dvd_parts) {
          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
                " is less than the total number of parts (%d/%d, device=%s)\n"),
          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
                " is less than the total number of parts (%d/%d, device=%s)\n"),
-               dev->part, dev->num_parts, dev->print_name());
+               dev->part, dev->num_dvd_parts, dev->print_name());
          dev->dev_errno = EIO;
          return false;
       }
       
          dev->dev_errno = EIO;
          return false;
       }
       
-      if (open_next_part(dcr) < 0) {
+      if (dvd_open_next_part(dcr) < 0) {
          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
-                dev->print_name(), strerror_dev(dev));
+                dev->print_name(), dev->bstrerror());
          dev->dev_errno = EIO;
          return false;
       }
       
          dev->dev_errno = EIO;
          return false;
       }
       
-      dev->VolCatInfo.VolCatParts = dev->num_parts;
+      dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
             
       if (!dir_update_volume_info(dcr, false)) {
          Dmsg0(190, "Error from update_vol_info.\n");
             
       if (!dir_update_volume_info(dcr, false)) {
          Dmsg0(190, "Error from update_vol_info.\n");
@@ -805,8 +845,12 @@ static bool do_dvd_size_checks(DCR *dcr)
          return false;
       }
    }
          return false;
       }
    }
+
+   if (!dev->is_freespace_ok()) {
+      update_free_space_dev(dev);
+   }
    
    
-   if (dev->free_space_errno < 0) { /* Error while getting free space */
+   if (!dev->is_freespace_ok()) { /* Error while getting free space */
       char ed1[50], ed2[50];
       Dmsg1(10, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
       char ed1[50], ed2[50];
       Dmsg1(10, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
@@ -815,11 +859,11 @@ static bool do_dvd_size_checks(DCR *dcr)
            dev->file, dev->block_num, dev->print_name(),
            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
            dev->free_space_errno, dev->errmsg);
            dev->file, dev->block_num, dev->print_name(),
            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
            dev->free_space_errno, dev->errmsg);
-      dev->dev_errno = -dev->free_space_errno;
+      dev->dev_errno = dev->free_space_errno;
       return false;
    }
    
       return false;
    }
    
-   if ((dev->free_space_errno > 0 && (dev->part_size + block->binbuf) >= dev->free_space)) {
+   if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
       char ed1[50], ed2[50];
       Dmsg0(10, "==== Just enough free space on the device to write the current part...\n");
       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
       char ed1[50], ed2[50];
       Dmsg0(10, "==== Just enough free space on the device to write the current part...\n");
       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
@@ -866,66 +910,77 @@ bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
    JCR *jcr = dcr->jcr;
    DEVICE *dev = dcr->dev;
    DEV_BLOCK *block = dcr->block;
    JCR *jcr = dcr->jcr;
    DEVICE *dev = dcr->dev;
    DEV_BLOCK *block = dcr->block;
+
+   ASSERT(dev->is_open());
    
    if (dev->at_eot()) {
       return false;
    }
    looping = 0;
    
    if (dev->at_eot()) {
       return false;
    }
    looping = 0;
-   Dmsg1(200, "Full read() in read_block_from_device() len=%d\n",
+   Dmsg1(200, "Full read in read_block_from_device() len=%d\n",
          block->buf_len);
 reread:
    if (looping > 1) {
       dev->dev_errno = EIO;
       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
          block->buf_len);
 reread:
    if (looping > 1) {
       dev->dev_errno = EIO;
       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
-         dev->dev_name);
+         dev->print_name());
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       block->read_len = 0;
       return false;
    }
    
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       block->read_len = 0;
       return false;
    }
    
-   /*Dmsg1(200, "dev->file_size=%u\n",(unsigned int)dev->file_size);
-   Dmsg1(200, "lseek=%u\n",(unsigned int)lseek(dev->fd, 0, SEEK_CUR));
-   Dmsg1(200, "dev->part_start=%u\n",(unsigned int)dev->part_start);
-   Dmsg1(200, "dev->file_size-dev->part_start=%u\n",(unsigned int)dev->file_size-dev->part_start);
-   Dmsg1(200, "dev->part_size=%u\n", (unsigned int)dev->part_size);
-   Dmsg1(200, "dev->part=%u\n", (unsigned int)dev->part);
-   Dmsg1(200, "dev->VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
-   Dmsg3(200, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
-         ((dev->file_size-dev->part_start) == dev->part_size), 
-         (dev->part <= dev->VolCatInfo.VolCatParts));*/
-   /* Check for part file end */
-   if ((dev->num_parts > 0) &&
-        ((dev->file_size-dev->part_start) == dev->part_size) && 
-        (dev->part < dev->num_parts)) {
-      if (open_next_part(dcr) < 0) {
-         Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
-               dev->print_name(), strerror_dev(dev));
+#define lots_of_debug
+#ifdef lots_of_debug
+   if (dev->at_eof() && dev->is_dvd()) {
+      Dmsg1(100, "file_size=%u\n",(unsigned int)dev->file_size);
+      Dmsg1(100, "file_addr=%u\n",(unsigned int)dev->file_addr);
+      Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd, 0, SEEK_CUR));
+      Dmsg1(100, "part_start=%u\n",(unsigned int)dev->part_start);
+      Dmsg1(100, "part_size=%u\n", (unsigned int)dev->part_size);
+      Dmsg2(100, "part=%u num_dvd_parts=%u\n", dev->part, dev->num_dvd_parts);
+      Dmsg1(100, "VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
+      Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
+         ((dev->file_addr-dev->part_start) == dev->part_size), 
+         (dev->part <= dev->VolCatInfo.VolCatParts));
+  }
+#endif
+
+   /* Check for DVD part file end */
+   if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
+        dev->part <= dev->num_dvd_parts) {
+      Dmsg0(400, "Call dvd_open_next_part\n");
+      if (dvd_open_next_part(dcr) < 0) {
+         Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
+               dev->part, dev->print_name(), dev->bstrerror());
          dev->dev_errno = EIO;
          return false;
       }
    }
    
    retry = 0;
          dev->dev_errno = EIO;
          return false;
       }
    }
    
    retry = 0;
+   errno = 0;
+   stat = 0;
    do {
    do {
-//    uint32_t *bp = (uint32_t *)block->buf;
-//    Pmsg3(000, "Read %p %u at %llu\n", block->buf, block->buf_len, lseek(dev->fd, 0, SEEK_CUR));
-
-      stat = read(dev->fd, block->buf, (size_t)block->buf_len);
-
-//    Pmsg8(000, "stat=%d Csum=%u blen=%u bnum=%u %c%c%c%c\n",stat, bp[0],bp[1],bp[2],
-//      block->buf[12],block->buf[13],block->buf[14],block->buf[15]);
-
-      if (retry == 1) {
-         dev->VolCatInfo.VolCatErrors++;
+      if ((retry > 0 && stat == -1 && errno == EBUSY) || retry > 10) {
+         berrno be;
+         Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
+               retry, stat, errno, be.strerror());
+         bmicrosleep(0, 100000);    /* pause a bit if busy or lots of errors */
+         dev->clrerror(-1);
       }
       }
-   } while (stat == -1 && (errno == EINTR || errno == EIO) && retry++ < 11);
+      if (dev->is_tape()) {
+         stat = tape_read(dev->fd, block->buf, (size_t)block->buf_len);
+      } else {
+         stat = read(dev->fd, block->buf, (size_t)block->buf_len);
+      }
+   } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 30);
    if (stat < 0) {
       berrno be;
    if (stat < 0) {
       berrno be;
-      clrerror_dev(dev, -1);
+      dev->clrerror(-1);
       Dmsg1(200, "Read device got: ERR=%s\n", be.strerror());
       block->read_len = 0;
       Mmsg4(dev->errmsg, _("Read error at file:blk %u:%u on device %s. ERR=%s.\n"),
       Dmsg1(200, "Read device got: ERR=%s\n", be.strerror());
       block->read_len = 0;
       Mmsg4(dev->errmsg, _("Read error at file:blk %u:%u on device %s. ERR=%s.\n"),
-         dev->file, dev->block_num, dev->dev_name, be.strerror());
+         dev->file, dev->block_num, dev->print_name(), be.strerror());
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       if (dev->at_eof()) {        /* EOF just seen? */
          dev->set_eot();          /* yes, error => EOT */
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       if (dev->at_eof()) {        /* EOF just seen? */
          dev->set_eot();          /* yes, error => EOT */
@@ -938,7 +993,7 @@ reread:
       dev->block_num = 0;
       block->read_len = 0;
       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
       dev->block_num = 0;
       block->read_len = 0;
       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
-         dev->file, dev->block_num, dev->dev_name);
+         dev->file, dev->block_num, dev->print_name());
       if (dev->at_eof()) {       /* EOF already read? */
          dev->set_eot();         /* yes, 2 EOFs => EOT */
          return 0;
       if (dev->at_eof()) {       /* EOF already read? */
          dev->set_eot();         /* yes, 2 EOFs => EOT */
          return 0;
@@ -951,7 +1006,7 @@ reread:
    if (block->read_len < BLKHDR2_LENGTH) {
       dev->dev_errno = EIO;
       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
    if (block->read_len < BLKHDR2_LENGTH) {
       dev->dev_errno = EIO;
       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
-         dev->file, dev->block_num, block->read_len, dev->dev_name);
+         dev->file, dev->block_num, block->read_len, dev->print_name());
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       dev->set_short_block();   
       block->read_len = block->binbuf = 0;
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       dev->set_short_block();   
       block->read_len = block->binbuf = 0;
@@ -982,16 +1037,16 @@ reread:
       /* Attempt to reposition to re-read the block */
       if (dev->is_tape()) {
          Dmsg0(200, "BSR for reread; block too big for buffer.\n");
       /* Attempt to reposition to re-read the block */
       if (dev->is_tape()) {
          Dmsg0(200, "BSR for reread; block too big for buffer.\n");
-         if (!bsr_dev(dev, 1)) {
-            Jmsg(jcr, M_ERROR, 0, "%s", strerror_dev(dev));
+         if (!dev->bsr(1)) {
+            Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
             block->read_len = 0;
             return false;
          }
       } else {
          Dmsg0(200, "Seek to beginning of block for reread.\n");
             block->read_len = 0;
             return false;
          }
       } else {
          Dmsg0(200, "Seek to beginning of block for reread.\n");
-         off_t pos = lseek_dev(dev, (off_t)0, SEEK_CUR); /* get curr pos */
+         off_t pos = dev->lseek(dcr, (off_t)0, SEEK_CUR); /* get curr pos */
          pos -= block->read_len;
          pos -= block->read_len;
-         lseek_dev(dev, pos, SEEK_SET);
+         dev->lseek(dcr, pos, SEEK_SET);
          dev->file_addr = pos;
       }
       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
          dev->file_addr = pos;
       }
       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
@@ -1010,7 +1065,7 @@ reread:
    if (block->block_len > block->read_len) {
       dev->dev_errno = EIO;
       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
    if (block->block_len > block->read_len) {
       dev->dev_errno = EIO;
       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
-         dev->file, dev->block_num, block->read_len, dev->dev_name);
+         dev->file, dev->block_num, block->read_len, dev->print_name());
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       dev->set_short_block();
       block->read_len = block->binbuf = 0;
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       dev->set_short_block();
       block->read_len = block->binbuf = 0;
@@ -1024,6 +1079,9 @@ reread:
 
    dev->VolCatInfo.VolCatBytes += block->block_len;
    dev->VolCatInfo.VolCatBlocks++;
 
    dev->VolCatInfo.VolCatBytes += block->block_len;
    dev->VolCatInfo.VolCatBlocks++;
+   if (dev->VolCatInfo.VolFirstWritten == 0) {
+      dev->VolCatInfo.VolFirstWritten = time(NULL);    /* Set first written time */
+   }
    dev->EndBlock = dev->block_num;
    dev->EndFile  = dev->file;
    dev->block_num++;
    dev->EndBlock = dev->block_num;
    dev->EndFile  = dev->file;
    dev->block_num++;
@@ -1033,13 +1091,14 @@ reread:
       dcr->EndBlock = dev->EndBlock;
       dcr->EndFile  = dev->EndFile;
    } else {
       dcr->EndBlock = dev->EndBlock;
       dcr->EndFile  = dev->EndFile;
    } else {
-      dcr->EndBlock = (uint32_t)dev->file_addr;
-      dcr->EndFile = (uint32_t)(dev->file_addr >> 32);
+      uint64_t addr = dev->file_addr + block->read_len - 1;
+      dcr->EndBlock = (uint32_t)addr;
+      dcr->EndFile = (uint32_t)(addr >> 32);
       dev->block_num = dcr->EndBlock;
       dev->file = dcr->EndFile;
    }
       dev->block_num = dcr->EndBlock;
       dev->file = dcr->EndFile;
    }
-   dev->file_addr += block->block_len;
-   dev->file_size += block->block_len;
+   dev->file_addr += block->read_len;
+   dev->file_size += block->read_len;
 
    /*
     * If we read a short block on disk,
 
    /*
     * If we read a short block on disk,
@@ -1057,11 +1116,12 @@ reread:
    Dmsg0(200, "At end of read block\n");
    if (block->read_len > block->block_len && !dev->is_tape()) {
       char ed1[50];
    Dmsg0(200, "At end of read block\n");
    if (block->read_len > block->block_len && !dev->is_tape()) {
       char ed1[50];
-      off_t pos = lseek_dev(dev, (off_t)0, SEEK_CUR); /* get curr pos */
+      off_t pos = dev->lseek(dcr, (off_t)0, SEEK_CUR); /* get curr pos */
+      Dmsg1(200, "Current lseek pos=%s\n", edit_int64(pos, ed1));
       pos -= (block->read_len - block->block_len);
       pos -= (block->read_len - block->block_len);
-      lseek_dev(dev, pos, SEEK_SET);
+      dev->lseek(dcr, pos, SEEK_SET);
       Dmsg3(200, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
       Dmsg3(200, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
-         edit_uint64(pos, ed1), block->block_len,
+         edit_int64(pos, ed1), block->block_len,
             block->read_len);
       dev->file_addr = pos;
       dev->file_size = pos;
             block->read_len);
       dev->file_addr = pos;
       dev->file_size = pos;