X-Git-Url: https://git.sur5r.net/?a=blobdiff_plain;f=bacula%2Fsrc%2Fstored%2Fblock.c;h=fb36d5a888d24f77a7fe24d8c8d075a861410257;hb=b22b260eaa7fb9f122523fff0e324dca5904b97f;hp=a3d354da1e337c5da0f10edf4906c8a30aa9bb26;hpb=49839d5884780b05d5323732715f3f28d4b77171;p=bacula%2Fbacula

diff --git a/bacula/src/stored/block.c b/bacula/src/stored/block.c
index a3d354da1e..fb36d5a888 100644
--- a/bacula/src/stored/block.c
+++ b/bacula/src/stored/block.c
@@ -401,6 +401,7 @@ bool write_block_to_dev(DCR *dcr)
    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()) {
@@ -509,9 +510,26 @@ bool write_block_to_dev(DCR *dcr)
 #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) {
@@ -533,6 +551,7 @@ bool write_block_to_dev(DCR *dcr)
             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"),
                dev->file, dev->block_num, dev->print_name(), be.strerror());
          }
@@ -559,18 +578,19 @@ bool write_block_to_dev(DCR *dcr)
    }
 
    /* 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->block_num++;
    block->BlockNumber++;
 
    /* Update dcr values */
    if (dev->is_tape()) {
       dcr->EndBlock = dev->EndBlock;
       dcr->EndFile  = dev->EndFile;
+      dev->block_num++;
    } else {
       /* Save address of block just written */
       uint64_t addr = dev->file_addr + wlen - 1;
@@ -636,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
-          *    tape is requested. Note, the clrerror_dev() call in bsr()
+          *    tape is requested. Note, the clrerror() call in bsr()
           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
           */
       }
@@ -699,8 +719,15 @@ static bool terminate_writing_volume(DCR *dcr)
    dev->VolCatInfo.VolCatJobs++;              /* increment number of jobs */
    
    if (dev->is_dvd()) {
-      dvd_write_part(dcr);                 /* write last part */
-      dev->VolCatInfo.VolCatParts = dev->num_parts;
+      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)) {
@@ -795,10 +822,10 @@ static bool do_dvd_size_checks(DCR *dcr)
    /* Limit maximum part size to value specified by user 
     */
    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
-      if (dev->part < dev->num_parts) {
+      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"),
-               dev->part, dev->num_parts, dev->print_name());
+               dev->part, dev->num_dvd_parts, dev->print_name());
          dev->dev_errno = EIO;
          return false;
       }
@@ -810,7 +837,7 @@ static bool do_dvd_size_checks(DCR *dcr)
          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");
@@ -818,6 +845,10 @@ static bool do_dvd_size_checks(DCR *dcr)
          return false;
       }
    }
+
+   if (!dev->is_freespace_ok()) {
+      update_free_space_dev(dev);
+   }
    
    if (!dev->is_freespace_ok()) { /* Error while getting free space */
       char ed1[50], ed2[50];
@@ -879,12 +910,14 @@ bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
    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;
-   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) {
@@ -896,22 +929,26 @@ reread:
       return false;
    }
    
-   /*Dmsg1(100, "dev->file_size=%u\n",(unsigned int)dev->file_size);
-   Dmsg1(100, "dev->file_addr=%u\n",(unsigned int)dev->file_addr);
-   Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd, 0, SEEK_CUR));
-   Dmsg1(100, "dev->part_start=%u\n",(unsigned int)dev->part_start);
-   Dmsg1(100, "dev->file_addr-dev->part_start=%u\n",(unsigned int)dev->file_addr-dev->part_start);
-   Dmsg1(100, "dev->file_size-dev->part_start=%u\n",(unsigned int)dev->file_size-dev->part_start);
-   Dmsg1(100, "dev->part_size=%u\n", (unsigned int)dev->part_size);
-   Dmsg1(100, "dev->part=%u\n", (unsigned int)dev->part);
-   Dmsg1(100, "dev->num_parts=%u\n", (unsigned int)dev->num_parts);
-   Dmsg1(100, "dev->VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
-   Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
+#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));*/
+         (dev->part <= dev->VolCatInfo.VolCatParts));
+  }
+#endif
+
    /* Check for DVD part file end */
-   if (dev->at_eof() && dev->is_dvd() && dev->num_parts > 0 &&
-        dev->part < dev->num_parts) {
+   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());
@@ -921,19 +958,22 @@ reread:
    }
    
    retry = 0;
+   errno = 0;
+   stat = 0;
    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;
       dev->clrerror(-1);
@@ -1004,9 +1044,9 @@ reread:
          }
       } 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;
-         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);
@@ -1039,6 +1079,9 @@ reread:
 
    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++;
@@ -1073,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];
-      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);
-      lseek_dev(dev, pos, SEEK_SET);
+      dev->lseek(dcr, pos, SEEK_SET);
       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;