/*
* 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");
}