/* * Append Data sent from File daemon * */ bool do_append_data(JCR *jcr) { int32_t n; int32_t file_index, stream, last_file_index; BSOCK *fd = jcr->file_bsock; bool ok = true; DEV_RECORD rec; char buf1[100], buf2[100]; DCR *dcr = jcr->dcr; DEVICE *dev; char ec[50]; if (!dcr) { Jmsg0(jcr, M_FATAL, 0, _("DCR is NULL!!!\n")); return false; } dev = dcr->dev; if (!dev) { Jmsg0(jcr, M_FATAL, 0, _("DEVICE is NULL!!!\n")); return false; } Dmsg1(100, "Start append data. res=%d\n", dev->num_reserved()); memset(&rec, 0, sizeof(rec)); if (!fd->set_buffer_size(dcr->device->max_network_buffer_size, BNET_SETBUF_WRITE)) { jcr->setJobStatus(JS_ErrorTerminated); Jmsg0(jcr, M_FATAL, 0, _("Unable to set network buffer size.\n")); return false; } if (!acquire_device_for_append(dcr)) { jcr->setJobStatus(JS_ErrorTerminated); return false; } jcr->setJobStatus(JS_Running); dir_send_job_status(jcr); if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } Dmsg1(50, "Begin append device=%s\n", dev->print_name()); begin_data_spool(dcr); begin_attribute_spool(jcr); Dmsg0(100, "Just after acquire_device_for_append\n"); if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } /* * Write Begin Session Record */ if (!write_session_label(dcr, SOS_LABEL)) { Jmsg1(jcr, M_FATAL, 0, _("Write session label failed. ERR=%s\n"), dev->bstrerror()); jcr->setJobStatus(JS_ErrorTerminated); ok = false; } if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } /* Tell File daemon to send data */ if (!fd->fsend(OK_data)) { berrno be; Jmsg1(jcr, M_FATAL, 0, _("Network send error to FD. ERR=%s\n"), be.bstrerror(fd->b_errno)); ok = false; } /* * Get Data from File daemon, write to device. To clarify what is * going on here. We expect: * - A stream header * - Multiple records of data * - EOD record * * The Stream header is just used to sychronize things, and * none of the stream header is written to tape. * The Multiple records of data, contain first the Attributes, * then after another stream header, the file data, then * after another stream header, the MD5 data if any. * * So we get the (stream header, data, EOD) three time for each * file. 1. for the Attributes, 2. for the file data if any, * and 3. for the MD5 if any. */ dcr->VolFirstIndex = dcr->VolLastIndex = 0; jcr->run_time = time(NULL); /* start counting time for rates */ for (last_file_index = 0; ok && !jcr->is_job_canceled(); ) { /* Read Stream header from the File daemon. * The stream header consists of the following: * file_index (sequential Bacula file index, base 1) * stream (Bacula number to distinguish parts of data) * info (Info for Storage daemon -- compressed, encrypted, ...) * info is not currently used, so is read, but ignored! */ if ((n=bget_msg(fd)) <= 0) { if (n == BNET_SIGNAL && fd->msglen == BNET_EOD) { break; /* end of data */ } Jmsg1(jcr, M_FATAL, 0, _("Error reading data header from FD. ERR=%s\n"), fd->bstrerror()); possible_incomplete_job(jcr, last_file_index); ok = false; break; } if (sscanf(fd->msg, "%ld %ld", &file_index, &stream) != 2) { Jmsg1(jcr, M_FATAL, 0, _("Malformed data header from FD: %s\n"), fd->msg); ok = false; possible_incomplete_job(jcr, last_file_index); break; } Dmsg2(890, "<filed: Header FilInx=%d stream=%d\n", file_index, stream); /* * We make sure the file_index is advancing sequentially. * An incomplete job can start the file_index at any number. * otherwise, it must start at 1. */ if (jcr->rerunning && file_index > 0 && last_file_index == 0) { goto fi_checked; } if (file_index > 0 && (file_index == last_file_index || file_index == last_file_index + 1)) { goto fi_checked; } Jmsg2(jcr, M_FATAL, 0, _("FI=%d from FD not positive or sequential=%d\n"), file_index, last_file_index); possible_incomplete_job(jcr, last_file_index); ok = false; break; fi_checked: if (file_index != last_file_index) { jcr->JobFiles = file_index; last_file_index = file_index; } /* Read data stream from the File daemon. * The data stream is just raw bytes */ while ((n=bget_msg(fd)) > 0 && !jcr->is_job_canceled()) { rec.VolSessionId = jcr->VolSessionId; rec.VolSessionTime = jcr->VolSessionTime; rec.FileIndex = file_index; rec.Stream = stream; rec.maskedStream = stream & STREAMMASK_TYPE; /* strip high bits */ rec.data_len = fd->msglen; rec.data = fd->msg; /* use message buffer */ Dmsg4(850, "before writ_rec FI=%d SessId=%d Strm=%s len=%d\n", rec.FileIndex, rec.VolSessionId, stream_to_ascii(buf1, rec.Stream,rec.FileIndex), rec.data_len); while (!write_record_to_block(dcr->block, &rec)) { Dmsg2(850, "!write_record_to_block data_len=%d rem=%d\n", rec.data_len, rec.remainder); if (!write_block_to_device(dcr)) { Dmsg2(90, "Got write_block_to_dev error on device %s. %s\n", dev->print_name(), dev->bstrerror()); ok = false; break; } } if (!ok) { Dmsg0(400, "Not OK\n"); break; } jcr->JobBytes += rec.data_len; /* increment bytes this job */ Dmsg4(850, "write_record FI=%s SessId=%d Strm=%s len=%d\n", FI_to_ascii(buf1, rec.FileIndex), rec.VolSessionId, stream_to_ascii(buf2, rec.Stream, rec.FileIndex), rec.data_len); send_attrs_to_dir(jcr, &rec); Dmsg0(650, "Enter bnet_get\n"); } Dmsg1(650, "End read loop with FD. Stat=%d\n", n); if (fd->is_error()) { if (!jcr->is_job_canceled()) { Dmsg1(350, "Network read error from FD. ERR=%s\n", fd->bstrerror()); Jmsg1(jcr, M_FATAL, 0, _("Network error reading from FD. ERR=%s\n"), fd->bstrerror()); possible_incomplete_job(jcr, last_file_index); } ok = false; break; } } /* Create Job status for end of session label */ jcr->setJobStatus(ok?JS_Terminated:JS_ErrorTerminated); if (ok) { /* Terminate connection with FD */ fd->fsend(OK_append); do_fd_commands(jcr); /* finish dialog with FD */ } else { fd->fsend("3999 Failed append\n"); } /* * Don't use time_t for job_elapsed as time_t can be 32 or 64 bits, * and the subsequent Jmsg() editing will break */ int32_t job_elapsed = time(NULL) - jcr->run_time; if (job_elapsed <= 0) { job_elapsed = 1; } Jmsg(dcr->jcr, M_INFO, 0, _("Job write elapsed time = %02d:%02d:%02d, Transfer rate = %s Bytes/second\n"), job_elapsed / 3600, job_elapsed % 3600 / 60, job_elapsed % 60, edit_uint64_with_suffix(jcr->JobBytes / job_elapsed, ec)); Dmsg1(200, "Write EOS label JobStatus=%c\n", jcr->JobStatus); /* * Check if we can still write. This may not be the case * if we are at the end of the tape or we got a fatal I/O error. */ if (ok || dev->can_write()) { if (!write_session_label(dcr, EOS_LABEL)) { /* Print only if ok and not cancelled to avoid spurious messages */ if (ok && !jcr->is_job_canceled()) { Jmsg1(jcr, M_FATAL, 0, _("Error writing end session label. ERR=%s\n"), dev->bstrerror()); possible_incomplete_job(jcr, last_file_index); } jcr->setJobStatus(JS_ErrorTerminated); ok = false; } if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); Dmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } Dmsg0(90, "back from write_end_session_label()\n"); /* Flush out final partial block of this session */ if (!write_block_to_device(dcr)) { /* Print only if ok and not cancelled to avoid spurious messages */ if (ok && !jcr->is_job_canceled()) { Jmsg2(jcr, M_FATAL, 0, _("Fatal append error on device %s: ERR=%s\n"), dev->print_name(), dev->bstrerror()); Dmsg0(100, _("Set ok=FALSE after write_block_to_device.\n")); possible_incomplete_job(jcr, last_file_index); } jcr->setJobStatus(JS_ErrorTerminated); ok = false; } } if (!ok && !jcr->is_JobStatus(JS_Incomplete)) { discard_data_spool(dcr); } else { /* Note: if commit is OK, the device will remain blocked */ commit_data_spool(dcr); } if (ok) { ok = dvd_close_job(dcr); /* do DVD cleanup if any */ } /* * Release the device -- and send final Vol info to DIR * and unlock it. */ release_device(dcr); if ((!ok || jcr->is_job_canceled()) && !jcr->is_JobStatus(JS_Incomplete)) { discard_attribute_spool(jcr); } else { commit_attribute_spool(jcr); } dir_send_job_status(jcr); /* update director */ Dmsg1(100, "return from do_append_data() ok=%d\n", ok); return ok; }
/* * NB! This routine locks the device, but if committing will * not unlock it. If not committing, it will be unlocked. */ static bool despool_data(DCR *dcr, bool commit) { DEVICE *rdev; DCR *rdcr; bool ok = true; DEV_BLOCK *block; JCR *jcr = dcr->jcr; int status; char ec1[50]; BSOCK *dir = jcr->dir_bsock; Dmsg0(100, "Despooling data\n"); if (jcr->dcr->job_spool_size == 0) { Jmsg(jcr, M_WARNING, 0, _("Despooling zero bytes. Your disk is probably FULL!\n")); } /* * Commit means that the job is done, so we commit, otherwise, we * are despooling because of user spool size max or some error * (e.g. filesystem full). */ if (commit) { Jmsg(jcr, M_INFO, 0, _("Committing spooled data to Volume \"%s\". Despooling %s bytes ...\n"), jcr->dcr->VolumeName, edit_uint64_with_commas(jcr->dcr->job_spool_size, ec1)); jcr->setJobStatus(JS_DataCommitting); } else { Jmsg(jcr, M_INFO, 0, _("Writing spooled data to Volume. Despooling %s bytes ...\n"), edit_uint64_with_commas(jcr->dcr->job_spool_size, ec1)); jcr->setJobStatus(JS_DataDespooling); } jcr->sendJobStatus(JS_DataDespooling); dcr->despool_wait = true; dcr->spooling = false; /* * We work with device blocked, but not locked so that other threads * e.g. reservations can lock the device structure. */ dcr->dblock(BST_DESPOOLING); dcr->despool_wait = false; dcr->despooling = true; /* * This is really quite kludgy and should be fixed some time. * We create a dev structure to read from the spool file * in rdev and rdcr. */ rdev = (DEVICE *)malloc(sizeof(DEVICE)); memset(rdev, 0, sizeof(DEVICE)); rdev->dev_name = get_memory(strlen(spool_name)+1); bstrncpy(rdev->dev_name, spool_name, sizeof_pool_memory(rdev->dev_name)); rdev->errmsg = get_pool_memory(PM_EMSG); *rdev->errmsg = 0; rdev->max_block_size = dcr->dev->max_block_size; rdev->min_block_size = dcr->dev->min_block_size; rdev->device = dcr->dev->device; rdcr = dcr->get_new_spooling_dcr(); setup_new_dcr_device(jcr, rdcr, rdev, NULL); rdcr->spool_fd = dcr->spool_fd; block = dcr->block; /* save block */ dcr->block = rdcr->block; /* make read and write block the same */ Dmsg1(800, "read/write block size = %d\n", block->buf_len); lseek(rdcr->spool_fd, 0, SEEK_SET); /* rewind */ #if defined(HAVE_POSIX_FADVISE) && defined(POSIX_FADV_WILLNEED) posix_fadvise(rdcr->spool_fd, 0, 0, POSIX_FADV_WILLNEED); #endif /* Add run time, to get current wait time */ int32_t despool_start = time(NULL) - jcr->run_time; set_new_file_parameters(dcr); while (ok) { if (job_canceled(jcr)) { ok = false; break; } status = read_block_from_spool_file(rdcr); if (status == RB_EOT) { break; } else if (status == RB_ERROR) { ok = false; break; } ok = dcr->write_block_to_device(); if (!ok) { Jmsg2(jcr, M_FATAL, 0, _("Fatal append error on device %s: ERR=%s\n"), dcr->dev->print_name(), dcr->dev->bstrerror()); Dmsg2(000, "Fatal append error on device %s: ERR=%s\n", dcr->dev->print_name(), dcr->dev->bstrerror()); /* Force in case Incomplete set */ jcr->forceJobStatus(JS_FatalError); } Dmsg3(800, "Write block ok=%d FI=%d LI=%d\n", ok, block->FirstIndex, block->LastIndex); } /* * If this Job is incomplete, we need to backup the FileIndex * to the last correctly saved file so that the JobMedia * LastIndex is correct. */ if (jcr->is_JobStatus(JS_Incomplete)) { dcr->VolLastIndex = dir->get_FileIndex(); Dmsg1(100, "======= Set FI=%ld\n", dir->get_FileIndex()); } if (!dcr->dir_create_jobmedia_record(false)) { Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"), dcr->getVolCatName(), jcr->Job); jcr->forceJobStatus(JS_FatalError); /* override any Incomplete */ } /* Set new file/block parameters for current dcr */ set_new_file_parameters(dcr); /* * Subtracting run_time give us elapsed time - wait_time since * we started despooling. Note, don't use time_t as it is 32 or 64 * bits depending on the OS and doesn't edit with %d */ int32_t despool_elapsed = time(NULL) - despool_start - jcr->run_time; if (despool_elapsed <= 0) { despool_elapsed = 1; } Jmsg(jcr, M_INFO, 0, _("Despooling elapsed time = %02d:%02d:%02d, Transfer rate = %s Bytes/second\n"), despool_elapsed / 3600, despool_elapsed % 3600 / 60, despool_elapsed % 60, edit_uint64_with_suffix(jcr->dcr->job_spool_size / despool_elapsed, ec1)); dcr->block = block; /* reset block */ lseek(rdcr->spool_fd, 0, SEEK_SET); /* rewind */ if (ftruncate(rdcr->spool_fd, 0) != 0) { berrno be; Jmsg(jcr, M_ERROR, 0, _("Ftruncate spool file failed: ERR=%s\n"), be.bstrerror()); /* Note, try continuing despite ftruncate problem */ } P(mutex); if (spool_stats.data_size < dcr->job_spool_size) { spool_stats.data_size = 0; } else { spool_stats.data_size -= dcr->job_spool_size; } V(mutex); P(dcr->dev->spool_mutex); dcr->dev->spool_size -= dcr->job_spool_size; dcr->job_spool_size = 0; /* zap size in input dcr */ V(dcr->dev->spool_mutex); free_memory(rdev->dev_name); free_pool_memory(rdev->errmsg); /* Be careful to NULL the jcr and free rdev after free_dcr() */ rdcr->jcr = NULL; rdcr->set_dev(NULL); free_dcr(rdcr); free(rdev); dcr->spooling = true; /* turn on spooling again */ dcr->despooling = false; /* * Note, if committing we leave the device blocked. It will be removed in * release_device(); */ if (!commit) { dcr->dev->dunblock(); } jcr->sendJobStatus(JS_Running); return ok; }
/* * Append Data sent from Client (FD/SD) * */ bool do_append_data(JCR *jcr) { int32_t n; int32_t file_index, stream, last_file_index; uint64_t stream_len; BSOCK *fd = jcr->file_bsock; bool ok = true; DEV_RECORD rec; char buf1[100], buf2[100]; DCR *dcr = jcr->dcr; DEVICE *dev; char ec[50]; POOLMEM *eblock = NULL; POOL_MEM errmsg(PM_EMSG); if (!dcr) { pm_strcpy(jcr->errmsg, _("DCR is NULL!!!\n")); Jmsg0(jcr, M_FATAL, 0, jcr->errmsg); return false; } dev = dcr->dev; if (!dev) { pm_strcpy(jcr->errmsg, _("DEVICE is NULL!!!\n")); Jmsg0(jcr, M_FATAL, 0, jcr->errmsg); return false; } Dmsg1(100, "Start append data. res=%d\n", dev->num_reserved()); memset(&rec, 0, sizeof(rec)); if (!fd->set_buffer_size(dcr->device->max_network_buffer_size, BNET_SETBUF_WRITE)) { jcr->setJobStatus(JS_ErrorTerminated); pm_strcpy(jcr->errmsg, _("Unable to set network buffer size.\n")); Jmsg0(jcr, M_FATAL, 0, jcr->errmsg); return false; } if (!acquire_device_for_append(dcr)) { jcr->setJobStatus(JS_ErrorTerminated); return false; } jcr->sendJobStatus(JS_Running); //ASSERT(dev->VolCatInfo.VolCatName[0]); if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } Dmsg1(50, "Begin append device=%s\n", dev->print_name()); begin_data_spool(dcr); begin_attribute_spool(jcr); Dmsg0(100, "Just after acquire_device_for_append\n"); //ASSERT(dev->VolCatInfo.VolCatName[0]); if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } /* * Write Begin Session Record */ if (!write_session_label(dcr, SOS_LABEL)) { Jmsg1(jcr, M_FATAL, 0, _("Write session label failed. ERR=%s\n"), dev->bstrerror()); jcr->setJobStatus(JS_ErrorTerminated); ok = false; } //ASSERT(dev->VolCatInfo.VolCatName[0]); if (dev->VolCatInfo.VolCatName[0] == 0) { Pmsg0(000, _("NULL Volume name. This shouldn't happen!!!\n")); } /* Tell File daemon to send data */ if (!fd->fsend(OK_data)) { berrno be; Jmsg1(jcr, M_FATAL, 0, _("Network send error to FD. ERR=%s\n"), be.bstrerror(fd->b_errno)); ok = false; } /* * Get Data from File daemon, write to device. To clarify what is * going on here. We expect: * - A stream header * - Multiple records of data * - EOD record * * The Stream header is just used to synchronize things, and * none of the stream header is written to tape. * The Multiple records of data, contain first the Attributes, * then after another stream header, the file data, then * after another stream header, the MD5 data if any. * * So we get the (stream header, data, EOD) three time for each * file. 1. for the Attributes, 2. for the file data if any, * and 3. for the MD5 if any. */ dcr->VolFirstIndex = dcr->VolLastIndex = 0; jcr->run_time = time(NULL); /* start counting time for rates */ GetMsg *qfd; qfd = New(GetMsg(jcr, fd, NULL, GETMSG_MAX_MSG_SIZE)); qfd->start_read_sock(); for (last_file_index = 0; ok && !jcr->is_job_canceled(); ) { /* Read Stream header from the File daemon. * The stream header consists of the following: * file_index (sequential Bacula file index, base 1) * stream (Bacula number to distinguish parts of data) * stream_len (Expected length of this stream. This * will be the size backed up if the file does not * grow during the backup. */ n = qfd->bget_msg(NULL); if (n <= 0) { if (n == BNET_SIGNAL && qfd->msglen == BNET_EOD) { Dmsg0(200, "Got EOD on reading header.\n"); break; /* end of data */ } Jmsg3(jcr, M_FATAL, 0, _("Error reading data header from FD. n=%d msglen=%d ERR=%s\n"), n, qfd->msglen, fd->bstrerror()); // ASX TODO the fd->bstrerror() can be related to the wrong error, I should Queue the error too possible_incomplete_job(jcr, last_file_index); ok = false; break; } if (sscanf(qfd->msg, "%ld %ld %lld", &file_index, &stream, &stream_len) != 3) { // TODO ASX already done in bufmsg, should reuse the values char buf[256]; Jmsg1(jcr, M_FATAL, 0, _("Malformed data header from FD: %s\n"), asciidump(qfd->msg, qfd->msglen, buf, sizeof(buf))); ok = false; possible_incomplete_job(jcr, last_file_index); break; } Dmsg3(890, "<filed: Header FilInx=%d stream=%d stream_len=%lld\n", file_index, stream, stream_len); /* * We make sure the file_index is advancing sequentially. * An incomplete job can start the file_index at any number. * otherwise, it must start at 1. */ if (jcr->rerunning && file_index > 0 && last_file_index == 0) { goto fi_checked; } Dmsg2(400, "file_index=%d last_file_index=%d\n", file_index, last_file_index); if (file_index > 0 && (file_index == last_file_index || file_index == last_file_index + 1)) { goto fi_checked; } Jmsg2(jcr, M_FATAL, 0, _("FI=%d from FD not positive or last_FI=%d\n"), file_index, last_file_index); possible_incomplete_job(jcr, last_file_index); ok = false; break; fi_checked: if (file_index != last_file_index) { jcr->JobFiles = file_index; last_file_index = file_index; } /* Read data stream from the File daemon. * The data stream is just raw bytes */ while ((n=qfd->bget_msg(NULL)) > 0 && !jcr->is_job_canceled()) { rec.VolSessionId = jcr->VolSessionId; rec.VolSessionTime = jcr->VolSessionTime; rec.FileIndex = file_index; rec.Stream = stream; rec.StreamLen = stream_len; rec.maskedStream = stream & STREAMMASK_TYPE; /* strip high bits */ rec.data_len = qfd->msglen; rec.data = qfd->msg; /* use message buffer */ Dmsg4(850, "before writ_rec FI=%d SessId=%d Strm=%s len=%d\n", rec.FileIndex, rec.VolSessionId, stream_to_ascii(buf1, rec.Stream,rec.FileIndex), rec.data_len); ok = dcr->write_record(&rec); if (!ok) { Dmsg2(90, "Got write_block_to_dev error on device %s. %s\n", dcr->dev->print_name(), dcr->dev->bstrerror()); break; } jcr->JobBytes += rec.data_len; /* increment bytes this job */ jcr->JobBytes += qfd->bmsg->jobbytes; // if the block as been downloaded, count it Dmsg4(850, "write_record FI=%s SessId=%d Strm=%s len=%d\n", FI_to_ascii(buf1, rec.FileIndex), rec.VolSessionId, stream_to_ascii(buf2, rec.Stream, rec.FileIndex), rec.data_len); send_attrs_to_dir(jcr, &rec); Dmsg0(650, "Enter bnet_get\n"); } Dmsg2(650, "End read loop with FD. JobFiles=%d Stat=%d\n", jcr->JobFiles, n); if (fd->is_error()) { if (!jcr->is_job_canceled()) { Dmsg1(350, "Network read error from FD. ERR=%s\n", fd->bstrerror()); Jmsg1(jcr, M_FATAL, 0, _("Network error reading from FD. ERR=%s\n"), fd->bstrerror()); possible_incomplete_job(jcr, last_file_index); } ok = false; break; } } qfd->wait_read_sock(); free_GetMsg(qfd); if (eblock != NULL) { free_pool_memory(eblock); } /* Create Job status for end of session label */ jcr->setJobStatus(ok?JS_Terminated:JS_ErrorTerminated); if (ok) { /* Terminate connection with Client */ fd->fsend(OK_append); do_client_commands(jcr); /* finish dialog with Client */ } else { fd->fsend("3999 Failed append\n"); } Dmsg1(200, "Write EOS label JobStatus=%c\n", jcr->JobStatus); /* * Check if we can still write. This may not be the case * if we are at the end of the tape or we got a fatal I/O error. */ if (ok || dev->can_write()) { if (!write_session_label(dcr, EOS_LABEL)) { /* Print only if ok and not cancelled to avoid spurious messages */ if (ok && !jcr->is_job_canceled()) { Jmsg1(jcr, M_FATAL, 0, _("Error writing end session label. ERR=%s\n"), dev->bstrerror()); possible_incomplete_job(jcr, last_file_index); } jcr->setJobStatus(JS_ErrorTerminated); ok = false; } /* Flush out final partial block of this session */ if (!dcr->write_final_block_to_device()) { /* Print only if ok and not cancelled to avoid spurious messages */ if (ok && !jcr->is_job_canceled()) { Jmsg2(jcr, M_FATAL, 0, _("Fatal append error on device %s: ERR=%s\n"), dev->print_name(), dev->bstrerror()); Dmsg0(100, _("Set ok=FALSE after write_final_block_to_device.\n")); possible_incomplete_job(jcr, last_file_index); } jcr->setJobStatus(JS_ErrorTerminated); ok = false; } } flush_jobmedia_queue(jcr); if (!ok && !jcr->is_JobStatus(JS_Incomplete)) { discard_data_spool(dcr); } else { /* Note: if commit is OK, the device will remain blocked */ commit_data_spool(dcr); } /* * Don't use time_t for job_elapsed as time_t can be 32 or 64 bits, * and the subsequent Jmsg() editing will break */ int32_t job_elapsed = time(NULL) - jcr->run_time; if (job_elapsed <= 0) { job_elapsed = 1; } Jmsg(dcr->jcr, M_INFO, 0, _("Elapsed time=%02d:%02d:%02d, Transfer rate=%s Bytes/second\n"), job_elapsed / 3600, job_elapsed % 3600 / 60, job_elapsed % 60, edit_uint64_with_suffix(jcr->JobBytes / job_elapsed, ec)); /* * Release the device -- and send final Vol info to DIR * and unlock it. */ release_device(dcr); if ((!ok || jcr->is_job_canceled()) && !jcr->is_JobStatus(JS_Incomplete)) { discard_attribute_spool(jcr); } else { commit_attribute_spool(jcr); } jcr->sendJobStatus(); /* update director */ Dmsg1(100, "return from do_append_data() ok=%d\n", ok); return ok; }
/* * Read Data and commit to new job. */ bool do_mac_run(JCR *jcr) { DEVICE *dev; char ec1[50]; const char *Type; bool ok = true; BSOCK *dir = jcr->dir_bsock; switch(jcr->getJobType()) { case JT_MIGRATE: Type = "Migration"; break; case JT_ARCHIVE: Type = "Archive"; break; case JT_COPY: Type = "Copy"; break; case JT_BACKUP: Type = "Virtual Backup"; break; default: Type = "Unknown"; break; } Dmsg0(20, "Start read data.\n"); if (jcr->NumReadVolumes == 0) { Jmsg(jcr, M_FATAL, 0, _("No Volume names found for %s.\n"), Type); goto bail_out; } /* * Check autoinflation/autodeflation settings. */ check_auto_xflation(jcr); /* * See if we perform both read and write or read only. */ if (jcr->remote_replicate) { BSOCK *sd; if (!jcr->read_dcr) { Jmsg(jcr, M_FATAL, 0, _("Read device not properly initialized.\n")); goto bail_out; } Dmsg1(100, "read_dcr=%p\n", jcr->read_dcr); Dmsg3(200, "Found %d volumes names for %s. First=%s\n", jcr->NumReadVolumes, Type, jcr->VolList->VolumeName); /* * Ready devices for reading. */ if (!acquire_device_for_read(jcr->read_dcr)) { ok = false; goto bail_out; } Dmsg2(200, "===== After acquire pos %u:%u\n", jcr->read_dcr->dev->file, jcr->read_dcr->dev->block_num); jcr->sendJobStatus(JS_Running); /* * Set network buffering. */ sd = jcr->store_bsock; if (!sd->set_buffer_size(me->max_network_buffer_size, BNET_SETBUF_WRITE)) { Jmsg(jcr, M_FATAL, 0, _("Cannot set buffer size SD->SD.\n")); ok = false; goto bail_out; } /* * Let the remote SD know we are about to start the replication. */ sd->fsend(start_replicate); Dmsg1(110, ">stored: %s", sd->msg); /* * Expect to receive back the Ticket number. */ if (bget_msg(sd) >= 0) { Dmsg1(110, "<stored: %s", sd->msg); if (sscanf(sd->msg, OK_start_replicate, &jcr->Ticket) != 1) { Jmsg(jcr, M_FATAL, 0, _("Bad response to start replicate: %s\n"), sd->msg); goto bail_out; } Dmsg1(110, "Got Ticket=%d\n", jcr->Ticket); } else { Jmsg(jcr, M_FATAL, 0, _("Bad response from stored to start replicate command\n")); goto bail_out; } /* * Let the remote SD know we are now really going to send the data. */ sd->fsend(replicate_data, jcr->Ticket); Dmsg1(110, ">stored: %s", sd->msg); /* * Expect to get response to the replicate data cmd from Storage daemon */ if (!response(jcr, sd, OK_data, "replicate data")) { ok = false; goto bail_out; } /* * Read all data and send it to remote SD. */ ok = read_records(jcr->read_dcr, clone_record_to_remote_sd, mount_next_read_volume); /* * Send the last EOD to close the last data transfer and a next EOD to * signal the remote we are done. */ if (!sd->signal(BNET_EOD) || !sd->signal(BNET_EOD)) { if (!jcr->is_job_canceled()) { Jmsg1(jcr, M_FATAL, 0, _("Network send error to SD. ERR=%s\n"), sd->bstrerror()); } goto bail_out; } /* * Expect to get response that the replicate data succeeded. */ if (!response(jcr, sd, OK_replicate, "replicate data")) { ok = false; goto bail_out; } /* * End replicate session. */ sd->fsend(end_replicate); Dmsg1(110, ">stored: %s", sd->msg); /* * Expect to get response to the end replicate cmd from Storage daemon */ if (!response(jcr, sd, OK_end_replicate, "end replicate")) { ok = false; goto bail_out; } /* Inform Storage daemon that we are done */ sd->signal(BNET_TERMINATE); } else { if (!jcr->read_dcr || !jcr->dcr) { Jmsg(jcr, M_FATAL, 0, _("Read and write devices not properly initialized.\n")); goto bail_out; } Dmsg2(100, "read_dcr=%p write_dcr=%p\n", jcr->read_dcr, jcr->dcr); Dmsg3(200, "Found %d volumes names for %s. First=%s\n", jcr->NumReadVolumes, Type, jcr->VolList->VolumeName); /* * Ready devices for reading and writing. */ if (!acquire_device_for_read(jcr->read_dcr) || !acquire_device_for_append(jcr->dcr)) { ok = false; goto bail_out; } Dmsg2(200, "===== After acquire pos %u:%u\n", jcr->dcr->dev->file, jcr->dcr->dev->block_num); jcr->sendJobStatus(JS_Running); if (!begin_data_spool(jcr->dcr) ) { ok = false; goto bail_out; } if (!begin_attribute_spool(jcr)) { ok = false; goto bail_out; } jcr->dcr->VolFirstIndex = jcr->dcr->VolLastIndex = 0; jcr->run_time = time(NULL); set_start_vol_position(jcr->dcr); jcr->JobFiles = 0; /* * Read all data and make a local clone of it. */ ok = read_records(jcr->read_dcr, clone_record_internally, mount_next_read_volume); } bail_out: if (!ok) { jcr->setJobStatus(JS_ErrorTerminated); } if (!jcr->remote_replicate && jcr->dcr) { /* * Don't use time_t for job_elapsed as time_t can be 32 or 64 bits, * and the subsequent Jmsg() editing will break */ int32_t job_elapsed; dev = jcr->dcr->dev; Dmsg1(100, "ok=%d\n", ok); if (ok || dev->can_write()) { /* * Flush out final partial block of this session */ if (!jcr->dcr->write_block_to_device()) { Jmsg2(jcr, M_FATAL, 0, _("Fatal append error on device %s: ERR=%s\n"), dev->print_name(), dev->bstrerror()); Dmsg0(100, _("Set ok=FALSE after write_block_to_device.\n")); ok = false; } Dmsg2(200, "Flush block to device pos %u:%u\n", dev->file, dev->block_num); } if (!ok) { discard_data_spool(jcr->dcr); } else { /* * Note: if commit is OK, the device will remain blocked */ commit_data_spool(jcr->dcr); } job_elapsed = time(NULL) - jcr->run_time; if (job_elapsed <= 0) { job_elapsed = 1; } Jmsg(jcr, M_INFO, 0, _("Elapsed time=%02d:%02d:%02d, Transfer rate=%s Bytes/second\n"), job_elapsed / 3600, job_elapsed % 3600 / 60, job_elapsed % 60, edit_uint64_with_suffix(jcr->JobBytes / job_elapsed, ec1)); /* * Release the device -- and send final Vol info to DIR */ release_device(jcr->dcr); if (!ok || job_canceled(jcr)) { discard_attribute_spool(jcr); } else { commit_attribute_spool(jcr); } } if (jcr->read_dcr) { if (!release_device(jcr->read_dcr)) { ok = false; } } jcr->sendJobStatus(); /* update director */ Dmsg0(30, "Done reading.\n"); jcr->end_time = time(NULL); dequeue_messages(jcr); /* send any queued messages */ if (ok) { jcr->setJobStatus(JS_Terminated); } generate_plugin_event(jcr, bsdEventJobEnd); dir->fsend(Job_end, jcr->Job, jcr->JobStatus, jcr->JobFiles, edit_uint64(jcr->JobBytes, ec1), jcr->JobErrors); Dmsg4(100, Job_end, jcr->Job, jcr->JobStatus, jcr->JobFiles, ec1); dir->signal(BNET_EOD); /* send EOD to Director daemon */ free_plugins(jcr); /* release instantiated plugins */ return false; /* Continue DIR session ? */ }
static void list_terminated_jobs(STATUS_PKT *sp) { int len; struct s_last_job *je; POOL_MEM msg(PM_MESSAGE); char level[10], dt[MAX_TIME_LENGTH], b1[30], b2[30]; if (!sp->api) { len = pm_strcpy(msg, _("\nTerminated Jobs:\n")); sendit(msg, len, sp); } if (last_jobs->size() == 0) { if (!sp->api) { len = pm_strcpy(msg, _("====\n")); sendit(msg, len, sp); } return; } lock_last_jobs_list(); if (!sp->api) { len = pm_strcpy(msg, _(" JobId Level Files Bytes Status Finished Name \n")); sendit(msg, len, sp); len = pm_strcpy(msg, _("======================================================================\n")); sendit(msg, len, sp); } foreach_dlist(je, last_jobs) { char *p; char JobName[MAX_NAME_LENGTH]; const char *termstat; bstrftime_nc(dt, sizeof(dt), je->end_time); switch (je->JobType) { case JT_ADMIN: case JT_RESTORE: bstrncpy(level, " ", sizeof(level)); break; default: bstrncpy(level, level_to_str(je->JobLevel), sizeof(level)); level[4] = 0; break; } switch (je->JobStatus) { case JS_Created: termstat = _("Created"); break; case JS_FatalError: case JS_ErrorTerminated: termstat = _("Error"); break; case JS_Differences: termstat = _("Diffs"); break; case JS_Canceled: termstat = _("Cancel"); break; case JS_Terminated: termstat = _("OK"); break; default: termstat = _("Other"); break; } bstrncpy(JobName, je->Job, sizeof(JobName)); /* * There are three periods after the Job name */ for (int i=0; i<3; i++) { if ((p=strrchr(JobName, '.')) != NULL) { *p = 0; } } if (sp->api) { len = Mmsg(msg, _("%6d\t%-6s\t%8s\t%10s\t%-7s\t%-8s\t%s\n"), je->JobId, level, edit_uint64_with_commas(je->JobFiles, b1), edit_uint64_with_suffix(je->JobBytes, b2), termstat, dt, JobName); } else { len = Mmsg(msg, _("%6d %-6s %8s %10s %-7s %-8s %s\n"), je->JobId, level, edit_uint64_with_commas(je->JobFiles, b1), edit_uint64_with_suffix(je->JobBytes, b2), termstat, dt, JobName); } sendit(msg, len, sp); }
/* * Release resources allocated during backup. */ void backup_cleanup(JCR *jcr, int TermCode) { char sdt[50], edt[50], schedt[50]; char ec1[30], ec2[30], ec3[30], ec4[30], ec5[30], compress[50]; char ec6[30], ec7[30], ec8[30], elapsed[50]; char term_code[100], fd_term_msg[100], sd_term_msg[100]; const char *term_msg; int msg_type = M_INFO; MEDIA_DBR mr; CLIENT_DBR cr; double kbps, compression; utime_t RunTime; if (jcr->get_JobLevel() == L_VIRTUAL_FULL) { vbackup_cleanup(jcr, TermCode); return; } Dmsg2(100, "Enter backup_cleanup %d %c\n", TermCode, TermCode); memset(&mr, 0, sizeof(mr)); memset(&cr, 0, sizeof(cr)); update_job_end(jcr, TermCode); if (!db_get_job_record(jcr, jcr->db, &jcr->jr)) { Jmsg(jcr, M_WARNING, 0, _("Error getting Job record for Job report: ERR=%s"), db_strerror(jcr->db)); set_jcr_job_status(jcr, JS_ErrorTerminated); } bstrncpy(cr.Name, jcr->client->name(), sizeof(cr.Name)); if (!db_get_client_record(jcr, jcr->db, &cr)) { Jmsg(jcr, M_WARNING, 0, _("Error getting Client record for Job report: ERR=%s"), db_strerror(jcr->db)); } bstrncpy(mr.VolumeName, jcr->VolumeName, sizeof(mr.VolumeName)); if (!db_get_media_record(jcr, jcr->db, &mr)) { Jmsg(jcr, M_WARNING, 0, _("Error getting Media record for Volume \"%s\": ERR=%s"), mr.VolumeName, db_strerror(jcr->db)); set_jcr_job_status(jcr, JS_ErrorTerminated); } update_bootstrap_file(jcr); switch (jcr->JobStatus) { case JS_Terminated: if (jcr->JobErrors || jcr->SDErrors) { term_msg = _("Backup OK -- with warnings"); } else { term_msg = _("Backup OK"); } break; case JS_Warnings: term_msg = _("Backup OK -- with warnings"); break; case JS_FatalError: case JS_ErrorTerminated: term_msg = _("*** Backup Error ***"); msg_type = M_ERROR; /* Generate error message */ if (jcr->store_bsock) { jcr->store_bsock->signal(BNET_TERMINATE); if (jcr->SD_msg_chan) { pthread_cancel(jcr->SD_msg_chan); } } break; case JS_Canceled: term_msg = _("Backup Canceled"); if (jcr->store_bsock) { jcr->store_bsock->signal(BNET_TERMINATE); if (jcr->SD_msg_chan) { pthread_cancel(jcr->SD_msg_chan); } } break; default: term_msg = term_code; sprintf(term_code, _("Inappropriate term code: %c\n"), jcr->JobStatus); break; } bstrftimes(schedt, sizeof(schedt), jcr->jr.SchedTime); bstrftimes(sdt, sizeof(sdt), jcr->jr.StartTime); bstrftimes(edt, sizeof(edt), jcr->jr.EndTime); RunTime = jcr->jr.EndTime - jcr->jr.StartTime; if (RunTime <= 0) { kbps = 0; } else { kbps = ((double)jcr->jr.JobBytes) / (1000.0 * (double)RunTime); } if (!db_get_job_volume_names(jcr, jcr->db, jcr->jr.JobId, &jcr->VolumeName)) { /* * Note, if the job has erred, most likely it did not write any * tape, so suppress this "error" message since in that case * it is normal. Or look at it the other way, only for a * normal exit should we complain about this error. */ if (jcr->JobStatus == JS_Terminated && jcr->jr.JobBytes) { Jmsg(jcr, M_ERROR, 0, "%s", db_strerror(jcr->db)); } jcr->VolumeName[0] = 0; /* none */ } if (jcr->ReadBytes == 0) { bstrncpy(compress, "None", sizeof(compress)); } else { compression = (double)100 - 100.0 * ((double)jcr->JobBytes / (double)jcr->ReadBytes); if (compression < 0.5) { bstrncpy(compress, "None", sizeof(compress)); } else { bsnprintf(compress, sizeof(compress), "%.1f %%", compression); } } jobstatus_to_ascii(jcr->FDJobStatus, fd_term_msg, sizeof(fd_term_msg)); jobstatus_to_ascii(jcr->SDJobStatus, sd_term_msg, sizeof(sd_term_msg)); // bmicrosleep(15, 0); /* for debugging SIGHUP */ Jmsg(jcr, msg_type, 0, _("%s %s %s (%s): %s\n" " Build OS: %s %s %s\n" " JobId: %d\n" " Job: %s\n" " Backup Level: %s%s\n" " Client: \"%s\" %s\n" " FileSet: \"%s\" %s\n" " Pool: \"%s\" (From %s)\n" " Catalog: \"%s\" (From %s)\n" " Storage: \"%s\" (From %s)\n" " Scheduled time: %s\n" " Start time: %s\n" " End time: %s\n" " Elapsed time: %s\n" " Priority: %d\n" " FD Files Written: %s\n" " SD Files Written: %s\n" " FD Bytes Written: %s (%sB)\n" " SD Bytes Written: %s (%sB)\n" " Rate: %.1f KB/s\n" " Software Compression: %s\n" " VSS: %s\n" " Encryption: %s\n" " Accurate: %s\n" " Volume name(s): %s\n" " Volume Session Id: %d\n" " Volume Session Time: %d\n" " Last Volume Bytes: %s (%sB)\n" " Non-fatal FD errors: %d\n" " SD Errors: %d\n" " FD termination status: %s\n" " SD termination status: %s\n" " Termination: %s\n\n"), BACULA, my_name, VERSION, LSMDATE, edt, HOST_OS, DISTNAME, DISTVER, jcr->jr.JobId, jcr->jr.Job, level_to_str(jcr->get_JobLevel()), jcr->since, jcr->client->name(), cr.Uname, jcr->fileset->name(), jcr->FSCreateTime, jcr->pool->name(), jcr->pool_source, jcr->catalog->name(), jcr->catalog_source, jcr->wstore->name(), jcr->wstore_source, schedt, sdt, edt, edit_utime(RunTime, elapsed, sizeof(elapsed)), jcr->JobPriority, edit_uint64_with_commas(jcr->jr.JobFiles, ec1), edit_uint64_with_commas(jcr->SDJobFiles, ec2), edit_uint64_with_commas(jcr->jr.JobBytes, ec3), edit_uint64_with_suffix(jcr->jr.JobBytes, ec4), edit_uint64_with_commas(jcr->SDJobBytes, ec5), edit_uint64_with_suffix(jcr->SDJobBytes, ec6), kbps, compress, jcr->VSS?_("yes"):_("no"), jcr->Encrypt?_("yes"):_("no"), jcr->accurate?_("yes"):_("no"), jcr->VolumeName, jcr->VolSessionId, jcr->VolSessionTime, edit_uint64_with_commas(mr.VolBytes, ec7), edit_uint64_with_suffix(mr.VolBytes, ec8), jcr->JobErrors, jcr->SDErrors, fd_term_msg, sd_term_msg, term_msg); Dmsg0(100, "Leave backup_cleanup()\n"); }