2 Bacula® - The Network Backup Solution
4 Copyright (C) 2001-2012 Free Software Foundation Europe e.V.
6 The main author of Bacula is Kern Sibbald, with contributions from
7 many others, a complete list can be found in the file AUTHORS.
8 This program is Free Software; you can redistribute it and/or
9 modify it under the terms of version three of the GNU Affero General Public
10 License as published by the Free Software Foundation and included
13 This program is distributed in the hope that it will be useful, but
14 WITHOUT ANY WARRANTY; without even the implied warranty of
15 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
16 General Public License for more details.
18 You should have received a copy of the GNU Affero General Public License
19 along with this program; if not, write to the Free Software
20 Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
23 Bacula® is a registered trademark of Kern Sibbald.
24 The licensor of Bacula is the Free Software Foundation Europe
25 (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
26 Switzerland, email:ftf@fsfeurope.org.
30 * block.c -- tape block handling functions
32 * Kern Sibbald, March MMI
33 * added BB02 format October MMII
41 #ifdef DEBUG_BLOCK_CHECKSUM
42 static const bool debug_block_checksum = true;
44 static const bool debug_block_checksum = false;
47 #ifdef NO_TAPE_WRITE_TEST
48 static const bool no_tape_write_test = true;
50 static const bool no_tape_write_test = false;
54 static bool terminate_writing_volume(DCR *dcr);
55 static bool do_new_file_bookkeeping(DCR *dcr);
56 static bool do_dvd_size_checks(DCR *dcr);
57 static void reread_last_block(DCR *dcr);
60 * Dump the block header, then walk through
61 * the block printing out the record headers.
63 void dump_block(DEV_BLOCK *b, const char *msg)
67 char Id[BLKHDR_ID_LENGTH+1];
68 uint32_t CheckSum, BlockCheckSum;
71 uint32_t VolSessionId, VolSessionTime, data_len;
75 char buf1[100], buf2[100];
77 unser_begin(b->buf, BLKHDR1_LENGTH);
78 unser_uint32(CheckSum);
79 unser_uint32(block_len);
80 unser_uint32(BlockNumber);
81 unser_bytes(Id, BLKHDR_ID_LENGTH);
82 ASSERT(unser_length(b->buf) == BLKHDR1_LENGTH);
83 Id[BLKHDR_ID_LENGTH] = 0;
85 unser_uint32(VolSessionId);
86 unser_uint32(VolSessionTime);
90 VolSessionId = VolSessionTime = 0;
95 if (block_len > 4000000) {
96 Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len);
100 BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
101 block_len-BLKHDR_CS_LENGTH);
102 Pmsg6(000, _("Dump block %s %x: size=%d BlkNum=%d\n"
103 " Hdrcksum=%x cksum=%x\n"),
104 msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
106 while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) {
107 unser_begin(p, WRITE_RECHDR_LENGTH);
108 if (rhl == RECHDR1_LENGTH) {
109 unser_uint32(VolSessionId);
110 unser_uint32(VolSessionTime);
112 unser_int32(FileIndex);
114 unser_uint32(data_len);
115 Pmsg6(000, _(" Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n"),
116 VolSessionId, VolSessionTime, FI_to_ascii(buf1, FileIndex),
117 stream_to_ascii(buf2, Stream, FileIndex), data_len, p);
123 * Create a new block structure.
124 * We pass device so that the block can inherit the
125 * min and max block sizes.
127 DEV_BLOCK *new_block(DEVICE *dev)
129 DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
131 memset(block, 0, sizeof(DEV_BLOCK));
133 /* If the user has specified a max_block_size, use it as the default */
134 if (dev->max_block_size == 0) {
135 block->buf_len = DEFAULT_BLOCK_SIZE;
137 block->buf_len = dev->max_block_size;
140 block->block_len = block->buf_len; /* default block size */
141 block->buf = get_memory(block->buf_len);
143 block->BlockVer = BLOCK_VER; /* default write version */
144 Dmsg1(650, "Returning new block=%x\n", block);
150 * Duplicate an existing block (eblock)
152 DEV_BLOCK *dup_block(DEV_BLOCK *eblock)
154 DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
155 int buf_len = sizeof_pool_memory(eblock->buf);
157 memcpy(block, eblock, sizeof(DEV_BLOCK));
158 block->buf = get_memory(buf_len);
159 memcpy(block->buf, eblock->buf, buf_len);
165 * Only the first block checksum error was reported.
166 * If there are more, report it now.
168 void print_block_read_errors(JCR *jcr, DEV_BLOCK *block)
170 if (block->read_errors > 1) {
171 Jmsg(jcr, M_ERROR, 0, _("%d block read errors not printed.\n"),
179 void free_block(DEV_BLOCK *block)
182 Dmsg1(999, "free_block buffer %x\n", block->buf);
183 free_memory(block->buf);
184 Dmsg1(999, "free_block block %x\n", block);
185 free_memory((POOLMEM *)block);
189 /* Empty the block -- for writing */
190 void empty_block(DEV_BLOCK *block)
192 block->binbuf = WRITE_BLKHDR_LENGTH;
193 block->bufp = block->buf + block->binbuf;
195 block->write_failed = false;
196 block->block_read = false;
197 block->FirstIndex = block->LastIndex = 0;
201 * Create block header just before write. The space
202 * in the buffer should have already been reserved by
205 static uint32_t ser_block_header(DEV_BLOCK *block, bool do_checksum)
208 uint32_t CheckSum = 0;
209 uint32_t block_len = block->binbuf;
211 Dmsg1(1390, "ser_block_header: block_len=%d\n", block_len);
212 ser_begin(block->buf, BLKHDR2_LENGTH);
213 ser_uint32(CheckSum);
214 ser_uint32(block_len);
215 ser_uint32(block->BlockNumber);
216 ser_bytes(WRITE_BLKHDR_ID, BLKHDR_ID_LENGTH);
217 if (BLOCK_VER >= 2) {
218 ser_uint32(block->VolSessionId);
219 ser_uint32(block->VolSessionTime);
222 /* Checksum whole block except for the checksum */
224 CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
225 block_len-BLKHDR_CS_LENGTH);
227 Dmsg1(1390, "ser_bloc_header: checksum=%x\n", CheckSum);
228 ser_begin(block->buf, BLKHDR2_LENGTH);
229 ser_uint32(CheckSum); /* now add checksum to block header */
234 * Unserialize the block header for reading block.
235 * This includes setting all the buffer pointers correctly.
237 * Returns: false on failure (not a block)
240 static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
243 char Id[BLKHDR_ID_LENGTH+1];
244 uint32_t CheckSum, BlockCheckSum;
247 uint32_t BlockNumber;
250 unser_begin(block->buf, BLKHDR_LENGTH);
251 unser_uint32(CheckSum);
252 unser_uint32(block_len);
253 unser_uint32(BlockNumber);
254 unser_bytes(Id, BLKHDR_ID_LENGTH);
255 ASSERT(unser_length(block->buf) == BLKHDR1_LENGTH);
257 Id[BLKHDR_ID_LENGTH] = 0;
259 bhl = BLKHDR1_LENGTH;
261 block->bufp = block->buf + bhl;
262 if (strncmp(Id, BLKHDR1_ID, BLKHDR_ID_LENGTH) != 0) {
263 dev->dev_errno = EIO;
264 Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
265 dev->file, dev->block_num, BLKHDR1_ID, Id);
266 if (block->read_errors == 0 || verbose >= 2) {
267 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
269 block->read_errors++;
272 } else if (Id[3] == '2') {
273 unser_uint32(block->VolSessionId);
274 unser_uint32(block->VolSessionTime);
275 bhl = BLKHDR2_LENGTH;
277 block->bufp = block->buf + bhl;
278 if (strncmp(Id, BLKHDR2_ID, BLKHDR_ID_LENGTH) != 0) {
279 dev->dev_errno = EIO;
280 Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
281 dev->file, dev->block_num, BLKHDR2_ID, Id);
282 if (block->read_errors == 0 || verbose >= 2) {
283 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
285 block->read_errors++;
289 dev->dev_errno = EIO;
290 Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
291 dev->file, dev->block_num, BLKHDR2_ID, Id);
292 Dmsg1(50, "%s", dev->errmsg);
293 if (block->read_errors == 0 || verbose >= 2) {
294 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
296 block->read_errors++;
297 unser_uint32(block->VolSessionId);
298 unser_uint32(block->VolSessionTime);
303 if (block_len > MAX_BLOCK_LENGTH) {
304 dev->dev_errno = EIO;
305 Mmsg3(dev->errmsg, _("Volume data error at %u:%u! Block length %u is insane (too large), probably due to a bad archive.\n"),
306 dev->file, dev->block_num, block_len);
307 if (block->read_errors == 0 || verbose >= 2) {
308 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
310 block->read_errors++;
314 Dmsg1(390, "unser_block_header block_len=%d\n", block_len);
315 /* Find end of block or end of buffer whichever is smaller */
316 if (block_len > block->read_len) {
317 block_end = block->read_len;
319 block_end = block_len;
321 block->binbuf = block_end - bhl;
322 block->block_len = block_len;
323 block->BlockNumber = BlockNumber;
324 Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
326 if (block_len <= block->read_len && dev->do_checksum()) {
327 BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
328 block_len-BLKHDR_CS_LENGTH);
329 if (BlockCheckSum != CheckSum) {
330 dev->dev_errno = EIO;
331 Mmsg6(dev->errmsg, _("Volume data error at %u:%u!\n"
332 "Block checksum mismatch in block=%u len=%d: calc=%x blk=%x\n"),
333 dev->file, dev->block_num, (unsigned)BlockNumber,
334 block_len, BlockCheckSum, CheckSum);
335 if (block->read_errors == 0 || verbose >= 2) {
336 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
337 dump_block(block, "with checksum error");
339 block->read_errors++;
349 * Write a block to the device, with locking and unlocking
351 * Returns: true on success
355 bool DCR::write_block_to_device()
361 Dmsg0(100, "Write to spool\n");
362 stat = write_block_to_spool_file(dcr);
366 if (!dcr->is_dev_locked()) { /* device already locked? */
367 /* note, do not change this to dcr->r_dlock */
368 dev->rLock(); /* no, lock it */
372 * If a new volume has been mounted since our last write
373 * Create a JobMedia record for the previous volume written,
374 * and set new parameters to write this volume
375 * The same applies for if we are in a new file.
377 if (dcr->NewVol || dcr->NewFile) {
378 if (job_canceled(jcr)) {
380 Dmsg0(100, "Canceled\n");
383 /* Create a jobmedia record for this job */
384 if (!dir_create_jobmedia_record(dcr)) {
385 dev->dev_errno = EIO;
386 Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
387 dcr->getVolCatName(), jcr->Job);
388 set_new_volume_parameters(dcr);
390 Dmsg0(100, "cannot create media record\n");
394 /* Note, setting a new volume also handles any pending new file */
395 set_new_volume_parameters(dcr);
397 set_new_file_parameters(dcr);
401 if (!dcr->write_block_to_dev()) {
402 if (job_canceled(jcr) || jcr->getJobType() == JT_SYSTEM) {
405 stat = fixup_device_block_write_error(dcr);
410 if (!dcr->is_dev_locked()) { /* did we lock dev above? */
411 /* note, do not change this to dcr->dunlock */
412 dev->Unlock(); /* unlock it now */
418 * Write a block to the device
420 * Returns: true on success or EOT
421 * false on hard error
423 bool DCR::write_block_to_dev()
426 uint32_t wlen; /* length to write */
427 int hit_max1, hit_max2;
432 if (no_tape_write_test) {
436 if (job_canceled(jcr)) {
440 ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
442 wlen = block->binbuf;
443 if (wlen <= WRITE_BLKHDR_LENGTH) { /* Does block have data in it? */
444 Dmsg0(100, "return write_block_to_dev no data to write\n");
448 /* dump_block(block, "before write"); */
449 if (dev->at_weot()) {
450 Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
451 dev->dev_errno = ENOSPC;
452 Jmsg1(jcr, M_FATAL, 0, _("Cannot write block. Device at EOM. dev=%s\n"), dev->print_name());
453 Dmsg1(100, "Attempt to write on read-only Volume. dev=%s\n", dev->print_name());
456 if (!dev->can_append()) {
457 dev->dev_errno = EIO;
458 Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume. dev=%s\n"), dev->print_name());
459 Dmsg1(100, "Attempt to write on read-only Volume. dev=%s\n", dev->print_name());
463 if (!dev->is_open()) {
464 Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on closed device=%s\n"), dev->print_name());
465 Dmsg1(100, "Attempt to write on closed device=%s\n", dev->print_name());
470 * Clear to the end of the buffer if it is not full,
471 * and on tape devices, apply min and fixed blocking.
473 if (wlen != block->buf_len) {
474 uint32_t blen; /* current buffer length */
476 Dmsg2(250, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
479 /* Adjust write size to min/max for tapes only */
480 if (dev->is_tape()) {
481 /* check for fixed block size */
482 if (dev->min_block_size == dev->max_block_size) {
483 wlen = block->buf_len; /* fixed block size already rounded */
484 /* Check for min block size */
485 } else if (wlen < dev->min_block_size) {
486 wlen = ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
487 /* Ensure size is rounded */
489 wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
493 memset(block->bufp, 0, wlen-blen); /* clear garbage */
497 checksum = ser_block_header(block, dev->do_checksum());
499 /* Limit maximum Volume size to value specified by user */
500 hit_max1 = (dev->max_volume_size > 0) &&
501 ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
502 hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
503 ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
504 if (hit_max1 || hit_max2) {
507 Dmsg0(100, "==== Output bytes Triggered medium max capacity.\n");
509 max_cap = dev->max_volume_size;
511 max_cap = dev->VolCatInfo.VolCatMaxBytes;
513 Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
514 edit_uint64_with_commas(max_cap, ed1), dev->print_name());
515 terminate_writing_volume(dcr);
516 reread_last_block(dcr); /* DEBUG */
517 dev->dev_errno = ENOSPC;
521 /* Limit maximum File size on volume to user specified value */
522 if ((dev->max_file_size > 0) &&
523 (dev->file_size+block->binbuf) >= dev->max_file_size) {
524 dev->file_size = 0; /* reset file size */
526 if (!dev->weof(1)) { /* write eof */
527 Dmsg0(50, "WEOF error in max file size.\n");
528 Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"),
530 terminate_writing_volume(dcr);
531 dev->dev_errno = ENOSPC;
534 if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
538 if (!do_new_file_bookkeeping(dcr)) {
539 /* Error message already sent */
544 if (!do_dvd_size_checks(dcr)) {
545 /* Error message already sent */
549 dev->VolCatInfo.VolCatWrites++;
550 Dmsg1(1300, "Write block of %u bytes\n", wlen);
551 #ifdef DEBUG_BLOCK_ZEROING
552 uint32_t *bp = (uint32_t *)block->buf;
553 if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
554 Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
559 * Do write here, make a somewhat feeble attempt to recover from
560 * I/O errors, or from the OS telling us it is busy.
566 if (retry > 0 && stat == -1 && errno == EBUSY) {
568 Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
569 retry, stat, errno, be.bstrerror());
570 bmicrosleep(5, 0); /* pause a bit if busy or lots of errors */
573 stat = dev->write(block->buf, (size_t)wlen);
575 } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
577 if (debug_block_checksum) {
578 uint32_t achecksum = ser_block_header(block, dev->do_checksum());
579 if (checksum != achecksum) {
580 Jmsg2(jcr, M_ERROR, 0, _("Block checksum changed during write: before=%ud after=%ud\n"),
581 checksum, achecksum);
582 dump_block(block, "with checksum error");
586 #ifdef DEBUG_BLOCK_ZEROING
587 if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
588 Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
592 if (stat != (ssize_t)wlen) {
593 /* Some devices simply report EIO when the volume is full.
594 * With a little more thought we may be able to check
595 * capacity and distinguish real errors and EOT
596 * conditions. In any case, we probably want to
597 * simulate an End of Medium.
602 if (dev->dev_errno == 0) {
603 dev->dev_errno = ENOSPC; /* out of space */
605 if (dev->dev_errno != ENOSPC) {
606 dev->VolCatInfo.VolCatErrors++;
607 Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
608 dev->file, dev->block_num, dev->print_name(), be.bstrerror());
611 dev->dev_errno = ENOSPC; /* out of space */
613 if (dev->dev_errno == ENOSPC) {
614 Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
615 dev->getVolCatName(),
616 dev->file, dev->block_num, dev->print_name(), wlen, stat);
618 if (debug_level >= 100) {
620 Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
621 dev->fd(), wlen, stat, dev->block_num, block->BlockNumber,
622 dev->dev_errno, be.bstrerror(dev->dev_errno));
625 ok = terminate_writing_volume(dcr);
626 if (!ok && !forge_on) {
630 reread_last_block(dcr);
635 /* We successfully wrote the block, now do housekeeping */
636 Dmsg2(1300, "VolCatBytes=%d newVolCatBytes=%d\n", (int)dev->VolCatInfo.VolCatBytes,
637 (int)(dev->VolCatInfo.VolCatBytes+wlen));
638 dev->VolCatInfo.VolCatBytes += wlen;
639 dev->VolCatInfo.VolCatBlocks++;
640 dev->EndBlock = dev->block_num;
641 dev->EndFile = dev->file;
642 dev->LastBlock = block->BlockNumber;
643 block->BlockNumber++;
645 /* Update dcr values */
646 if (dev->is_tape()) {
647 dcr->EndBlock = dev->EndBlock;
648 dcr->EndFile = dev->EndFile;
651 /* Save address of block just written */
652 uint64_t addr = dev->file_addr + wlen - 1;
653 dcr->EndBlock = (uint32_t)addr;
654 dcr->EndFile = (uint32_t)(addr >> 32);
655 dev->block_num = dcr->EndBlock;
656 dev->file = dcr->EndFile;
658 dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
659 if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
660 dcr->VolFirstIndex = block->FirstIndex;
662 if (block->LastIndex > 0) {
663 dcr->VolLastIndex = block->LastIndex;
665 dcr->WroteVol = true;
666 dev->file_addr += wlen; /* update file address */
667 dev->file_size += wlen;
668 dev->part_size += wlen;
670 Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
675 static void reread_last_block(DCR *dcr)
677 #define CHECK_LAST_BLOCK
678 #ifdef CHECK_LAST_BLOCK
680 DEVICE *dev = dcr->dev;
682 DEV_BLOCK *block = dcr->block;
684 * If the device is a tape and it supports backspace record,
685 * we backspace over one or two eof marks depending on
686 * how many we just wrote, then over the last record,
687 * then re-read it and verify that the block number is
690 if (dev->is_tape() && dev->has_cap(CAP_BSR)) {
691 /* Now back up over what we wrote and read the last block */
695 Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"),
696 be.bstrerror(dev->dev_errno));
698 if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
701 Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"),
702 be.bstrerror(dev->dev_errno));
704 /* Backspace over record */
705 if (ok && !dev->bsr(1)) {
708 Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"),
709 be.bstrerror(dev->dev_errno));
711 * On FreeBSD systems, if the user got here, it is likely that his/her
712 * tape drive is "frozen". The correct thing to do is a
713 * rewind(), but if we do that, higher levels in cleaning up, will
714 * most likely write the EOS record over the beginning of the
715 * tape. The rewind *is* done later in mount.c when another
716 * tape is requested. Note, the clrerror() call in bsr()
717 * calls ioctl(MTCERRSTAT), which *should* fix the problem.
721 DEV_BLOCK *lblock = new_block(dev);
722 /* Note, this can destroy dev->errmsg */
724 if (!dcr->read_block_from_dev(NO_BLOCK_NUMBER_CHECK)) {
725 Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"),
729 * If we wrote block and the block numbers don't agree
730 * we have a possible problem.
732 if (lblock->BlockNumber != dev->LastBlock) {
733 if (dev->LastBlock > (lblock->BlockNumber + 1)) {
734 Jmsg(jcr, M_FATAL, 0, _(
735 "Re-read of last block: block numbers differ by more than one.\n"
736 "Probable tape misconfiguration and data loss. Read block=%u Want block=%u.\n"),
737 lblock->BlockNumber, dev->LastBlock);
739 Jmsg(jcr, M_ERROR, 0, _(
740 "Re-read of last block OK, but block numbers differ. Read block=%u Want block=%u.\n"),
741 lblock->BlockNumber, dev->LastBlock);
744 Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
755 * If this routine is called, we do our bookkeeping and
756 * then assure that the volume will not be written any
759 static bool terminate_writing_volume(DCR *dcr)
761 DEVICE *dev = dcr->dev;
764 /* Create a JobMedia record to indicated end of tape */
765 dev->VolCatInfo.VolCatFiles = dev->file;
766 if (!dir_create_jobmedia_record(dcr)) {
767 Dmsg0(50, "Error from create JobMedia\n");
768 dev->dev_errno = EIO;
769 Mmsg2(dev->errmsg, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
770 dcr->getVolCatName(), dcr->jcr->Job);
771 Jmsg(dcr->jcr, M_FATAL, 0, "%s", dev->errmsg);
774 dcr->block->write_failed = true;
775 if (!dev->weof(1)) { /* end the tape */
776 dev->VolCatInfo.VolCatErrors++;
777 Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
780 Dmsg0(50, "Error writing final EOF to volume.\n");
783 ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
785 bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
786 dev->VolCatInfo.VolCatFiles = dev->file; /* set number of files */
789 if (!dvd_write_part(dcr)) { /* write last part */
790 dev->VolCatInfo.VolCatErrors++;
791 Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
792 "This Volume may not be readable.\n%s"),
795 Dmsg0(100, "dvd_write_part error.\n");
797 dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
800 if (!dir_update_volume_info(dcr, false, true)) {
801 Mmsg(dev->errmsg, _("Error sending Volume info to Director.\n"));
803 Dmsg0(50, "Error updating volume info.\n");
805 Dmsg1(50, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
808 * Walk through all attached dcrs setting flag to call
809 * set_new_file_parameters() when that dcr is next used.
812 foreach_dlist(mdcr, dev->attached_dcrs) {
813 if (mdcr->jcr->JobId == 0) {
816 mdcr->NewFile = true; /* set reminder to do set_new_file_params */
818 /* Set new file/block parameters for current dcr */
819 set_new_file_parameters(dcr);
821 if (ok && dev->has_cap(CAP_TWOEOF) && !dev->weof(1)) { /* end the tape */
822 dev->VolCatInfo.VolCatErrors++;
823 /* This may not be fatal since we already wrote an EOF */
824 Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
825 Dmsg0(50, "Writing second EOF failed.\n");
828 dev->set_ateot(); /* no more writing this tape */
829 Dmsg1(50, "*** Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
834 * Do bookkeeping when a new file is created on a Volume. This is
835 * also done for disk files to generate the jobmedia records for
838 static bool do_new_file_bookkeeping(DCR *dcr)
840 DEVICE *dev = dcr->dev;
843 /* Create a JobMedia record so restore can seek */
844 if (!dir_create_jobmedia_record(dcr)) {
845 Dmsg0(50, "Error from create_job_media.\n");
846 dev->dev_errno = EIO;
847 Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
848 dcr->getVolCatName(), jcr->Job);
849 terminate_writing_volume(dcr);
850 dev->dev_errno = EIO;
853 dev->VolCatInfo.VolCatFiles = dev->file;
854 if (!dir_update_volume_info(dcr, false, false)) {
855 Dmsg0(50, "Error from update_vol_info.\n");
856 terminate_writing_volume(dcr);
857 dev->dev_errno = EIO;
860 Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
863 * Walk through all attached dcrs setting flag to call
864 * set_new_file_parameters() when that dcr is next used.
867 foreach_dlist(mdcr, dev->attached_dcrs) {
868 if (mdcr->jcr->JobId == 0) {
871 mdcr->NewFile = true; /* set reminder to do set_new_file_params */
873 /* Set new file/block parameters for current dcr */
874 set_new_file_parameters(dcr);
879 * Do all checks for DVD sizes during writing.
881 static bool do_dvd_size_checks(DCR *dcr)
883 DEVICE *dev = dcr->dev;
885 DEV_BLOCK *block = dcr->block;
887 /* Don't go further if the device is not a dvd */
888 if (!dev->is_dvd()) {
892 /* Limit maximum part size to value specified by user
894 if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
895 if (dev->part < dev->num_dvd_parts) {
896 Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
897 " is less than the total number of parts (%d/%d, device=%s)\n"),
898 dev->part, dev->num_dvd_parts, dev->print_name());
899 dev->dev_errno = EIO;
903 if (dvd_open_next_part(dcr) < 0) {
904 Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
905 dev->print_name(), dev->bstrerror());
906 dev->dev_errno = EIO;
910 dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
912 if (!dir_update_volume_info(dcr, false, false)) {
913 Dmsg0(190, "Error from update_vol_info.\n");
914 dev->dev_errno = EIO;
919 dev->update_freespace();
921 if (!dev->is_freespace_ok()) { /* Error while getting free space */
922 char ed1[50], ed2[50];
923 Dmsg1(100, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
924 Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
925 "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
926 dev->getVolCatName(),
927 dev->file, dev->block_num, dev->print_name(),
928 edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
929 dev->free_space_errno, dev->errmsg);
930 dev->dev_errno = dev->free_space_errno;
934 if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
935 char ed1[50], ed2[50];
936 Dmsg0(100, "==== Just enough free space on the device to write the current part...\n");
937 Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
938 "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
939 dev->getVolCatName(),
940 dev->file, dev->block_num, dev->print_name(),
941 edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
942 dev->free_space_errno);
943 terminate_writing_volume(dcr);
944 dev->dev_errno = ENOSPC;
952 * Read block with locking
955 bool DCR::read_block_from_device(bool check_block_numbers)
959 Dmsg0(250, "Enter read_block_from_device\n");
961 ok = read_block_from_dev(check_block_numbers);
963 Dmsg0(250, "Leave read_block_from_device\n");
968 * Read the next block into the block structure and unserialize
969 * the block header. For a file, the block may be partially
970 * or completely in the current buffer.
972 bool DCR::read_block_from_dev(bool check_block_numbers)
979 if (job_canceled(jcr)) {
980 Mmsg(dev->errmsg, _("Job failed or canceled.\n"));
986 Mmsg(dev->errmsg, _("Attempt to read past end of tape or file.\n"));
991 Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
994 if (!dev->is_open()) {
995 Mmsg4(dev->errmsg, _("Attempt to read closed device: fd=%d at file:blk %u:%u on device %s\n"),
996 dev->fd(), dev->file, dev->block_num, dev->print_name());
997 Jmsg(dcr->jcr, M_WARNING, 0, "%s", dev->errmsg);
1004 dev->dev_errno = EIO;
1005 Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
1007 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1008 block->read_len = 0;
1012 /* Check for DVD part file end */
1013 if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
1014 dev->part <= dev->num_dvd_parts) {
1015 Dmsg0(400, "Call dvd_open_next_part\n");
1016 if (dvd_open_next_part(dcr) < 0) {
1017 Mmsg3(dev->errmsg, _("Unable to open device part=%d %s: ERR=%s\n"),
1018 dev->part, dev->print_name(), dev->bstrerror());
1019 Jmsg(dcr->jcr, M_FATAL, 0, "%s", dev->errmsg);
1020 dev->dev_errno = EIO;
1029 if ((retry > 0 && stat == -1 && errno == EBUSY)) {
1031 Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
1032 retry, stat, errno, be.bstrerror());
1033 bmicrosleep(10, 0); /* pause a bit if busy or lots of errors */
1036 stat = dev->read(block->buf, (size_t)block->buf_len);
1038 } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
1042 Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
1043 block->read_len = 0;
1044 Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
1045 dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
1046 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1047 if (dev->at_eof()) { /* EOF just seen? */
1048 dev->set_eot(); /* yes, error => EOT */
1052 Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
1053 dev->file, dev->block_num);
1054 if (stat == 0) { /* Got EOF ! */
1056 block->read_len = 0;
1057 Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1058 dev->file, dev->block_num, dev->print_name());
1059 if (dev->at_eof()) { /* EOF already read? */
1060 dev->set_eot(); /* yes, 2 EOFs => EOT */
1064 return false; /* return eof */
1067 /* Continue here for successful read */
1069 block->read_len = stat; /* save length read */
1070 if (block->read_len == 80 &&
1071 (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
1072 dcr->device->label_type != B_BACULA_LABEL)) {
1073 /* ***FIXME*** should check label */
1074 Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
1076 goto reread; /* skip ANSI/IBM label */
1079 if (block->read_len < BLKHDR2_LENGTH) {
1080 dev->dev_errno = EIO;
1081 Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1082 dev->file, dev->block_num, block->read_len, dev->print_name());
1083 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1084 dev->set_short_block();
1085 block->read_len = block->binbuf = 0;
1086 Dmsg2(200, "set block=%p binbuf=%d\n", block, block->binbuf);
1087 return false; /* return error */
1090 // BlockNumber = block->BlockNumber + 1;
1091 if (!unser_block_header(jcr, dev, block)) {
1093 dev->file_addr += block->read_len;
1094 dev->file_size += block->read_len;
1101 * If the block is bigger than the buffer, we reposition for
1102 * re-reading the block, allocate a buffer of the correct size,
1105 if (block->block_len > block->buf_len) {
1106 dev->dev_errno = EIO;
1107 Mmsg2(dev->errmsg, _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1108 block->block_len, block->buf_len);
1109 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1110 Pmsg1(000, "%s", dev->errmsg);
1111 /* Attempt to reposition to re-read the block */
1112 if (dev->is_tape()) {
1113 Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1115 Mmsg(dev->errmsg, "%s", dev->bstrerror());
1116 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1117 block->read_len = 0;
1121 Dmsg0(250, "Seek to beginning of block for reread.\n");
1122 boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1123 pos -= block->read_len;
1124 dev->lseek(dcr, pos, SEEK_SET);
1125 dev->file_addr = pos;
1127 Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1128 Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1129 Pmsg1(000, "%s", dev->errmsg);
1130 /* Set new block length */
1131 dev->max_block_size = block->block_len;
1132 block->buf_len = block->block_len;
1133 free_memory(block->buf);
1134 block->buf = get_memory(block->buf_len);
1137 goto reread; /* re-read block with correct block size */
1140 if (block->block_len > block->read_len) {
1141 dev->dev_errno = EIO;
1142 Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1143 dev->file, dev->block_num, block->read_len, dev->print_name());
1144 Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1145 dev->set_short_block();
1146 block->read_len = block->binbuf = 0;
1147 return false; /* return error */
1150 dev->clear_short_block();
1152 dev->VolCatInfo.VolCatReads++;
1153 dev->VolCatInfo.VolCatRBytes += block->read_len;
1155 dev->EndBlock = dev->block_num;
1156 dev->EndFile = dev->file;
1159 /* Update dcr values */
1160 if (dev->is_tape()) {
1161 dcr->EndBlock = dev->EndBlock;
1162 dcr->EndFile = dev->EndFile;
1164 /* We need to take care about a short block in EndBlock/File
1167 uint32_t len = MIN(block->read_len, block->block_len);
1168 uint64_t addr = dev->file_addr + len - 1;
1169 dcr->EndBlock = (uint32_t)addr;
1170 dcr->EndFile = (uint32_t)(addr >> 32);
1171 dev->block_num = dev->EndBlock = dcr->EndBlock;
1172 dev->file = dev->EndFile = dcr->EndFile;
1174 dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
1175 dev->file_addr += block->read_len;
1176 dev->file_size += block->read_len;
1179 * If we read a short block on disk,
1180 * seek to beginning of next block. This saves us
1181 * from shuffling blocks around in the buffer. Take a
1182 * look at this from an efficiency stand point later, but
1183 * it should only happen once at the end of each job.
1185 * I've been lseek()ing negative relative to SEEK_CUR for 30
1186 * years now. However, it seems that with the new off_t definition,
1187 * it is not possible to seek negative amounts, so we use two
1188 * lseek(). One to get the position, then the second to do an
1189 * absolute positioning -- so much for efficiency. KES Sep 02.
1191 Dmsg0(250, "At end of read block\n");
1192 if (block->read_len > block->block_len && !dev->is_tape()) {
1194 boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1195 Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1196 pos -= (block->read_len - block->block_len);
1197 dev->lseek(dcr, pos, SEEK_SET);
1198 Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n",
1199 edit_int64(pos, ed1), block->block_len,
1201 dev->file_addr = pos;
1202 dev->file_size = pos;
1204 Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1205 block->read_len, block->block_len);
1206 block->block_read = true;