X-Git-Url: https://git.sur5r.net/?a=blobdiff_plain;f=bacula%2Fsrc%2Fstored%2Fblock.c;h=92c56ecd6b0ef72ed0a129b9db3bab1d16176c5e;hb=8709733a5d458ffd671aada1a837537352cacdb8;hp=faa51c94d586b6bd542a72d0a527caf914e20bb8;hpb=abef8271979074d70e8c67a3591d0ce69e8425f2;p=bacula%2Fbacula diff --git a/bacula/src/stored/block.c b/bacula/src/stored/block.c index faa51c94d5..92c56ecd6b 100644 --- a/bacula/src/stored/block.c +++ b/bacula/src/stored/block.c @@ -1,331 +1,51 @@ +/* + Bacula(R) - The Network Backup Solution + + Copyright (C) 2000-2017 Kern Sibbald + + The original author of Bacula is Kern Sibbald, with contributions + from many others, a complete list can be found in the file AUTHORS. + + You may use this file and others of this release according to the + license defined in the LICENSE file, which includes the Affero General + Public License, v3.0 ("AGPLv3") and some additional permissions and + terms pursuant to its AGPLv3 Section 7. + + This notice must be preserved when any source code is + conveyed and/or propagated. + + Bacula(R) is a registered trademark of Kern Sibbald. +*/ /* * * block.c -- tape block handling functions * * Kern Sibbald, March MMI * added BB02 format October MMII - * - * Version $Id$ - * */ -/* - Bacula® - The Network Backup Solution - - Copyright (C) 2001-2007 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 - License as published by the Free Software Foundation plus additions - that are listed in the file LICENSE. - - This program is distributed in the hope that it will be useful, but - WITHOUT ANY WARRANTY; without even the implied warranty of - 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 - 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. - The licensor of Bacula is the Free Software Foundation Europe - (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich, - Switzerland, email:ftf@fsfeurope.org. -*/ #include "bacula.h" #include "stored.h" -static bool terminate_writing_volume(DCR *dcr); -static bool do_new_file_bookkeeping(DCR *dcr); -static bool do_dvd_size_checks(DCR *dcr); -static void reread_last_block(DCR *dcr); - -/* - * Dump the block header, then walk through - * the block printing out the record headers. - */ -void dump_block(DEV_BLOCK *b, const char *msg) -{ - ser_declare; - char *p; - char Id[BLKHDR_ID_LENGTH+1]; - uint32_t CheckSum, BlockCheckSum; - uint32_t block_len; - uint32_t BlockNumber; - uint32_t VolSessionId, VolSessionTime, data_len; - int32_t FileIndex; - int32_t Stream; - int bhl, rhl; - char buf1[100], buf2[100]; - - unser_begin(b->buf, BLKHDR1_LENGTH); - unser_uint32(CheckSum); - unser_uint32(block_len); - unser_uint32(BlockNumber); - unser_bytes(Id, BLKHDR_ID_LENGTH); - ASSERT(unser_length(b->buf) == BLKHDR1_LENGTH); - Id[BLKHDR_ID_LENGTH] = 0; - if (Id[3] == '2') { - unser_uint32(VolSessionId); - unser_uint32(VolSessionTime); - bhl = BLKHDR2_LENGTH; - rhl = RECHDR2_LENGTH; - } else { - VolSessionId = VolSessionTime = 0; - bhl = BLKHDR1_LENGTH; - rhl = RECHDR1_LENGTH; - } - - if (block_len > 100000) { - Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len); - return; - } - - 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"), - msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum); - p = b->buf + bhl; - while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) { - unser_begin(p, WRITE_RECHDR_LENGTH); - if (rhl == RECHDR1_LENGTH) { - unser_uint32(VolSessionId); - unser_uint32(VolSessionTime); - } - 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(buf1, FileIndex), - stream_to_ascii(buf2, Stream, FileIndex), data_len, p); - p += data_len + rhl; - } -} - -/* - * Create a new block structure. - * We pass device so that the block can inherit the - * min and max block sizes. - */ -DEV_BLOCK *new_block(DEVICE *dev) -{ - DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK)); - - memset(block, 0, sizeof(DEV_BLOCK)); - - /* If the user has specified a max_block_size, use it as the default */ - if (dev->max_block_size == 0) { - block->buf_len = DEFAULT_BLOCK_SIZE; - } else { - block->buf_len = dev->max_block_size; - } - block->dev = dev; - block->block_len = block->buf_len; /* default block size */ - block->buf = get_memory(block->buf_len); - empty_block(block); - block->BlockVer = BLOCK_VER; /* default write version */ - Dmsg1(650, "Returning new block=%x\n", block); - return block; -} - - -/* - * Duplicate an existing block (eblock) - */ -DEV_BLOCK *dup_block(DEV_BLOCK *eblock) -{ - DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK)); - int buf_len = sizeof_pool_memory(eblock->buf); - - memcpy(block, eblock, sizeof(DEV_BLOCK)); - block->buf = get_memory(buf_len); - memcpy(block->buf, eblock->buf, buf_len); - return block; -} - - -/* - * Only the first block checksum error was reported. - * If there are more, report it now. - */ -void print_block_read_errors(JCR *jcr, DEV_BLOCK *block) -{ - if (block->read_errors > 1) { - Jmsg(jcr, M_ERROR, 0, _("%d block read errors not printed.\n"), - block->read_errors); - } -} +#ifdef DEBUG_BLOCK_CHECKSUM +static const bool debug_block_checksum = true; +#else +static const bool debug_block_checksum = false; +#endif -/* - * Free 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); -} +static int debug_io_error = 0; /* # blocks to write before creating I/O error */ -/* Empty the block -- for writing */ -void empty_block(DEV_BLOCK *block) -{ - block->binbuf = WRITE_BLKHDR_LENGTH; - block->bufp = block->buf + block->binbuf; - block->read_len = 0; - block->write_failed = false; - block->block_read = false; - block->FirstIndex = block->LastIndex = 0; -} +#ifdef NO_TAPE_WRITE_TEST +static const bool no_tape_write_test = true; +#else +static const bool no_tape_write_test = false; +#endif -/* - * Create block header just before write. The space - * in the buffer should have already been reserved by - * init_block. - */ -void ser_block_header(DEV_BLOCK *block) -{ - ser_declare; - uint32_t CheckSum = 0; - uint32_t block_len = block->binbuf; - - 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_uint32(block->BlockNumber); - ser_bytes(WRITE_BLKHDR_ID, BLKHDR_ID_LENGTH); - if (BLOCK_VER >= 2) { - ser_uint32(block->VolSessionId); - ser_uint32(block->VolSessionTime); - } - /* Checksum whole block except for the 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 */ -} - -/* - * Unserialize the block header for reading block. - * This includes setting all the buffer pointers correctly. - * - * Returns: false on failure (not a block) - * true on success - */ -static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block) -{ - ser_declare; - char Id[BLKHDR_ID_LENGTH+1]; - uint32_t CheckSum, BlockCheckSum; - uint32_t block_len; - uint32_t block_end; - uint32_t BlockNumber; - int bhl; - - unser_begin(block->buf, BLKHDR_LENGTH); - unser_uint32(CheckSum); - unser_uint32(block_len); - unser_uint32(BlockNumber); - unser_bytes(Id, BLKHDR_ID_LENGTH); - ASSERT(unser_length(block->buf) == BLKHDR1_LENGTH); - - Id[BLKHDR_ID_LENGTH] = 0; - if (Id[3] == '1') { - bhl = BLKHDR1_LENGTH; - block->BlockVer = 1; - block->bufp = block->buf + bhl; - if (strncmp(Id, BLKHDR1_ID, BLKHDR_ID_LENGTH) != 0) { - dev->dev_errno = EIO; - Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"), - dev->file, dev->block_num, BLKHDR1_ID, Id); - if (block->read_errors == 0 || verbose >= 2) { - Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); - } - block->read_errors++; - return false; - } - } else if (Id[3] == '2') { - unser_uint32(block->VolSessionId); - unser_uint32(block->VolSessionTime); - bhl = BLKHDR2_LENGTH; - block->BlockVer = 2; - block->bufp = block->buf + bhl; - if (strncmp(Id, BLKHDR2_ID, BLKHDR_ID_LENGTH) != 0) { - dev->dev_errno = EIO; - Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"), - dev->file, dev->block_num, BLKHDR2_ID, Id); - if (block->read_errors == 0 || verbose >= 2) { - Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); - } - block->read_errors++; - return false; - } - } else { - dev->dev_errno = EIO; - Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"), - dev->file, dev->block_num, BLKHDR2_ID, Id); - if (block->read_errors == 0 || verbose >= 2) { - Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); - } - block->read_errors++; - unser_uint32(block->VolSessionId); - unser_uint32(block->VolSessionTime); - return false; - } - - /* Sanity check */ - if (block_len > MAX_BLOCK_LENGTH) { - dev->dev_errno = EIO; - Mmsg3(dev->errmsg, _("Volume data error at %u:%u! Block length %u is insane (too large), probably due to a bad archive.\n"), - dev->file, dev->block_num, block_len); - if (block->read_errors == 0 || verbose >= 2) { - Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); - } - block->read_errors++; - return false; - } - - Dmsg1(390, "unser_block_header block_len=%d\n", block_len); - /* Find end of block or end of buffer whichever is smaller */ - if (block_len > block->read_len) { - block_end = block->read_len; - } else { - block_end = block_len; - } - block->binbuf = block_end - bhl; - block->block_len = block_len; - block->BlockNumber = BlockNumber; - Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf, - bhl, block_len); - if (block_len <= block->read_len) { - BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH, - block_len-BLKHDR_CS_LENGTH); - if (BlockCheckSum != CheckSum) { - dev->dev_errno = EIO; - Mmsg6(dev->errmsg, _("Volume data error at %u:%u!\n" - "Block checksum mismatch in block=%u len=%d: calc=%x blk=%x\n"), - dev->file, dev->block_num, (unsigned)BlockNumber, - block_len, BlockCheckSum, CheckSum); - if (block->read_errors == 0 || verbose >= 2) { - Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); - } - block->read_errors++; - if (!forge_on) { - return false; - } - } - } - return true; -} +uint32_t get_len_and_clear_block(DEV_BLOCK *block, DEVICE *dev, uint32_t &pad); +uint32_t ser_block_header(DEV_BLOCK *block, bool do_checksum); +bool unser_block_header(DCR *dcr, DEVICE *dev, DEV_BLOCK *block); /* * Write a block to the device, with locking and unlocking @@ -334,63 +54,63 @@ 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 final) { - bool stat = true; - DEVICE *dev = dcr->dev; - JCR *jcr = dcr->jcr; + bool ok = true; + DCR *dcr = this; if (dcr->spooling) { - stat = write_block_to_spool_file(dcr); - return stat; + Dmsg0(250, "Write to spool\n"); + ok = write_block_to_spool_file(dcr); + return ok; } - if (!dcr->dev_locked) { /* device already locked? */ - lock_device(dev); /* no, lock it */ + if (!is_dev_locked()) { /* device already locked? */ + /* note, do not change this to dcr->rLock */ + dev->rLock(false); /* no, lock it */ } - /* - * If a new volume has been mounted since our last write - * Create a JobMedia record for the previous volume written, - * and set new parameters to write this volume - * The same applies for if we are in a new file. - */ - if (dcr->NewVol || dcr->NewFile) { - if (job_canceled(jcr)) { - stat = false; - 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); - set_new_volume_parameters(dcr); - stat = false; - 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 */ + if (!check_for_newvol_or_newfile(dcr)) { + ok = false; + goto bail_out; /* fatal error */ + } + + Dmsg1(500, "Write block to dev=%p\n", dcr->dev); + if (!write_block_to_dev()) { + Dmsg2(40, "*** Failed write_block_to_dev adata=%d block=%p\n", + block->adata, block); + if (job_canceled(jcr) || jcr->getJobType() == JT_SYSTEM) { + ok = false; + Dmsg2(40, "cancel=%d or SYSTEM=%d\n", job_canceled(jcr), + jcr->getJobType() == JT_SYSTEM); } else { - set_new_file_parameters(dcr); + bool was_adata = false; + if (was_adata) { + dcr->set_ameta(); + was_adata = true; + } + /* Flush any existing JobMedia info */ + if (!(ok = dir_create_jobmedia_record(dcr))) { + Jmsg(jcr, M_FATAL, 0, _("Error writing JobMedia record to catalog.\n")); + } else { + Dmsg1(40, "Calling fixup_device was_adata=%d...\n", was_adata); + ok = fixup_device_block_write_error(dcr); + } + if (was_adata) { + dcr->set_adata(); + } } } - - if (!write_block_to_dev(dcr)) { - if (job_canceled(jcr) || jcr->JobType == JT_SYSTEM) { - stat = false; - } else { - stat = fixup_device_block_write_error(dcr); - } + if (ok && final && !dir_create_jobmedia_record(dcr)) { + Jmsg(jcr, M_FATAL, 0, _("Error writing final JobMedia record to catalog.\n")); } bail_out: - if (!dcr->dev_locked) { /* did we lock dev above? */ - dev->unlock(); /* unlock it now */ + if (!dcr->is_dev_locked()) { /* did we lock dev above? */ + /* note, do not change this to dcr->dunlock */ + dev->Unlock(); /* unlock it now */ } - return stat; + return ok; } /* @@ -399,122 +119,73 @@ 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; + uint32_t pad; /* padding or zeros written */ + boffset_t pos; + char ed1[50]; -#ifdef NO_TAPE_WRITE_TEST - empty_block(block); - return true; -#endif - ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf))); - ASSERT(dev->is_open()); + if (no_tape_write_test) { + empty_block(block); + return true; + } + if (job_canceled(jcr)) { + return false; + } + if (!dev->enabled) { + Jmsg1(jcr, M_FATAL, 0, _("Cannot write block. Device is disabled. dev=%s\n"), dev->print_name()); + return false; + } + + ASSERT2(block->adata == dev->adata, "Block and dev adata not same"); + Dmsg4(200, "fd=%d adata=%d bufp-buf=%d binbuf=%d\n", dev->fd(), block->adata, + block->bufp-block->buf, block->binbuf); + ASSERT2(block->binbuf == ((uint32_t)(block->bufp - block->buf)), "binbuf badly set"); + + if (is_block_empty(block)) { /* Does block have data in it? */ + Dmsg1(50, "return write_block_to_dev no adata=%d data to write\n", block->adata); + return true; + } - /* dump_block(block, "before write"); */ if (dev->at_weot()) { - Dmsg0(100, "return write_block_to_dev with ST_WEOT\n"); + Dmsg1(50, "==== FATAL: At EOM with ST_WEOT. adata=%d.\n", dev->adata); 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()); 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(50, "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; - } - /* - * Clear to the end of the buffer if it is not full, - * and on tape devices, apply min and fixed blocking. - */ - if (wlen != block->buf_len) { - uint32_t blen; /* current buffer length */ - - Dmsg2(200, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len); - blen = wlen; - /* Adjust write size to min/max for tapes only */ - if (dev->is_tape()) { - /* check for fixed block size */ - if (dev->min_block_size == dev->max_block_size) { - wlen = block->buf_len; /* fixed block size already rounded */ - /* Check for min block size */ - } else if (wlen < dev->min_block_size) { - wlen = ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE; - /* Ensure size is rounded */ - } else { - wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE; - } - } - if (wlen-blen > 0) { - memset(block->bufp, 0, wlen-blen); /* clear garbage */ - } + if (!dev->is_open()) { + Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on closed device=%s\n"), dev->print_name()); + Dmsg1(50, "Attempt to write on closed device=%s\n", dev->print_name()); + return false; } - ser_block_header(block); + wlen = get_len_and_clear_block(block, dev, pad); + block->block_len = wlen; + dev->updateVolCatPadding(pad); - /* Limit maximum Volume size to value specified by user */ - hit_max1 = (dev->max_volume_size > 0) && - ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size; - hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) && - ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes; - if (hit_max1 || hit_max2) { - char ed1[50]; - uint64_t max_cap; - Dmsg0(10, "==== Output bytes Triggered medium max capacity.\n"); - if (hit_max1) { - max_cap = dev->max_volume_size; - } else { - 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->print_name()); - terminate_writing_volume(dcr); - reread_last_block(dcr); /* DEBUG */ - dev->dev_errno = ENOSPC; + checksum = ser_block_header(block, dev->do_checksum()); + + if (!dev->do_size_checks(dcr, block)) { + Dmsg0(50, "Size check triggered. Cannot write block.\n"); return false; } - /* Limit maximum File size on volume to user specified value */ - if ((dev->max_file_size > 0) && - (dev->file_size+block->binbuf) >= dev->max_file_size) { - dev->file_size = 0; /* reset file size */ - - 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"), - dev->bstrerror()); - terminate_writing_volume(dcr); - dev->dev_errno = ENOSPC; - return false; - } - if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) { - return false; - } + dev->updateVolCatWrites(1); - if (!do_new_file_bookkeeping(dcr)) { - /* Error message already sent */ - return false; - } - } - - if (!do_dvd_size_checks(dcr)) { - /* Error message already sent */ - return false; - } + dump_block(dev, block, "before write"); - dev->VolCatInfo.VolCatWrites++; - 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) { @@ -523,30 +194,81 @@ bool write_block_to_dev(DCR *dcr) #endif /* - * Do write here, make a somewhat feeble attempt to recover from + * If Adata block, we must seek to the correct address + */ + if (block->adata) { + ASSERT(dcr->dev->adata); + uint64_t cur = dev->lseek(dcr, 0, SEEK_CUR); + /* If we are going to create a hole, record it */ + if (block->BlockAddr != cur) { + dev->lseek(dcr, block->BlockAddr, SEEK_SET); + Dmsg4(100, "Adata seek BlockAddr from %lld to %lld = %lld bytes adata_addr=%lld\n", + cur, block->BlockAddr, block->BlockAddr - cur, dev->adata_addr); + /* Insanity check */ + if (block->BlockAddr > cur) { + dev->updateVolCatHoleBytes(block->BlockAddr - cur); + } else if (block->BlockAddr < cur) { + Pmsg5(000, "Vol=%s cur=%lld BlockAddr=%lld adata=%d block=%p\n", + dev->getVolCatName(), cur, block->BlockAddr, block->adata, block); + Jmsg3(jcr, M_FATAL, 0, "Bad seek on adata Vol=%s BlockAddr=%lld DiskAddr=%lld. Multiple simultaneous Jobs?\n", + dev->getVolCatName(), block->BlockAddr, cur); + //Pmsg2(000, "HoleBytes would go negative cur=%lld blkaddr=%lld\n", cur, block->BlockAddr); + } + } + } + + /* + * Do write here, make a somewhat feeble attempt to recover from * I/O errors, or from the OS telling us it is busy. - */ + */ int retry = 0; errno = 0; stat = 0; + /* ***FIXME**** remove next line debug */ + pos = dev->lseek(dcr, 0, SEEK_CUR); do { if (retry > 0 && stat == -1 && errno == EBUSY) { berrno be; Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n", - retry, stat, errno, be.strerror()); + retry, stat, errno, be.bstrerror()); bmicrosleep(5, 0); /* pause a bit if busy or lots of errors */ dev->clrerror(-1); } stat = dev->write(block->buf, (size_t)wlen); - + Dmsg4(100, "%s write() BlockAddr=%lld wlen=%d Vol=%s wlen=%d\n", + block->adata?"Adata":"Ameta", block->BlockAddr, wlen, + dev->VolHdr.VolumeName); } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3); + /* ***FIXME*** remove 2 lines debug */ + Dmsg2(100, "Wrote %d bytes at %s\n", wlen, dev->print_addr(ed1, sizeof(ed1), pos)); + dump_block(dev, block, "After write"); + + 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=%u after=%u\n"), + checksum, achecksum); + dump_block(dev, 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")); } #endif + if (debug_io_error) { + debug_io_error--; + if (debug_io_error == 1) { /* trigger error */ + stat = -1; + dev->dev_errno = EIO; + errno = EIO; + debug_io_error = 0; /* turn off trigger */ + } + } + if (stat != (ssize_t)wlen) { /* Some devices simply report EIO when the volume is full. * With a little more thought we may be able to check @@ -556,31 +278,49 @@ bool write_block_to_dev(DCR *dcr) */ if (stat == -1) { berrno be; - dev->clrerror(-1); + dev->clrerror(-1); /* saves errno in dev->dev_errno */ if (dev->dev_errno == 0) { dev->dev_errno = ENOSPC; /* out of space */ } if (dev->dev_errno != ENOSPC) { + int etype = M_ERROR; + if (block->adata) { + etype = M_FATAL; + } 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()); + Jmsg4(jcr, etype, 0, _("Write error at %s on device %s Vol=%s. ERR=%s.\n"), + dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), + dev->getVolCatName(), be.bstrerror()); + if (dev->get_tape_alerts(this)) { + dev->show_tape_alerts(this, list_long, list_last, alert_callback); + } } } else { dev->dev_errno = ENOSPC; /* out of space */ } 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->file, dev->block_num, dev->print_name(), wlen, stat); + dev->update_freespace(); + if (dev->is_freespace_ok() && dev->free_space < dev->min_free_space) { + dev->set_nospace(); + Jmsg(jcr, M_FATAL, 0, _("Out of freespace caused End of Volume \"%s\" at %s on device %s. Write of %u bytes got %d.\n"), + dev->getVolCatName(), + dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), wlen, stat); + } else { + dev->clear_nospace(); + Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %s on device %s. Write of %u bytes got %d.\n"), + dev->getVolCatName(), + dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), wlen, stat); + } + } + if (chk_dbglvl(100)) { + berrno be; + Dmsg7(90, "==== 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)); } - 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)); + Dmsg0(40, "Calling terminate_writing_volume\n"); ok = terminate_writing_volume(dcr); - if (!ok && !forge_on) { - return false; - } if (ok) { reread_last_block(dcr); } @@ -588,301 +328,74 @@ bool write_block_to_dev(DCR *dcr) } /* We successfully wrote the block, now do housekeeping */ - 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; + Dmsg2(1300, "VolCatBytes=%lld newVolCatBytes=%lld\n", dev->VolCatInfo.VolCatBytes, + (dev->VolCatInfo.VolCatBytes+wlen)); + if (!dev->setVolCatAdataBytes(block->BlockAddr + wlen)) { + dev->updateVolCatBytes(wlen); + Dmsg3(200, "AmetaBytes=%lld AdataBytes=%lld Bytes=%lld\n", + dev->VolCatInfo.VolCatAmetaBytes, dev->VolCatInfo.VolCatAdataBytes, dev->VolCatInfo.VolCatBytes); + } + dev->updateVolCatBlocks(1); + dev->LastBlock = block->BlockNumber; block->BlockNumber++; /* Update dcr values */ if (dev->is_tape()) { - dcr->EndBlock = dev->EndBlock; - dcr->EndFile = dev->EndFile; + dev->EndAddr = dev->get_full_addr(); + if (dcr->EndAddr < dev->EndAddr) { + dcr->EndAddr = dev->EndAddr; + } dev->block_num++; } else { - /* Save address of block just written */ + /* Save address of byte 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 (block->LastIndex > 0) { - dcr->VolLastIndex = block->LastIndex; - } - dcr->WroteVol = true; - dev->file_addr += wlen; /* update file address */ - dev->file_size += wlen; - dev->part_size += wlen; - - Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen); - empty_block(block); - return true; -} - -static void reread_last_block(DCR *dcr) -{ -#define CHECK_LAST_BLOCK -#ifdef CHECK_LAST_BLOCK - bool ok = true; - DEVICE *dev = dcr->dev; - JCR *jcr = dcr->jcr; - DEV_BLOCK *block = dcr->block; - /* - * If the device is a tape and it supports backspace record, - * we backspace over one or two eof marks depending on - * how many we just wrote, then over the last record, - * then re-read it and verify that the block number is - * correct. - */ - if (dev->is_tape() && dev->has_cap(CAP_BSR)) { - /* Now back up over what we wrote and read the last block */ - 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)); - } - 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 */ - if (ok && !dev->bsr(1)) { - berrno be; - ok = false; - Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), - be.strerror(dev->dev_errno)); - /* - * On FreeBSD systems, if the user got here, it is likely that his/her - * tape drive is "frozen". The correct thing to do is a - * 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() call in bsr() - * calls ioctl(MTCERRSTAT), which *should* fix the problem. - */ - } - if (ok) { - 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)) { - Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), - dev->errmsg); - } 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, _( -"Re-read of last block OK, but block numbers differ. Last block=%u Current block=%u.\n"), - lblock->BlockNumber, block->BlockNumber); - } else { - Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n")); - } + if (dev->is_indexed()) { + uint64_t full_addr = dev->get_full_addr(addr); + if (full_addr < dcr->EndAddr) { + Pmsg2(000, "Possible incorrect EndAddr oldEndAddr=%llu newEndAddr=%llu\n", + dcr->EndAddr, full_addr); } - free_block(lblock); - dcr->block = block; + dcr->EndAddr = full_addr; } - } -#endif -} - -static bool terminate_writing_volume(DCR *dcr) -{ - DEVICE *dev = dcr->dev; - bool ok = true; - /* 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"); - 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); - ok = false; - goto bail_out; - } - dcr->block->write_failed = true; - if (!dev->weof(1)) { /* end the tape */ - dev->VolCatInfo.VolCatErrors++; - 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"); - } - if (ok) { - ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName); - } - bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus)); - dev->VolCatInfo.VolCatFiles = dev->file; /* set number of files */ - - 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"); + if (dev->adata) { + /* We really should use file_addr, but I am not sure it is correctly set */ + Dmsg3(100, "Set BlockAddr from %lld to %lld adata_addr=%lld\n", + block->BlockAddr, block->BlockAddr + wlen, dev->adata_addr); + block->BlockAddr += wlen; + dev->adata_addr = block->BlockAddr; + } else { + block->BlockAddr = dev->get_full_addr() + wlen; } - dev->VolCatInfo.VolCatParts = dev->num_dvd_parts; - } - - if (!dir_update_volume_info(dcr, false)) { - ok = false; } - Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR"); - - /* - * Walk through all attached dcrs setting flag to call - * set_new_file_parameters() when that dcr is next used. - */ - DCR *mdcr; - foreach_dlist(mdcr, dev->attached_dcrs) { - if (mdcr->jcr->JobId == 0) { - continue; + if (dev->is_indexed()) { + if (dcr->VolMediaId != dev->VolCatInfo.VolMediaId) { + Dmsg7(100, "JobMedia Vol=%s wrote=%d MediaId=%lld FI=%lu LI=%lu StartAddr=%lld EndAddr=%lld Wrote\n", + dcr->VolumeName, dcr->WroteVol, dcr->VolMediaId, + dcr->VolFirstIndex, dcr->VolLastIndex, dcr->StartAddr, dcr->EndAddr); } - mdcr->NewFile = true; /* set reminder to do set_new_file_params */ - } - /* Set new file/block parameters for current dcr */ - set_new_file_parameters(dcr); - - if (ok && dev->has_cap(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); - } -bail_out: - dev->set_ateot(); /* no more writing this tape */ - Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR"); - return ok; -} - -/* - * Do bookkeeping when a new file is created on a Volume. This is - * also done for disk files to generate the jobmedia records for - * quick seeking. - */ -static bool do_new_file_bookkeeping(DCR *dcr) -{ - DEVICE *dev = dcr->dev; - JCR *jcr = dcr->jcr; - - /* Create a JobMedia record so restore can seek */ - if (!dir_create_jobmedia_record(dcr)) { - Dmsg0(190, "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); - 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"); - terminate_writing_volume(dcr); - dev->dev_errno = EIO; - return false; - } - Dmsg0(100, "dir_update_volume_info max file size -- OK\n"); - - /* - * Walk through all attached dcrs setting flag to call - * set_new_file_parameters() when that dcr is next used. - */ - DCR *mdcr; - foreach_dlist(mdcr, dev->attached_dcrs) { - if (mdcr->jcr->JobId == 0) { - continue; + dcr->VolMediaId = dev->VolCatInfo.VolMediaId; + Dmsg3(150, "VolFirstIndex=%d blockFirstIndex=%d Vol=%s\n", + dcr->VolFirstIndex, block->FirstIndex, dcr->VolumeName); + if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) { + dcr->VolFirstIndex = block->FirstIndex; } - mdcr->NewFile = true; /* set reminder to do set_new_file_params */ - } - /* Set new file/block parameters for current dcr */ - set_new_file_parameters(dcr); - return true; -} - -/* - * Do all checks for DVD sizes during writing. - */ -static bool do_dvd_size_checks(DCR *dcr) -{ - DEVICE *dev = dcr->dev; - 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 - */ - 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"), - dev->part, dev->num_dvd_parts, dev->print_name()); - dev->dev_errno = EIO; - return false; - } - - if (dvd_open_next_part(dcr) < 0) { - Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"), - dev->print_name(), dev->bstrerror()); - dev->dev_errno = EIO; - return false; - } - - dev->VolCatInfo.VolCatParts = dev->num_dvd_parts; - - if (!dir_update_volume_info(dcr, false)) { - Dmsg0(190, "Error from update_vol_info.\n"); - dev->dev_errno = EIO; - return false; + if (block->LastIndex > (int32_t)dcr->VolLastIndex) { + dcr->VolLastIndex = block->LastIndex; } + dcr->WroteVol = true; } - dev->update_freespace(); - - 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 " - "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"), - dev->VolCatInfo.VolCatName, - 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; - return false; + dev->file_addr += wlen; /* update file address */ + dev->file_size += wlen; + dev->usage += wlen; /* update usage counter */ + if (dev->part > 0) { + dev->part_size += wlen; } - - 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 " - "(part_size=%s, free_space=%s, free_space_errno=%d).\n"), - dev->VolCatInfo.VolCatName, - 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); - terminate_writing_volume(dcr); - dev->dev_errno = ENOSPC; - return false; - } + dev->setVolCatInfo(false); /* Needs update */ + + Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen); + empty_block(block); return true; } @@ -891,140 +404,227 @@ 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(200, "Enter read_block_from_device\n"); - lock_device(dev); - ok = read_block_from_dev(dcr, check_block_numbers); - unlock_device(dev); - Dmsg0(200, "Leave read_block_from_device\n"); + + Dmsg0(250, "Enter read_block_from_device\n"); + dev->rLock(false); + ok = read_block_from_dev(check_block_numbers); + dev->rUnlock(); + Dmsg1(250, "Leave read_block_from_device. ok=%d\n", ok); return ok; } +static void set_block_position(DCR *dcr, DEVICE *dev, DEV_BLOCK *block) +{ + /* Used also by the Single Item Restore code to locate a particular block */ + if (dev->is_tape()) { + block->BlockAddr = dev->get_full_addr(); + + } else if (!dev->adata) { /* TODO: See if we just use !dev->adata for tapes */ + /* Note: we only update the DCR values for ameta blocks + * because all the indexing (JobMedia) is done with + * ameta blocks/records, which may point to adata. + */ + block->BlockAddr = dev->get_full_addr(); + } + block->RecNum = 0; +} + /* * Read the next block into the block structure and unserialize * the block header. For a file, the block may be partially * or completely in the current buffer. + * Note: in order for bscan to generate correct JobMedia records + * we must be careful to update the EndAddr of the last byte read. */ -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; + boffset_t pos; + char ed1[50]; + uint32_t data_len; + + if (job_canceled(jcr)) { + Mmsg(dev->errmsg, _("Job failed or canceled.\n")); + Dmsg1(000, "%s", dev->errmsg); + block->read_len = 0; + return false; + } + if (!dev->enabled) { + Mmsg(dev->errmsg, _("Cannot write block. Device is disabled. dev=%s\n"), dev->print_name()); + Jmsg1(jcr, M_FATAL, 0, "%s", dev->errmsg); + return false; + } - ASSERT(dev->is_open()); - if (dev->at_eot()) { + Mmsg(dev->errmsg, _("At EOT: attempt to read past end of Volume.\n")); + Dmsg1(000, "%s", dev->errmsg); + block->read_len = 0; return false; } looping = 0; - Dmsg1(200, "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_FATAL, 0, "%s", dev->errmsg); + Pmsg4(000, "Fatal: dev=%p dcr=%p adata=%d bytes=%lld\n", dev, dcr, dev->adata, + VolCatInfo.VolCatAdataRBytes); + Pmsg1(000, "%s", dev->errmsg); + block->read_len = 0; + return false; + } + + set_block_position(dcr, dev, block); + reread: if (looping > 1) { dev->dev_errno = EIO; Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"), dev->print_name()); + Dmsg1(000, "%s", dev->errmsg); Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); block->read_len = 0; 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"), - dev->part, dev->print_name(), dev->bstrerror()); - dev->dev_errno = EIO; - return false; + /* See if we must open another part */ + if (dev->at_eof() && !dev->open_next_part(dcr)) { + if (dev->at_eof()) { /* EOF just seen? */ + dev->set_eot(); /* yes, error => EOT */ } + return false; } - + retry = 0; errno = 0; stat = 0; + + if (dev->adata) { + dev->lseek(dcr, dcr->block->BlockAddr, SEEK_SET); + } + { /* debug block */ + pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */ + Dmsg2(200, "Pos for read=%s %lld\n", + dev->print_addr(ed1, sizeof(ed1), pos), pos); + } + + data_len = 0; + do { - if ((retry > 0 && stat == -1 && errno == EBUSY)) { - berrno be; - Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n", - retry, stat, errno, be.strerror()); - bmicrosleep(10, 0); /* pause a bit if busy or lots of errors */ - dev->clrerror(-1); - } - stat = dev->read(block->buf, (size_t)block->buf_len); + retry = 0; + + do { + if ((retry > 0 && stat == -1 && errno == EBUSY)) { + berrno be; + Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n", + retry, stat, errno, be.bstrerror()); + bmicrosleep(10, 0); /* pause a bit if busy or lots of errors */ + dev->clrerror(-1); + } + stat = dev->read(block->buf + data_len, (size_t)(block->buf_len - data_len)); + if (stat > 0) + data_len += stat; + + } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3); - } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3); + } while (data_len < block->buf_len && stat > 0 && dev->dev_type == B_FIFO_DEV); + + Dmsg4(110, "Read() adata=%d vol=%s nbytes=%d pos=%lld\n", + block->adata, dev->VolHdr.VolumeName, stat < 0 ? stat : data_len, pos); if (stat < 0) { berrno be; dev->clrerror(-1); - Dmsg1(200, "Read device got: ERR=%s\n", be.strerror()); + Dmsg2(90, "Read device fd=%d got: ERR=%s\n", dev->fd(), be.bstrerror()); block->read_len = 0; - Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"), - dev->fd(), dev->file, dev->block_num, dev->print_name(), be.strerror()); + if (reading_label) { /* Trying to read Volume label */ + Mmsg(dev->errmsg, _("The %sVolume=%s on device=%s appears to be unlabeled.%s\n"), + dev->adata?"adata ":"", VolumeName, dev->print_name(), + dev->is_fs_nearly_full(1048576)?" Notice that the filesystem is nearly full.":""); + } else { + Mmsg4(dev->errmsg, _("Read error on fd=%d at addr=%s on device %s. ERR=%s.\n"), + dev->fd(), dev->print_addr(ed1, sizeof(ed1)), dev->print_name(), be.bstrerror()); + } Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); + if (dev->get_tape_alerts(this)) { + dev->show_tape_alerts(this, list_long, list_last, alert_callback); + } if (dev->at_eof()) { /* EOF just seen? */ dev->set_eot(); /* yes, error => EOT */ } return false; } - Dmsg3(200, "Read device got %d bytes at %u:%u\n", stat, - dev->file, dev->block_num); + + stat = data_len; + if (stat == 0) { /* Got EOF ! */ - dev->block_num = 0; + pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */ + pos = dev->get_full_addr(pos); + if (reading_label) { /* Trying to read Volume label */ + Mmsg4(dev->errmsg, _("The %sVolume=%s on device=%s appears to be unlabeled.%s\n"), + dev->adata?"adata ":"", VolumeName, dev->print_name(), + dev->is_fs_nearly_full(1048576)?" Notice tha the filesystem is nearly full.":""); + } else { + Mmsg4(dev->errmsg, _("Read zero %sbytes Vol=%s at %s on device %s.\n"), + dev->adata?"adata ":"", dev->VolCatInfo.VolCatName, + dev->print_addr(ed1, sizeof(ed1), pos), dev->print_name()); + } block->read_len = 0; - Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"), - dev->file, dev->block_num, dev->print_name()); - if (dev->at_eof()) { /* EOF already read? */ - dev->set_eot(); /* yes, 2 EOFs => EOT */ - return 0; + Dmsg1(100, "%s", dev->errmsg); + if (dev->at_eof()) { /* EOF just seen? */ + dev->set_eot(); /* yes, error => EOT */ } dev->set_ateof(); + dev->file_addr = 0; + dev->EndAddr = pos; + if (dcr->EndAddr < dev->EndAddr) { + dcr->EndAddr = dev->EndAddr; + } + Dmsg3(150, "==== Read zero bytes. adata=%d vol=%s at %s\n", dev->adata, + dev->VolCatInfo.VolCatName, dev->print_addr(ed1, sizeof(ed1), pos)); return false; /* return eof */ } + /* Continue here for successful read */ + block->read_len = stat; /* save length read */ - 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->print_name()); - Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); - dev->set_short_block(); - block->read_len = block->binbuf = 0; - return false; /* return error */ - } + if (block->adata) { + block->binbuf = block->read_len; + block->block_len = block->read_len; + } else { + if (block->read_len == 80 && + (dcr->VolCatInfo.LabelType != B_BACULA_LABEL || + dcr->device->label_type != B_BACULA_LABEL)) { + /* ***FIXME*** should check label */ + Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num); + dev->clear_eof(); + goto reread; /* skip ANSI/IBM label */ + } - BlockNumber = block->BlockNumber + 1; - if (!unser_block_header(jcr, dev, block)) { - if (forge_on) { - dev->file_addr += block->read_len; - dev->file_size += block->read_len; - goto reread; + if (block->read_len < BLKHDR2_LENGTH) { + dev->dev_errno = EIO; + Mmsg3(dev->errmsg, _("Volume data error at %s! Very short block of %d bytes on device %s discarded.\n"), + dev->print_addr(ed1, sizeof(ed1)), block->read_len, dev->print_name()); + Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); + dev->set_short_block(); + block->read_len = block->binbuf = 0; + Dmsg2(50, "set block=%p binbuf=%d\n", block, block->binbuf); + return false; /* return error */ + } + + if (!unser_block_header(this, dev, block)) { + if (forge_on) { + dev->file_addr += block->read_len; + dev->file_size += block->read_len; + goto reread; + } + return false; } - return false; } /* @@ -1032,6 +632,7 @@ reread: * re-reading the block, allocate a buffer of the correct size, * and go re-read. */ + Dmsg3(150, "adata=%d block_len=%d buf_len=%d\n", block->adata, block->block_len, block->buf_len); if (block->block_len > block->buf_len) { dev->dev_errno = EIO; Mmsg2(dev->errmsg, _("Block length %u is greater than buffer %u. Attempting recovery.\n"), @@ -1040,14 +641,17 @@ reread: Pmsg1(000, "%s", dev->errmsg); /* Attempt to reposition to re-read the block */ if (dev->is_tape()) { - Dmsg0(200, "BSR for reread; block too big for buffer.\n"); + 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()); + if (dev->errmsg[0]) { + Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg); + } block->read_len = 0; return false; } } else { - Dmsg0(200, "Seek to beginning of block for reread.\n"); + Dmsg0(250, "Seek to beginning of block for reread.\n"); boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */ pos -= block->read_len; dev->lseek(dcr, pos, SEEK_SET); @@ -1078,31 +682,35 @@ reread: dev->clear_short_block(); dev->clear_eof(); - dev->VolCatInfo.VolCatReads++; - dev->VolCatInfo.VolCatRBytes += block->read_len; - - dev->VolCatInfo.VolCatBytes += block->block_len; - dev->VolCatInfo.VolCatBlocks++; - if (dev->VolCatInfo.VolFirstWritten == 0) { - dev->VolCatInfo.VolFirstWritten = (utime_t)time(NULL); /* Set first written time */ - } - dev->EndBlock = dev->block_num; - dev->EndFile = dev->file; - dev->block_num++; + dev->updateVolCatReads(1); + dev->updateVolCatReadBytes(block->read_len); /* Update dcr values */ if (dev->is_tape()) { - dcr->EndBlock = dev->EndBlock; - dcr->EndFile = dev->EndFile; + dev->EndAddr = dev->get_full_addr(); + if (dcr->EndAddr < dev->EndAddr) { + dcr->EndAddr = dev->EndAddr; + } + dev->block_num++; } else { - 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; + /* 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->get_full_addr() + len - 1; + if (dev->is_indexed()) { + if (addr > dcr->EndAddr) { + dcr->EndAddr = addr; + } + } + dev->EndAddr = addr; + } + if (dev->is_indexed()) { + dcr->VolMediaId = dev->VolCatInfo.VolMediaId; } dev->file_addr += block->read_len; dev->file_size += block->read_len; + dev->usage += block->read_len; /* update usage counter */ /* * If we read a short block on disk, @@ -1117,21 +725,21 @@ reread: * lseek(). One to get the position, then the second to do an * absolute positioning -- so much for efficiency. KES Sep 02. */ - Dmsg0(200, "At end of read block\n"); + Dmsg0(250, "At end of read block\n"); if (block->read_len > block->block_len && !dev->is_tape()) { char ed1[50]; boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */ - Dmsg1(200, "Current lseek pos=%s\n", edit_int64(pos, ed1)); + Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1)); pos -= (block->read_len - block->block_len); dev->lseek(dcr, pos, SEEK_SET); - Dmsg3(200, "Did lseek pos=%s blk_size=%d rdlen=%d\n", + Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", edit_int64(pos, ed1), block->block_len, block->read_len); dev->file_addr = pos; dev->file_size = pos; } - Dmsg2(200, "Exit read_block read_len=%d block_len=%d\n", - block->read_len, block->block_len); + Dmsg3(150, "Exit read_block read_len=%d block_len=%d binbuf=%d\n", + block->read_len, block->block_len, block->binbuf); block->block_read = true; return true; }