]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/block.c
Backport new lock calls + debug for SD
[bacula/bacula] / bacula / src / stored / block.c
index d23182a7eed9ed00022e6668fdce554fa55130e7..e731320b880b2a459c8916bfad46c32c18dded34 100644 (file)
@@ -1,12 +1,12 @@
 /*
    Bacula® - The Network Backup Solution
 
-   Copyright (C) 2001-2007 Free Software Foundation Europe e.V.
+   Copyright (C) 2001-2012 Free Software Foundation Europe e.V.
 
    The main author of Bacula is Kern Sibbald, with contributions from
    many others, a complete list can be found in the file AUTHORS.
    This program is Free Software; you can redistribute it and/or
-   modify it under the terms of version two of the GNU General Public
+   modify it under the terms of version three of the GNU Affero General Public
    License as published by the Free Software Foundation and included
    in the file LICENSE.
 
    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
    General Public License for more details.
 
-   You should have received a copy of the GNU General Public License
+   You should have received a copy of the GNU Affero General Public License
    along with this program; if not, write to the Free Software
    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
    02110-1301, USA.
 
-   Bacula® is a registered trademark of John Walker.
+   Bacula® is a registered trademark of Kern Sibbald.
    The licensor of Bacula is the Free Software Foundation Europe
    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
    Switzerland, email:ftf@fsfeurope.org.
  *              Kern Sibbald, March MMI
  *                 added BB02 format October MMII
  *
- *   Version $Id$
- *
  */
 
 
 #include "bacula.h"
 #include "stored.h"
 
+#ifdef DEBUG_BLOCK_CHECKSUM
+static const bool debug_block_checksum = true;
+#else
+static const bool debug_block_checksum = false;
+#endif
+
+#ifdef NO_TAPE_WRITE_TEST
+static const bool no_tape_write_test = true;
+#else
+static const bool no_tape_write_test = false;
+#endif
+
+
 static bool terminate_writing_volume(DCR *dcr);
 static bool do_new_file_bookkeeping(DCR *dcr);
 static bool do_dvd_size_checks(DCR *dcr);
@@ -81,7 +92,7 @@ void dump_block(DEV_BLOCK *b, const char *msg)
       rhl = RECHDR1_LENGTH;
    }
 
-   if (block_len > 100000) {
+   if (block_len > 4000000) {
       Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len);
       return;
    }
@@ -167,10 +178,12 @@ void print_block_read_errors(JCR *jcr, DEV_BLOCK *block)
  */
 void free_block(DEV_BLOCK *block)
 {
-   Dmsg1(999, "free_block buffer %x\n", block->buf);
-   free_memory(block->buf);
-   Dmsg1(999, "free_block block %x\n", block);
-   free_memory((POOLMEM *)block);
+   if (block) {
+      Dmsg1(999, "free_block buffer %x\n", block->buf);
+      free_memory(block->buf);
+      Dmsg1(999, "free_block block %x\n", block);
+      free_memory((POOLMEM *)block);
+   }
 }
 
 /* Empty the block -- for writing */
@@ -189,7 +202,7 @@ void empty_block(DEV_BLOCK *block)
  * in the buffer should have already been reserved by
  * init_block.
  */
-void ser_block_header(DEV_BLOCK *block)
+static uint32_t ser_block_header(DEV_BLOCK *block, bool do_checksum)
 {
    ser_declare;
    uint32_t CheckSum = 0;
@@ -207,11 +220,14 @@ 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);
+   if (do_checksum) {
+      CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
+                    block_len-BLKHDR_CS_LENGTH);
+   }
    Dmsg1(1390, "ser_bloc_header: checksum=%x\n", CheckSum);
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);              /* now add checksum to block header */
+   return CheckSum;
 }
 
 /*
@@ -307,7 +323,7 @@ static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
    block->BlockNumber = BlockNumber;
    Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
       bhl, block_len);
-   if (block_len <= block->read_len) {
+   if (block_len <= block->read_len && dev->do_checksum()) {
       BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
                          block_len-BLKHDR_CS_LENGTH);
       if (BlockCheckSum != CheckSum) {
@@ -318,6 +334,7 @@ static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
             block_len, BlockCheckSum, CheckSum);
          if (block->read_errors == 0 || verbose >= 2) {
             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
+            dump_block(block, "with checksum error");
          }
          block->read_errors++;
          if (!forge_on) {
@@ -335,20 +352,20 @@ static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
  *        : false on failure
  *
  */
-bool write_block_to_device(DCR *dcr)
+bool DCR::write_block_to_device()
 {
    bool stat = true;
-   DEVICE *dev = dcr->dev;
-   JCR *jcr = dcr->jcr;
+   DCR *dcr = this;
 
    if (dcr->spooling) {
+      Dmsg0(100, "Write to spool\n");
       stat = write_block_to_spool_file(dcr);
       return stat;
    }
 
    if (!dcr->is_dev_locked()) {        /* device already locked? */
       /* note, do not change this to dcr->r_dlock */
-      dev->r_dlock();                  /* no, lock it */
+      dev->rLock();                  /* no, lock it */
    }
 
    /*
@@ -360,28 +377,29 @@ bool write_block_to_device(DCR *dcr)
    if (dcr->NewVol || dcr->NewFile) {
       if (job_canceled(jcr)) {
          stat = false;
+         Dmsg0(100, "Canceled\n");
          goto bail_out;
       }
       /* Create a jobmedia record for this job */
       if (!dir_create_jobmedia_record(dcr)) {
          dev->dev_errno = EIO;
-         Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
-            dcr->VolCatInfo.VolCatName, jcr->Job);
+         Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
+            dcr->getVolCatName(), jcr->Job);
          set_new_volume_parameters(dcr);
          stat = false;
+         Dmsg0(100, "cannot create media record\n");
          goto bail_out;
       }
       if (dcr->NewVol) {
          /* Note, setting a new volume also handles any pending new file */
          set_new_volume_parameters(dcr);
-         dcr->NewFile = false;        /* this handled for new file too */
       } else {
          set_new_file_parameters(dcr);
       }
    }
 
-   if (!write_block_to_dev(dcr)) {
-       if (job_canceled(jcr) || jcr->JobType == JT_SYSTEM) {
+   if (!dcr->write_block_to_dev()) {
+       if (job_canceled(jcr) || jcr->getJobType() == JT_SYSTEM) {
           stat = false;
        } else {
           stat = fixup_device_block_write_error(dcr);
@@ -391,7 +409,7 @@ bool write_block_to_device(DCR *dcr)
 bail_out:
    if (!dcr->is_dev_locked()) {        /* did we lock dev above? */
       /* note, do not change this to dcr->dunlock */
-      dev->dunlock();                  /* unlock it now */
+      dev->Unlock();                  /* unlock it now */
    }
    return stat;
 }
@@ -402,40 +420,52 @@ bail_out:
  *  Returns: true  on success or EOT
  *           false on hard error
  */
-bool write_block_to_dev(DCR *dcr)
+bool DCR::write_block_to_dev()
 {
    ssize_t stat = 0;
    uint32_t wlen;                     /* length to write */
    int hit_max1, hit_max2;
    bool ok = true;
-   DEVICE *dev = dcr->dev;
-   JCR *jcr = dcr->jcr;
-   DEV_BLOCK *block = dcr->block;
+   DCR *dcr = this;
+   uint32_t checksum;
+
+   if (no_tape_write_test) {
+      empty_block(block);
+      return true;
+   }
+   if (job_canceled(jcr)) {
+      return false;
+   }
 
-#ifdef NO_TAPE_WRITE_TEST
-   empty_block(block);
-   return true;
-#endif
    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
-   ASSERT(dev->is_open());
+
+   wlen = block->binbuf;
+   if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
+      Dmsg0(100, "return write_block_to_dev no data to write\n");
+      return true;
+   }
 
    /* dump_block(block, "before write"); */
    if (dev->at_weot()) {
       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
       dev->dev_errno = ENOSPC;
-      Jmsg(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
+      Jmsg1(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM. dev=%s\n"), dev->print_name());
+      Dmsg1(100, "Attempt to write on read-only Volume. dev=%s\n", dev->print_name());
       return false;
    }
    if (!dev->can_append()) {
       dev->dev_errno = EIO;
-      Jmsg(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume.\n"));
+      Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume. dev=%s\n"), dev->print_name());
+      Dmsg1(100, "Attempt to write on read-only Volume. dev=%s\n", dev->print_name());
       return false;
    }
-   wlen = block->binbuf;
-   if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
-      Dmsg0(100, "return write_block_to_dev no data to write\n");
-      return true;
+   if (!dev->is_open()) {
+      Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on closed device=%s\n"), dev->print_name());
+      Dmsg1(100, "Attempt to write on closed device=%s\n", dev->print_name());
+      return false;
    }
+
    /*
     * Clear to the end of the buffer if it is not full,
     *  and on tape devices, apply min and fixed blocking.
@@ -464,7 +494,7 @@ bool write_block_to_dev(DCR *dcr)
       }
    }
 
-   ser_block_header(block);
+   checksum = ser_block_header(block, dev->do_checksum());
 
    /* Limit maximum Volume size to value specified by user */
    hit_max1 = (dev->max_volume_size > 0) &&
@@ -494,7 +524,7 @@ bool write_block_to_dev(DCR *dcr)
       dev->file_size = 0;             /* reset file size */
 
       if (!dev->weof(1)) {            /* write eof */
-         Dmsg0(190, "WEOF error in max file size.\n");
+         Dmsg0(50, "WEOF error in max file size.\n");
          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
             dev->bstrerror());
          terminate_writing_volume(dcr);
@@ -544,6 +574,15 @@ bool write_block_to_dev(DCR *dcr)
 
    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
 
+   if (debug_block_checksum) {
+      uint32_t achecksum = ser_block_header(block, dev->do_checksum());
+      if (checksum != achecksum) {
+         Jmsg2(jcr, M_ERROR, 0, _("Block checksum changed during write: before=%ud after=%ud\n"),
+            checksum, achecksum);
+         dump_block(block, "with checksum error");
+      }
+   }
+
 #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"));
@@ -573,12 +612,15 @@ bool write_block_to_dev(DCR *dcr)
       }
       if (dev->dev_errno == ENOSPC) {
          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
-            dev->VolCatInfo.VolCatName,
+            dev->getVolCatName(),
             dev->file, dev->block_num, dev->print_name(), wlen, stat);
       }
-      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));
+      if (debug_level >= 100) {
+         berrno be;
+         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, be.bstrerror(dev->dev_errno));
+      }
 
       ok = terminate_writing_volume(dcr);
       if (!ok && !forge_on) {
@@ -597,6 +639,7 @@ bool write_block_to_dev(DCR *dcr)
    dev->VolCatInfo.VolCatBlocks++;
    dev->EndBlock = dev->block_num;
    dev->EndFile  = dev->file;
+   dev->LastBlock = block->BlockNumber;
    block->BlockNumber++;
 
    /* Update dcr values */
@@ -678,7 +721,7 @@ static void reread_last_block(DCR *dcr)
          DEV_BLOCK *lblock = new_block(dev);
          /* Note, this can destroy dev->errmsg */
          dcr->block = lblock;
-         if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
+         if (!dcr->read_block_from_dev(NO_BLOCK_NUMBER_CHECK)) {
             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
                  dev->errmsg);
          } else {
@@ -686,11 +729,17 @@ static void reread_last_block(DCR *dcr)
              * 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, _(
-"Re-read of last block OK, but block numbers differ. Last block=%u Current block=%u.\n"),
-                    lblock->BlockNumber, block->BlockNumber);
+            if (lblock->BlockNumber != dev->LastBlock) {
+                if (dev->LastBlock > (lblock->BlockNumber + 1)) {
+                   Jmsg(jcr, M_FATAL, 0, _(
+"Re-read of last block: block numbers differ by more than one.\n"
+"Probable tape misconfiguration and data loss. Read block=%u Want block=%u.\n"),
+                       lblock->BlockNumber, dev->LastBlock);
+                 } else {
+                   Jmsg(jcr, M_ERROR, 0, _(
+"Re-read of last block OK, but block numbers differ. Read block=%u Want block=%u.\n"),
+                       lblock->BlockNumber, dev->LastBlock);
+                 }
             } else {
                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
             }
@@ -702,6 +751,11 @@ static void reread_last_block(DCR *dcr)
 #endif
 }
 
+/*
+ * If this routine is called, we do our bookkeeping and
+ *   then assure that the volume will not be written any
+ *   more.
+ */
 static bool terminate_writing_volume(DCR *dcr)
 {
    DEVICE *dev = dcr->dev;
@@ -710,12 +764,12 @@ static bool terminate_writing_volume(DCR *dcr)
    /* Create a JobMedia record to indicated end of tape */
    dev->VolCatInfo.VolCatFiles = dev->file;
    if (!dir_create_jobmedia_record(dcr)) {
-      Dmsg0(190, "Error from create JobMedia\n");
+      Dmsg0(50, "Error from create JobMedia\n");
       dev->dev_errno = EIO;
-       Jmsg(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
-            dcr->VolCatInfo.VolCatName, dcr->jcr->Job);
+        Mmsg2(dev->errmsg, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
+            dcr->getVolCatName(), dcr->jcr->Job);
+       Jmsg(dcr->jcr, M_FATAL, 0, "%s", dev->errmsg);
        ok = false;
-       goto bail_out;
    }
    dcr->block->write_failed = true;
    if (!dev->weof(1)) {         /* end the tape */
@@ -723,7 +777,7 @@ static bool terminate_writing_volume(DCR *dcr)
       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");
+      Dmsg0(50, "Error writing final EOF to volume.\n");
    }
    if (ok) {
       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
@@ -743,10 +797,12 @@ static bool terminate_writing_volume(DCR *dcr)
       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
    }
    
-   if (!dir_update_volume_info(dcr, false)) {
+   if (!dir_update_volume_info(dcr, false, true)) {
+      Mmsg(dev->errmsg, _("Error sending Volume info to Director.\n"));
       ok = false;
+      Dmsg0(50, "Error updating volume info.\n");
    }
-   Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
+   Dmsg1(50, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
 
    /*
     * Walk through all attached dcrs setting flag to call
@@ -766,10 +822,11 @@ static bool terminate_writing_volume(DCR *dcr)
       dev->VolCatInfo.VolCatErrors++;
       /* This may not be fatal since we already wrote an EOF */
       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
+      Dmsg0(50, "Writing second EOF failed.\n");
    }
-bail_out:
+
    dev->set_ateot();                  /* no more writing this tape */
-   Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
+   Dmsg1(50, "*** Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
    return ok;
 }
 
@@ -785,17 +842,17 @@ static bool do_new_file_bookkeeping(DCR *dcr)
 
    /* Create a JobMedia record so restore can seek */
    if (!dir_create_jobmedia_record(dcr)) {
-      Dmsg0(190, "Error from create_job_media.\n");
+      Dmsg0(50, "Error from create_job_media.\n");
       dev->dev_errno = EIO;
-      Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
-           dcr->VolCatInfo.VolCatName, jcr->Job);
+      Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
+           dcr->getVolCatName(), jcr->Job);
       terminate_writing_volume(dcr);
       dev->dev_errno = EIO;
       return false;
    }
    dev->VolCatInfo.VolCatFiles = dev->file;
-   if (!dir_update_volume_info(dcr, false)) {
-      Dmsg0(190, "Error from update_vol_info.\n");
+   if (!dir_update_volume_info(dcr, false, false)) {
+      Dmsg0(50, "Error from update_vol_info.\n");
       terminate_writing_volume(dcr);
       dev->dev_errno = EIO;
       return false;
@@ -852,7 +909,7 @@ static bool do_dvd_size_checks(DCR *dcr)
       
       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
             
-      if (!dir_update_volume_info(dcr, false)) {
+      if (!dir_update_volume_info(dcr, false, false)) {
          Dmsg0(190, "Error from update_vol_info.\n");
          dev->dev_errno = EIO;
          return false;
@@ -866,7 +923,7 @@ static bool do_dvd_size_checks(DCR *dcr)
       Dmsg1(100, "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 "
          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
-           dev->VolCatInfo.VolCatName,
+           dev->getVolCatName(),
            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);
@@ -879,7 +936,7 @@ static bool do_dvd_size_checks(DCR *dcr)
       Dmsg0(100, "==== 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 "
          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
-            dev->VolCatInfo.VolCatName,
+            dev->getVolCatName(),
             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);
@@ -895,14 +952,14 @@ static bool do_dvd_size_checks(DCR *dcr)
  * Read block with locking
  *
  */
-bool read_block_from_device(DCR *dcr, bool check_block_numbers)
+bool DCR::read_block_from_device(bool check_block_numbers)
 {
    bool ok;
-   DEVICE *dev = dcr->dev;
+
    Dmsg0(250, "Enter read_block_from_device\n");
-   dev->r_dlock();
-   ok = read_block_from_dev(dcr, check_block_numbers);
-   dev->dunlock();
+   dev->rLock();
+   ok = read_block_from_dev(check_block_numbers);
+   dev->Unlock();
    Dmsg0(250, "Leave read_block_from_device\n");
    return ok;
 }
@@ -912,24 +969,36 @@ bool read_block_from_device(DCR *dcr, bool check_block_numbers)
  *  the block header.  For a file, the block may be partially
  *  or completely in the current buffer.
  */
-bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
+bool DCR::read_block_from_dev(bool check_block_numbers)
 {
    ssize_t stat;
    int looping;
-   uint32_t BlockNumber;
    int retry;
-   JCR *jcr = dcr->jcr;
-   DEVICE *dev = dcr->dev;
-   DEV_BLOCK *block = dcr->block;
+   DCR *dcr = this;
 
-   ASSERT(dev->is_open());
+   if (job_canceled(jcr)) {
+      Mmsg(dev->errmsg, _("Job failed or canceled.\n"));
+      block->read_len = 0;
+      return false;
+   }
    
    if (dev->at_eot()) {
+      Mmsg(dev->errmsg, _("Attempt to read past end of tape or file.\n"));
+      block->read_len = 0;
       return false;
    }
    looping = 0;
    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
          block->buf_len);
+
+   if (!dev->is_open()) {
+      Mmsg4(dev->errmsg, _("Attempt to read closed device: fd=%d at file:blk %u:%u on device %s\n"),
+         dev->fd(), dev->file, dev->block_num, dev->print_name());
+      Jmsg(dcr->jcr, M_WARNING, 0, "%s", dev->errmsg);
+      block->read_len = 0;
+      return false;
+    }
+
 reread:
    if (looping > 1) {
       dev->dev_errno = EIO;
@@ -940,29 +1009,14 @@ reread:
       return false;
    }
    
-// #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"),
+         Mmsg3(dev->errmsg, _("Unable to open device part=%d %s: ERR=%s\n"),
                dev->part, dev->print_name(), dev->bstrerror());
+         Jmsg(dcr->jcr, M_FATAL, 0, "%s", dev->errmsg);
          dev->dev_errno = EIO;
          return false;
       }
@@ -1013,7 +1067,7 @@ reread:
    /* Continue here for successful read */
 
    block->read_len = stat;      /* save length read */
-   if (dev->at_eof() && block->read_len == 80 && 
+   if (block->read_len == 80 && 
         (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
          dcr->device->label_type != B_BACULA_LABEL)) {
       /* ***FIXME*** should check label */
@@ -1029,10 +1083,11 @@ reread:
       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
       dev->set_short_block();   
       block->read_len = block->binbuf = 0;
+      Dmsg2(200, "set block=%p binbuf=%d\n", block, block->binbuf);
       return false;             /* return error */
    }
 
-   BlockNumber = block->BlockNumber + 1;
+// BlockNumber = block->BlockNumber + 1;
    if (!unser_block_header(jcr, dev, block)) {
       if (forge_on) {
          dev->file_addr += block->read_len;
@@ -1057,7 +1112,8 @@ reread:
       if (dev->is_tape()) {
          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
          if (!dev->bsr(1)) {
-            Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
+            Mmsg(dev->errmsg, "%s", dev->bstrerror());
+            Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
             block->read_len = 0;
             return false;
          }
@@ -1105,11 +1161,15 @@ reread:
       dcr->EndBlock = dev->EndBlock;
       dcr->EndFile  = dev->EndFile;
    } else {
-      uint64_t addr = dev->file_addr + block->read_len - 1;
+      /* We need to take care about a short block in EndBlock/File
+       * computation 
+       */
+      uint32_t len = MIN(block->read_len, block->block_len);
+      uint64_t addr = dev->file_addr + 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 = dev->EndBlock = dcr->EndBlock;
+      dev->file = dev->EndFile = dcr->EndFile;
    }
    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
    dev->file_addr += block->read_len;