/*
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);
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;
}
*/
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 */
* 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;
}
/* 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;
}
/*
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) {
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) {
* : 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->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);
* 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.
}
}
- 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) &&
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);
} 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"));
}
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) {
dev->VolCatInfo.VolCatBlocks++;
dev->EndBlock = dev->block_num;
dev->EndFile = dev->file;
+ dev->LastBlock = block->BlockNumber;
block->BlockNumber++;
/* Update dcr values */
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 {
* 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"));
}
#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;
/* 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 */
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);
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
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;
}
/* 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;
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;
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);
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);
* 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);
+ ok = read_block_from_dev(check_block_numbers);
dev->dunlock();
Dmsg0(250, "Leave read_block_from_device\n");
return ok;
* 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;
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;
}
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;
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;
}
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;