/*
* 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;
}
/*
* Read a block from the spool file
*
* Returns RB_OK on success
* RB_EOT when file done
* RB_ERROR on error
*/
static int read_block_from_spool_file(DCR *dcr)
{
uint32_t rlen;
ssize_t status;
spool_hdr hdr;
DEV_BLOCK *block = dcr->block;
JCR *jcr = dcr->jcr;
rlen = sizeof(hdr);
status = read(dcr->spool_fd, (char *)&hdr, (size_t)rlen);
if (status == 0) {
Dmsg0(100, "EOT on spool read.\n");
return RB_EOT;
} else if (status != (ssize_t)rlen) {
if (status == -1) {
berrno be;
Jmsg(dcr->jcr, M_FATAL, 0, _("Spool header read error. ERR=%s\n"), be.bstrerror());
} else {
Pmsg2(000, _("Spool read error. Wanted %u bytes, got %d\n"), rlen, status);
Jmsg2(jcr, M_FATAL, 0, _("Spool header read error. Wanted %u bytes, got %d\n"), rlen, status);
}
jcr->forceJobStatus(JS_FatalError); /* override any Incomplete */
return RB_ERROR;
}
rlen = hdr.len;
if (rlen > block->buf_len) {
Pmsg2(000, _("Spool block too big. Max %u bytes, got %u\n"), block->buf_len, rlen);
Jmsg2(jcr, M_FATAL, 0, _("Spool block too big. Max %u bytes, got %u\n"), block->buf_len, rlen);
jcr->forceJobStatus(JS_FatalError); /* override any Incomplete */
return RB_ERROR;
}
status = read(dcr->spool_fd, (char *)block->buf, (size_t)rlen);
if (status != (ssize_t)rlen) {
Pmsg2(000, _("Spool data read error. Wanted %u bytes, got %d\n"), rlen, status);
Jmsg2(dcr->jcr, M_FATAL, 0, _("Spool data read error. Wanted %u bytes, got %d\n"), rlen, status);
jcr->forceJobStatus(JS_FatalError); /* override any Incomplete */
return RB_ERROR;
}
/* Setup write pointers */
block->binbuf = rlen;
block->bufp = block->buf + block->binbuf;
block->FirstIndex = hdr.FirstIndex;
block->LastIndex = hdr.LastIndex;
block->VolSessionId = dcr->jcr->VolSessionId;
block->VolSessionTime = dcr->jcr->VolSessionTime;
Dmsg2(800, "Read block FI=%d LI=%d\n", block->FirstIndex, block->LastIndex);
return RB_OK;
}
/*
* Called here before the job is run to do the job
* specific setup.
*/
bool do_verify_init(JCR *jcr)
{
int JobLevel;
if (!allow_duplicate_job(jcr)) {
return false;
}
JobLevel = jcr->getJobLevel();
switch (JobLevel) {
case L_VERIFY_INIT:
case L_VERIFY_CATALOG:
case L_VERIFY_DISK_TO_CATALOG:
free_rstorage(jcr);
free_wstorage(jcr);
break;
case L_VERIFY_VOLUME_TO_CATALOG:
free_wstorage(jcr);
break;
case L_VERIFY_DATA:
break;
default:
Jmsg2(jcr, M_FATAL, 0, _("Unimplemented Verify level %d(%c)\n"), JobLevel, JobLevel);
return false;
}
return true;
}
static bool makedir(JCR *jcr, char *path, mode_t mode, int *created)
{
struct stat statp;
if (mkdir(path, mode) != 0) {
berrno be;
*created = false;
if (lstat(path, &statp) != 0) {
Jmsg2(jcr, M_ERROR, 0, _("Cannot create directory %s: ERR=%s\n"),
path, be.bstrerror());
return false;
} else if (!S_ISDIR(statp.st_mode)) {
Jmsg1(jcr, M_ERROR, 0, _("%s exists but is not a directory.\n"), path);
return false;
}
return true; /* directory exists */
}
if (S_ISLNK(statp.st_mode)) {
/*
* Note, we created a directory, not a link, so if we find a
* link, there is a security problem here.
*/
Jmsg1(jcr, M_FATAL, 0, _("Security problem!! We created directory %s, but it is a link.\n"),
path);
return false;
}
if (jcr->keep_path_list) {
/* When replace=NEVER, we keep track of all directories newly created */
path_list_add(jcr, strlen(path), path);
}
*created = true;
return true;
}
bool dvd_close_job(DCR *dcr)
{
DEVICE *dev = dcr->dev;
JCR *jcr = dcr->jcr;
bool ok = true;
/*
* If the device is a dvd and WritePartAfterJob
* is set to yes, open the next part, so, in case of a device
* that requires mount, it will be written to the device.
*/
if (dev->is_dvd() && jcr->write_part_after_job && (dev->part_size > 0)) {
Dmsg1(400, "Writing last part=%d write_partafter_job is set.\n",
dev->part);
if (dev->part < dev->num_dvd_parts+1) {
Jmsg3(jcr, M_FATAL, 0, _("Error writing. Current part less than total number of parts (%d/%d, device=%s)\n"),
dev->part, dev->num_dvd_parts, dev->print_name());
dev->dev_errno = EIO;
ok = false;
}
if (ok && !dvd_write_part(dcr)) {
Jmsg2(jcr, M_FATAL, 0, _("Unable to write last on %s: ERR=%s\n"),
dev->print_name(), dev->bstrerror());
dev->dev_errno = EIO;
ok = false;
}
}
return ok;
}
/*
* Restore the owner and permissions (mode) of a Directory.
* See attribs.c for the equivalent for files.
*/
static void set_own_mod(ATTR *attr, char *path, uid_t owner, gid_t group, mode_t mode)
{
if (lchown(path, owner, group) != 0 && attr->uid == 0
#ifdef AFS
&& errno != EPERM
#endif
) {
berrno be;
Jmsg2(attr->jcr, M_WARNING, 0, _("Cannot change owner and/or group of %s: ERR=%s\n"),
path, be.bstrerror());
}
if (lchmod(path, mode) != 0 && attr->uid == 0) {
berrno be;
Jmsg2(attr->jcr, M_WARNING, 0, _("Cannot change permissions of %s: ERR=%s\n"),
path, be.bstrerror());
}
}
/*
* After receiving a connection (in dircmd.c) if it is
* from the Storage daemon, this routine is called.
*/
void *handle_stored_connection(BSOCK *sd, char *job_name)
{
JCR *jcr;
/*
* With the following bmicrosleep on, running the
* SD under the debugger fails.
*/
// bmicrosleep(0, 50000); /* wait 50 millisecs */
if (!(jcr = get_jcr_by_full_name(job_name))) {
Jmsg1(NULL, M_FATAL, 0, _("SD connect failed: Job name not found: %s\n"), job_name);
Dmsg1(3, "**** Job \"%s\" not found.\n", job_name);
sd->close();
delete sd;
return NULL;
}
Dmsg1(50, "Found Job %s\n", job_name);
if (jcr->authenticated) {
Jmsg2(jcr, M_FATAL, 0, _("Hey!!!! JobId %u Job %s already authenticated.\n"),
(uint32_t)jcr->JobId, jcr->Job);
Dmsg2(50, "Hey!!!! JobId %u Job %s already authenticated.\n",
(uint32_t)jcr->JobId, jcr->Job);
sd->close();
delete sd;
free_jcr(jcr);
return NULL;
}
jcr->store_bsock = sd;
jcr->store_bsock->set_jcr(jcr);
/*
* Authenticate the Storage daemon
*/
if (jcr->authenticated || !authenticate_storagedaemon(jcr)) {
Dmsg1(50, "Authentication failed Job %s\n", jcr->Job);
Jmsg(jcr, M_FATAL, 0, _("Unable to authenticate Storage daemon\n"));
} else {
jcr->authenticated = true;
Dmsg2(50, "OK Authentication jid=%u Job %s\n", (uint32_t)jcr->JobId, jcr->Job);
}
if (!jcr->authenticated) {
jcr->setJobStatus(JS_ErrorTerminated);
}
pthread_cond_signal(&jcr->job_start_wait); /* wake waiting job */
free_jcr(jcr);
return NULL;
}
/*
* After receiving a connection (in dircmd.c) if it is
* from the File daemon, this routine is called.
*/
void handle_filed_connection(BSOCK *fd, char *job_name, int fd_version,
int sd_version)
{
JCR *jcr;
if (!(jcr=get_jcr_by_full_name(job_name))) {
Jmsg1(NULL, M_FATAL, 0, _("FD connect failed: Job name not found: %s\n"), job_name);
Dmsg1(3, "**** Job \"%s\" not found.\n", job_name);
fd->destroy();
return;
}
Dmsg1(100, "Found Filed Job %s\n", job_name);
if (jcr->authenticated) {
Jmsg2(jcr, M_FATAL, 0, _("Hey!!!! JobId %u Job %s already authenticated.\n"),
(uint32_t)jcr->JobId, jcr->Job);
Dmsg2(050, "Hey!!!! JobId %u Job %s already authenticated.\n",
(uint32_t)jcr->JobId, jcr->Job);
fd->destroy();
free_jcr(jcr);
return;
}
jcr->file_bsock = fd;
jcr->file_bsock->set_jcr(jcr);
jcr->FDVersion = fd_version;
jcr->SDVersion = sd_version;
Dmsg2(050, "fd_version=%d sd_version=%d\n", fd_version, sd_version);
/*
* Authenticate the File daemon
*/
if (jcr->authenticated || !authenticate_filed(jcr)) {
Dmsg1(50, "Authentication failed Job %s\n", jcr->Job);
Jmsg(jcr, M_FATAL, 0, _("Unable to authenticate File daemon\n"));
} else {
jcr->authenticated = true;
Dmsg2(050, "OK Authentication jid=%u Job %s\n", (uint32_t)jcr->JobId, jcr->Job);
}
if (!jcr->authenticated) {
jcr->setJobStatus(JS_ErrorTerminated);
}
Dmsg3(050, "=== Auth OK, unblock Job %s jid=%d sd_ver=%d\n", job_name, jcr->JobId, sd_version);
if (sd_version > 0) {
jcr->sd_client = true;
}
pthread_cond_signal(&jcr->job_start_wait); /* wake waiting job */
free_jcr(jcr);
return;
}
bool finish_cmd(JCR *jcr)
{
BSOCK *dir = jcr->dir_bsock;
char ec1[30];
/*
* See if the Job has a certain protocol. Some protocols allow the
* finish cmd some do not (Native backup for example does NOT)
*/
switch (jcr->getJobProtocol()) {
case PT_NDMP:
Dmsg1(200, "Finish_cmd: %s", jcr->dir_bsock->msg);
jcr->end_time = time(NULL);
dequeue_messages(jcr); /* send any queued messages */
jcr->setJobStatus(JS_Terminated);
switch (jcr->getJobType()) {
case JT_BACKUP:
end_of_ndmp_backup(jcr);
break;
case JT_RESTORE:
end_of_ndmp_restore(jcr);
break;
default:
break;
}
generate_plugin_event(jcr, bsdEventJobEnd);
dir->fsend(Job_end, jcr->Job, jcr->JobStatus, jcr->JobFiles,
edit_uint64(jcr->JobBytes, ec1), jcr->JobErrors);
dir->signal(BNET_EOD); /* send EOD to Director daemon */
free_plugins(jcr); /* release instantiated plugins */
Dmsg2(800, "Done jid=%d %p\n", jcr->JobId, jcr);
return false; /* Continue DIR session ? */
default:
Dmsg1(200, "Finish_cmd: %s", jcr->dir_bsock->msg);
Jmsg2(jcr, M_FATAL, 0, _("Hey!!!! JobId %u Job %s tries to use finish cmd while not part of protocol.\n"),
(uint32_t)jcr->JobId, jcr->Job);
return false; /* Continue DIR session ? */
}
}
void win_error(JCR *jcr, const char *prefix, DWORD lerror)
{
LPTSTR msg;
FormatMessage(FORMAT_MESSAGE_ALLOCATE_BUFFER | FORMAT_MESSAGE_FROM_SYSTEM,
NULL,
lerror,
0,
(LPTSTR)&msg,
0,
NULL);
strip_trailing_junk(msg);
if (jcr) {
Jmsg2(jcr, M_ERROR, 0, _("Error in %s: ERR=%s\n"), prefix, msg);
} else {
MessageBox(NULL, msg, prefix, MB_OK);
}
LocalFree(msg);
}
static bool makedir(JCR *jcr, char *path, mode_t mode, int *created)
{
struct stat statp;
if (mkdir(path, mode) != 0) {
berrno be;
*created = false;
if (stat(path, &statp) != 0) {
Jmsg2(jcr, M_ERROR, 0, _("Cannot create directory %s: ERR=%s\n"),
path, be.bstrerror());
return false;
} else if (!S_ISDIR(statp.st_mode)) {
Jmsg1(jcr, M_ERROR, 0, _("%s exists but is not a directory.\n"), path);
return false;
}
return true; /* directory exists */
}
*created = true;
return true;
}
/*
* If we are reading, we come here at the end of the tape
* and see if there are more volumes to be mounted.
*/
bool mount_next_read_volume(DCR *dcr)
{
DEVICE *dev = dcr->dev;
JCR *jcr = dcr->jcr;
Dmsg2(90, "NumReadVolumes=%d CurReadVolume=%d\n", jcr->NumReadVolumes, jcr->CurReadVolume);
volume_unused(dcr); /* release current volume */
/*
* End Of Tape -- mount next Volume (if another specified)
*/
if (jcr->NumReadVolumes > 1 && jcr->CurReadVolume < jcr->NumReadVolumes) {
dev->close();
if (!acquire_device_for_read(dcr)) {
Jmsg2(jcr, M_FATAL, 0, _("Cannot open Dev=%s, Vol=%s\n"), dev->print_name(),
dcr->VolumeName);
return false;
}
return true; /* next volume mounted */
}
Dmsg0(90, "End of Device reached.\n");
return false;
}
/*
* Clean up OpenSSL threading support
*/
void openssl_cleanup_threads(void)
{
int i, numlocks;
int status;
/* Unset thread ID callback */
CRYPTO_set_id_callback(NULL);
/* Deallocate static lock mutexes */
numlocks = CRYPTO_num_locks();
for (i = 0; i < numlocks; i++) {
if ((status = pthread_mutex_destroy(&mutexes[i])) != 0) {
berrno be;
switch (status) {
case EPERM:
/* No need to report errors when we get an EPERM */
break;
default:
/* We don't halt execution, reporting the error should be sufficient */
Jmsg2(NULL, M_ERROR, 0, _("Unable to destroy mutex: %d ERR=%s\n"),
status, be.bstrerror(status));
break;
}
}
}
/* Unset static locking callback */
CRYPTO_set_locking_callback(NULL);
/* Free static lock array */
free(mutexes);
/* Unset dynamic locking callbacks */
CRYPTO_set_dynlock_create_callback(NULL);
CRYPTO_set_dynlock_lock_callback(NULL);
CRYPTO_set_dynlock_destroy_callback(NULL);
}
/*
* Get response from Storage daemon to a command we sent.
* Check that the response is OK.
*
* Returns: false on failure
* true on success
*/
static bool response(JCR *jcr, BSOCK *sd, char *resp, const char *cmd)
{
if (sd->errors) {
return false;
}
if (bget_msg(sd) > 0) {
Dmsg1(110, "<stored: %s", sd->msg);
if (bstrcmp(sd->msg, resp)) {
return true;
}
}
if (job_canceled(jcr)) {
return false; /* if canceled avoid useless error messages */
}
if (is_bnet_error(sd)) {
Jmsg2(jcr, M_FATAL, 0, _("Comm error with SD. bad response to %s. ERR=%s\n"),
cmd, bnet_strerror(sd));
} else {
Jmsg3(jcr, M_FATAL, 0, _("Bad response to %s command. Wanted %s, got %s\n"),
cmd, resp, sd->msg);
}
return false;
}
/*
* Verify attributes of the requested files on the Volume
*
*/
void do_verify_volume(JCR *jcr)
{
BSOCK *sd, *dir;
POOLMEM *fname; /* original file name */
POOLMEM *lname; /* link name */
int32_t stream;
uint32_t size;
uint32_t VolSessionId, VolSessionTime, file_index;
uint32_t record_file_index;
char digest[BASE64_SIZE(CRYPTO_DIGEST_MAX_SIZE)];
int type, stat;
sd = jcr->store_bsock;
if (!sd) {
Jmsg(jcr, M_FATAL, 0, _("Storage command not issued before Verify.\n"));
jcr->setJobStatus(JS_FatalError);
return;
}
dir = jcr->dir_bsock;
jcr->setJobStatus(JS_Running);
LockRes();
CLIENT *client = (CLIENT *)GetNextRes(R_CLIENT, NULL);
UnlockRes();
uint32_t buf_size;
if (client) {
buf_size = client->max_network_buffer_size;
} else {
buf_size = 0; /* use default */
}
if (!sd->set_buffer_size(buf_size, BNET_SETBUF_WRITE)) {
jcr->setJobStatus(JS_FatalError);
return;
}
jcr->buf_size = sd->msglen;
fname = get_pool_memory(PM_FNAME);
lname = get_pool_memory(PM_FNAME);
/*
* Get a record from the Storage daemon
*/
while (bget_msg(sd) >= 0 && !job_canceled(jcr)) {
/*
* First we expect a Stream Record Header
*/
if (sscanf(sd->msg, rec_header, &VolSessionId, &VolSessionTime, &file_index,
&stream, &size) != 5) {
Jmsg1(jcr, M_FATAL, 0, _("Record header scan error: %s\n"), sd->msg);
goto bail_out;
}
Dmsg3(30, "Got hdr: FilInx=%d Stream=%d size=%d.\n", file_index, stream, size);
/*
* Now we expect the Stream Data
*/
if (bget_msg(sd) < 0) {
Jmsg1(jcr, M_FATAL, 0, _("Data record error. ERR=%s\n"), sd->bstrerror());
goto bail_out;
}
if (size != ((uint32_t)sd->msglen)) {
Jmsg2(jcr, M_FATAL, 0, _("Actual data size %d not same as header %d\n"), sd->msglen, size);
goto bail_out;
}
Dmsg2(30, "Got stream data %s, len=%d\n", stream_to_ascii(stream), sd->msglen);
/* File Attributes stream */
switch (stream) {
case STREAM_UNIX_ATTRIBUTES:
case STREAM_UNIX_ATTRIBUTES_EX:
char *ap, *lp, *fp;
Dmsg0(400, "Stream=Unix Attributes.\n");
if ((int)sizeof_pool_memory(fname) < sd->msglen) {
fname = realloc_pool_memory(fname, sd->msglen + 1);
}
if ((int)sizeof_pool_memory(lname) < sd->msglen) {
lname = realloc_pool_memory(lname, sd->msglen + 1);
}
*fname = 0;
*lname = 0;
/*
* An Attributes record consists of:
* File_index
* Type (FT_types)
* Filename
* Attributes
* Link name (if file linked i.e. FT_LNK)
* Extended Attributes (if Win32)
*/
if (sscanf(sd->msg, "%d %d", &record_file_index, &type) != 2) {
Jmsg(jcr, M_FATAL, 0, _("Error scanning record header: %s\n"), sd->msg);
Dmsg0(0, "\nError scanning header\n");
goto bail_out;
}
Dmsg2(30, "Got Attr: FilInx=%d type=%d\n", record_file_index, type);
ap = sd->msg;
while (*ap++ != ' ') /* skip record file index */
;
while (*ap++ != ' ') /* skip type */
;
/* Save filename and position to attributes */
fp = fname;
while (*ap != 0) {
*fp++ = *ap++; /* copy filename to fname */
}
*fp = *ap++; /* terminate filename & point to attribs */
Dmsg2(100, "File=%s Attr=%s\n", fname, ap);
/* Skip to Link name */
if (type == FT_LNK || type == FT_LNKSAVED) {
lp = ap;
while (*lp++ != 0) {
;
}
pm_strcat(lname, lp); /* "save" link name */
} else {
*lname = 0;
}
jcr->lock();
jcr->JobFiles++;
jcr->num_files_examined++;
pm_strcpy(jcr->last_fname, fname); /* last file examined */
jcr->unlock();
/*
* Send file attributes to Director
* File_index
* Stream
* Verify Options
* Filename (full path)
* Encoded attributes
* Link name (if type==FT_LNK)
* For a directory, link is the same as fname, but with trailing
* slash. For a linked file, link is the link.
*/
/* Send file attributes to Director */
Dmsg2(200, "send ATTR inx=%d fname=%s\n", jcr->JobFiles, fname);
if (type == FT_LNK || type == FT_LNKSAVED) {
stat = dir->fsend("%d %d %s %s%c%s%c%s%c", jcr->JobFiles,
STREAM_UNIX_ATTRIBUTES, "pinsug5", fname,
0, ap, 0, lname, 0);
/* for a deleted record, we set fileindex=0 */
} else if (type == FT_DELETED) {
stat = dir->fsend("%d %d %s %s%c%s%c%c", 0,
STREAM_UNIX_ATTRIBUTES, "pinsug5", fname,
0, ap, 0, 0);
} else {
stat = dir->fsend("%d %d %s %s%c%s%c%c", jcr->JobFiles,
STREAM_UNIX_ATTRIBUTES, "pinsug5", fname,
0, ap, 0, 0);
}
Dmsg2(200, "bfiled>bdird: attribs len=%d: msg=%s\n", dir->msglen, dir->msg);
if (!stat) {
Jmsg(jcr, M_FATAL, 0, _("Network error in send to Director: ERR=%s\n"), dir->bstrerror());
goto bail_out;
}
break;
case STREAM_MD5_DIGEST:
bin_to_base64(digest, sizeof(digest), (char *)sd->msg, CRYPTO_DIGEST_MD5_SIZE, true);
Dmsg2(400, "send inx=%d MD5=%s\n", jcr->JobFiles, digest);
dir->fsend("%d %d %s *MD5-%d*", jcr->JobFiles, STREAM_MD5_DIGEST, digest,
jcr->JobFiles);
Dmsg2(20, "bfiled>bdird: MD5 len=%d: msg=%s\n", dir->msglen, dir->msg);
break;
case STREAM_SHA1_DIGEST:
bin_to_base64(digest, sizeof(digest), (char *)sd->msg, CRYPTO_DIGEST_SHA1_SIZE, true);
Dmsg2(400, "send inx=%d SHA1=%s\n", jcr->JobFiles, digest);
dir->fsend("%d %d %s *SHA1-%d*", jcr->JobFiles, STREAM_SHA1_DIGEST,
digest, jcr->JobFiles);
Dmsg2(20, "bfiled>bdird: SHA1 len=%d: msg=%s\n", dir->msglen, dir->msg);
break;
case STREAM_SHA256_DIGEST:
bin_to_base64(digest, sizeof(digest), (char *)sd->msg, CRYPTO_DIGEST_SHA256_SIZE, true);
Dmsg2(400, "send inx=%d SHA256=%s\n", jcr->JobFiles, digest);
dir->fsend("%d %d %s *SHA256-%d*", jcr->JobFiles, STREAM_SHA256_DIGEST,
digest, jcr->JobFiles);
Dmsg2(20, "bfiled>bdird: SHA256 len=%d: msg=%s\n", dir->msglen, dir->msg);
break;
case STREAM_SHA512_DIGEST:
bin_to_base64(digest, sizeof(digest), (char *)sd->msg, CRYPTO_DIGEST_SHA512_SIZE, true);
Dmsg2(400, "send inx=%d SHA512=%s\n", jcr->JobFiles, digest);
dir->fsend("%d %d %s *SHA512-%d*", jcr->JobFiles, STREAM_SHA512_DIGEST,
digest, jcr->JobFiles);
Dmsg2(20, "bfiled>bdird: SHA512 len=%d: msg=%s\n", dir->msglen, dir->msg);
break;
/*
* Restore stream object is counted, but not restored here
*/
case STREAM_RESTORE_OBJECT:
jcr->lock();
jcr->JobFiles++;
jcr->num_files_examined++;
jcr->unlock();
break;
/* Ignore everything else */
default:
break;
} /* end switch */
} /* end while bnet_get */
jcr->setJobStatus(JS_Terminated);
goto ok_out;
bail_out:
jcr->setJobStatus(JS_ErrorTerminated);
ok_out:
if (jcr->compress_buf) {
free(jcr->compress_buf);
jcr->compress_buf = NULL;
}
free_pool_memory(fname);
free_pool_memory(lname);
Dmsg2(050, "End Verify-Vol. Files=%d Bytes=%" lld "\n", jcr->JobFiles,
jcr->JobBytes);
}
/*
* Read the header record
*/
static bool read_header(DCR *dcr, DEV_BLOCK *block, DEV_RECORD *rec)
{
ser_declare;
uint32_t VolSessionId;
uint32_t VolSessionTime;
int32_t FileIndex;
int32_t Stream;
uint32_t rhl;
char buf1[100], buf2[100];
Dmsg0(dbgep, "=== rpath 1 read_header\n");
/* Clear state flags */
rec->state_bits = 0;
if (block->dev->is_tape()) {
rec->state_bits |= REC_ISTAPE;
}
rec->Block = ((DEVICE *)block->dev)->EndBlock;
rec->File = ((DEVICE *)block->dev)->EndFile;
/*
* Get the header. There is always a full header,
* otherwise we find it in the next block.
*/
Dmsg3(read_dbglvl, "Block=%d Ver=%d block_len=%u\n",
block->BlockNumber, block->BlockVer, block->block_len);
if (block->BlockVer == 1) {
rhl = RECHDR1_LENGTH;
} else {
rhl = RECHDR2_LENGTH;
}
if (rec->remlen >= rhl) {
Dmsg0(dbgep, "=== rpath 2 begin unserial header\n");
Dmsg4(read_dbglvl, "read_header: remlen=%d data_len=%d rem=%d blkver=%d\n",
rec->remlen, rec->data_len, rec->remainder, block->BlockVer);
unser_begin(block->bufp, WRITE_RECHDR_LENGTH);
if (block->BlockVer == 1) {
unser_uint32(VolSessionId);
unser_uint32(VolSessionTime);
} else {
VolSessionId = block->VolSessionId;
VolSessionTime = block->VolSessionTime;
}
unser_int32(FileIndex);
unser_int32(Stream);
unser_uint32(rec->data_bytes);
block->bufp += rhl;
block->binbuf -= rhl;
rec->remlen -= rhl;
/* If we are looking for more (remainder!=0), we reject anything
* where the VolSessionId and VolSessionTime don't agree
*/
if (rec->remainder && (rec->VolSessionId != VolSessionId ||
rec->VolSessionTime != VolSessionTime)) {
rec->state_bits |= REC_NO_MATCH;
Dmsg0(read_dbglvl, "remainder and VolSession doesn't match\n");
Dmsg0(dbgep, "=== rpath 4 VolSession no match\n");
return false; /* This is from some other Session */
}
/* if Stream is negative, it means that this is a continuation
* of a previous partially written record.
*/
if (Stream < 0) { /* continuation record? */
Dmsg0(dbgep, "=== rpath 5 negative stream\n");
Dmsg1(read_dbglvl, "Got negative Stream => continuation. remainder=%d\n",
rec->remainder);
rec->state_bits |= REC_CONTINUATION;
if (!rec->remainder) { /* if we didn't read previously */
Dmsg0(dbgep, "=== rpath 6 no remainder\n");
rec->data_len = 0; /* return data as if no continuation */
} else if (rec->Stream != -Stream) {
Dmsg0(dbgep, "=== rpath 7 wrong cont stream\n");
rec->state_bits |= REC_NO_MATCH;
return false; /* This is from some other Session */
}
rec->Stream = -Stream; /* set correct Stream */
rec->maskedStream = rec->Stream & STREAMMASK_TYPE;
} else { /* Regular record */
Dmsg0(dbgep, "=== rpath 8 normal stream\n");
rec->Stream = Stream;
rec->maskedStream = rec->Stream & STREAMMASK_TYPE;
rec->data_len = 0; /* transfer to beginning of data */
}
rec->VolSessionId = VolSessionId;
rec->VolSessionTime = VolSessionTime;
rec->FileIndex = FileIndex;
if (FileIndex > 0) {
Dmsg0(dbgep, "=== rpath 9 FileIndex>0\n");
if (block->FirstIndex == 0) {
Dmsg0(dbgep, "=== rpath 10 FirstIndex\n");
block->FirstIndex = FileIndex;
}
block->LastIndex = rec->FileIndex;
}
Dmsg6(read_dbglvl, "read_header: FI=%s SessId=%d Strm=%s len=%u rec->remlen=%d data_len=%d\n",
FI_to_ascii(buf1, rec->FileIndex), rec->VolSessionId,
stream_to_ascii(buf2, rec->Stream, rec->FileIndex), rec->data_bytes, rec->remlen,
rec->data_len);
} else {
Dmsg0(dbgep, "=== rpath 11a block out of records\n");
/*
* No more records in this block because the number
* of remaining bytes are less than a record header
* length, so return empty handed, but indicate that
* he must read again. By returning, we allow the
* higher level routine to fetch the next block and
* then reread.
*/
Dmsg0(read_dbglvl, "read_header: End of block\n");
rec->state_bits |= (REC_NO_HEADER | REC_BLOCK_EMPTY);
empty_block(block); /* mark block empty */
return false;
}
/* Sanity check */
if (rec->data_bytes >= MAX_BLOCK_LENGTH) {
Dmsg0(dbgep, "=== rpath 11b maxlen too big\n");
/*
* Something is wrong, force read of next block, abort
* continuing with this block.
*/
rec->state_bits |= (REC_NO_HEADER | REC_BLOCK_EMPTY);
empty_block(block);
Jmsg2(dcr->jcr, M_WARNING, 0, _("Sanity check failed. maxlen=%d datalen=%d. Block discarded.\n"),
MAX_BLOCK_LENGTH, rec->data_bytes);
return false;
}
rec->data = check_pool_memory_size(rec->data, rec->data_len+rec->data_bytes);
rec->rstate = st_data;
return true;
}
/*
* Read a Record from the block
*
* Returns: false if nothing read or if the continuation record does not match.
* In both of these cases, a block read must be done.
* true if at least the record header was read, this
* routine may have to be called again with a new
* block if the entire record was not read.
*/
bool read_record_from_block(DCR *dcr, DEV_RECORD *rec)
{
ser_declare;
uint32_t remlen;
uint32_t VolSessionId;
uint32_t VolSessionTime;
int32_t FileIndex;
int32_t Stream;
uint32_t data_bytes;
uint32_t rhl;
char buf1[100], buf2[100];
remlen = dcr->block->binbuf;
/*
* Clear state flags
*/
clear_all_bits(REC_STATE_MAX, rec->state_bits);
if (dcr->block->dev->is_tape()) {
set_bit(REC_ISTAPE, rec->state_bits);
}
rec->Block = ((DEVICE *)(dcr->block->dev))->EndBlock;
rec->File = ((DEVICE *)(dcr->block->dev))->EndFile;
/*
* Get the header. There is always a full header, otherwise we find it in the next block.
*/
Dmsg3(450, "Block=%d Ver=%d size=%u\n", dcr->block->BlockNumber, dcr->block->BlockVer,
dcr->block->block_len);
if (dcr->block->BlockVer == 1) {
rhl = RECHDR1_LENGTH;
} else {
rhl = RECHDR2_LENGTH;
}
if (remlen >= rhl) {
Dmsg4(450, "Enter read_record_block: remlen=%d data_len=%d rem=%d blkver=%d\n",
remlen, rec->data_len, rec->remainder, dcr->block->BlockVer);
unser_begin(dcr->block->bufp, WRITE_RECHDR_LENGTH);
if (dcr->block->BlockVer == 1) {
unser_uint32(VolSessionId);
unser_uint32(VolSessionTime);
} else {
VolSessionId = dcr->block->VolSessionId;
VolSessionTime = dcr->block->VolSessionTime;
}
unser_int32(FileIndex);
unser_int32(Stream);
unser_uint32(data_bytes);
dcr->block->bufp += rhl;
dcr->block->binbuf -= rhl;
remlen -= rhl;
/*
* If we are looking for more (remainder!=0), we reject anything
* where the VolSessionId and VolSessionTime don't agree
*/
if (rec->remainder && (rec->VolSessionId != VolSessionId ||
rec->VolSessionTime != VolSessionTime)) {
set_bit(REC_NO_MATCH, rec->state_bits);
Dmsg0(450, "remainder and VolSession doesn't match\n");
return false; /* This is from some other Session */
}
/*
* If Stream is negative, it means that this is a continuation
* of a previous partially written record.
*/
if (Stream < 0) { /* continuation record? */
Dmsg1(500, "Got negative Stream => continuation. remainder=%d\n", rec->remainder);
set_bit(REC_CONTINUATION, rec->state_bits);
if (!rec->remainder) { /* if we didn't read previously */
rec->data_len = 0; /* return data as if no continuation */
} else if (rec->Stream != -Stream) {
set_bit(REC_NO_MATCH, rec->state_bits);
return false; /* This is from some other Session */
}
rec->Stream = -Stream; /* set correct Stream */
rec->maskedStream = rec->Stream & STREAMMASK_TYPE;
} else { /* Regular record */
rec->Stream = Stream;
rec->maskedStream = rec->Stream & STREAMMASK_TYPE;
rec->data_len = 0; /* transfer to beginning of data */
}
rec->VolSessionId = VolSessionId;
rec->VolSessionTime = VolSessionTime;
rec->FileIndex = FileIndex;
if (FileIndex > 0) {
if (dcr->block->FirstIndex == 0) {
dcr->block->FirstIndex = FileIndex;
}
dcr->block->LastIndex = FileIndex;
}
Dmsg6(450, "rd_rec_blk() got FI=%s SessId=%d Strm=%s len=%u\n"
"remlen=%d data_len=%d\n",
FI_to_ascii(buf1, rec->FileIndex), rec->VolSessionId,
stream_to_ascii(buf2, rec->Stream, rec->FileIndex), data_bytes, remlen,
rec->data_len);
} else {
/*
* No more records in this block because the number
* of remaining bytes are less than a record header
* length, so return empty handed, but indicate that
* he must read again. By returning, we allow the
* higher level routine to fetch the next block and
* then reread.
*/
Dmsg0(450, "read_record_block: nothing\n");
set_bit(REC_NO_HEADER, rec->state_bits);
set_bit(REC_BLOCK_EMPTY, rec->state_bits);
empty_block(dcr->block); /* mark block empty */
return false;
}
/* Sanity check */
if (data_bytes >= MAX_BLOCK_LENGTH) {
/*
* Something is wrong, force read of next block, abort
* continuing with this block.
*/
set_bit(REC_NO_HEADER, rec->state_bits);
set_bit(REC_BLOCK_EMPTY, rec->state_bits);
empty_block(dcr->block);
Jmsg2(dcr->jcr, M_WARNING, 0, _("Sanity check failed. maxlen=%d datalen=%d. Block discarded.\n"),
MAX_BLOCK_LENGTH, data_bytes);
return false;
}
rec->data = check_pool_memory_size(rec->data, rec->data_len + data_bytes);
/*
* At this point, we have read the header, now we
* must transfer as much of the data record as
* possible taking into account: 1. A partial
* data record may have previously been transferred,
* 2. The current block may not contain the whole data
* record.
*/
if (remlen >= data_bytes) {
/*
* Got whole record
*/
memcpy(rec->data+rec->data_len, dcr->block->bufp, data_bytes);
dcr->block->bufp += data_bytes;
dcr->block->binbuf -= data_bytes;
rec->data_len += data_bytes;
} else {
/*
* Partial record
*/
memcpy(rec->data+rec->data_len, dcr->block->bufp, remlen);
dcr->block->bufp += remlen;
dcr->block->binbuf -= remlen;
rec->data_len += remlen;
rec->remainder = 1; /* partial record transferred */
Dmsg1(450, "read_record_block: partial xfered=%d\n", rec->data_len);
set_bit(REC_PARTIAL_RECORD, rec->state_bits);
set_bit(REC_BLOCK_EMPTY, rec->state_bits);
return true;
}
rec->remainder = 0;
Dmsg4(450, "Rtn full rd_rec_blk 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);
return true; /* transferred full record */
}
/*********************************************************************
* Acquire device for reading.
* The drive should have previously been reserved by calling
* reserve_device_for_read(). We read the Volume label from the block and
* leave the block pointers just after the label.
*
* Returns: NULL if failed for any reason
* dcr if successful
*/
bool acquire_device_for_read(DCR *dcr)
{
DEVICE *dev;
JCR *jcr = dcr->jcr;
bool ok = false;
bool tape_previously_mounted;
VOL_LIST *vol;
bool try_autochanger = true;
int i;
int vol_label_status;
int retry = 0;
Enter(rdbglvl);
dev = dcr->dev;
dev->Lock_read_acquire();
Dmsg2(rdbglvl, "dcr=%p dev=%p\n", dcr, dcr->dev);
Dmsg2(rdbglvl, "MediaType dcr=%s dev=%s\n", dcr->media_type, dev->device->media_type);
dev->dblock(BST_DOING_ACQUIRE);
if (dev->num_writers > 0) {
Jmsg2(jcr, M_FATAL, 0, _("Acquire read: num_writers=%d not zero. Job %d canceled.\n"),
dev->num_writers, jcr->JobId);
goto get_out;
}
/* Find next Volume, if any */
vol = jcr->VolList;
if (!vol) {
char ed1[50];
Jmsg(jcr, M_FATAL, 0, _("No volumes specified for reading. Job %s canceled.\n"),
edit_int64(jcr->JobId, ed1));
goto get_out;
}
jcr->CurReadVolume++;
for (i=1; i<jcr->CurReadVolume; i++) {
vol = vol->next;
}
if (!vol) {
Jmsg(jcr, M_FATAL, 0, _("Logic error: no next volume to read. Numvol=%d Curvol=%d\n"),
jcr->NumReadVolumes, jcr->CurReadVolume);
goto get_out; /* should not happen */
}
set_dcr_from_vol(dcr, vol);
Dmsg2(rdbglvl, "Want Vol=%s Slot=%d\n", vol->VolumeName, vol->Slot);
/*
* If the MediaType requested for this volume is not the
* same as the current drive, we attempt to find the same
* device that was used to write the orginal volume. If
* found, we switch to using that device.
*
* N.B. A lot of routines rely on the dcr pointer not changing
* read_records.c even has multiple dcrs cached, so we take care
* here to release all important parts of the dcr and re-acquire
* them such as the block pointer (size may change), but we do
* not release the dcr.
*/
Dmsg2(rdbglvl, "MediaType dcr=%s dev=%s\n", dcr->media_type, dev->device->media_type);
if (dcr->media_type[0] && !bstrcmp(dcr->media_type, dev->device->media_type)) {
RCTX rctx;
DIRSTORE *store;
int status;
Jmsg3(jcr, M_INFO, 0, _("Changing read device. Want Media Type=\"%s\" have=\"%s\"\n"
" device=%s\n"),
dcr->media_type, dev->device->media_type, dev->print_name());
Dmsg3(rdbglvl, "Changing read device. Want Media Type=\"%s\" have=\"%s\"\n"
" device=%s\n",
dcr->media_type, dev->device->media_type, dev->print_name());
dev->dunblock(DEV_UNLOCKED);
lock_reservations();
memset(&rctx, 0, sizeof(RCTX));
rctx.jcr = jcr;
jcr->read_dcr = dcr;
jcr->reserve_msgs = New(alist(10, not_owned_by_alist));
rctx.any_drive = true;
rctx.device_name = vol->device;
store = new DIRSTORE;
memset(store, 0, sizeof(DIRSTORE));
store->name[0] = 0; /* No dir name */
bstrncpy(store->media_type, vol->MediaType, sizeof(store->media_type));
bstrncpy(store->pool_name, dcr->pool_name, sizeof(store->pool_name));
bstrncpy(store->pool_type, dcr->pool_type, sizeof(store->pool_type));
store->append = false;
rctx.store = store;
clean_device(dcr); /* clean up the dcr */
/*
* Search for a new device
*/
status = search_res_for_device(rctx);
release_reserve_messages(jcr); /* release queued messages */
unlock_reservations();
if (status == 1) { /* found new device to use */
/*
* Switching devices, so acquire lock on new device,
* then release the old one.
*/
dcr->dev->Lock_read_acquire(); /* lock new one */
dev->Unlock_read_acquire(); /* release old one */
dev = dcr->dev; /* get new device pointer */
dev->dblock(BST_DOING_ACQUIRE);
dcr->VolumeName[0] = 0;
Jmsg(jcr, M_INFO, 0, _("Media Type change. New read device %s chosen.\n"),
dev->print_name());
Dmsg1(50, "Media Type change. New read device %s chosen.\n", dev->print_name());
bstrncpy(dcr->VolumeName, vol->VolumeName, sizeof(dcr->VolumeName));
dcr->setVolCatName(vol->VolumeName);
bstrncpy(dcr->media_type, vol->MediaType, sizeof(dcr->media_type));
dcr->VolCatInfo.Slot = vol->Slot;
dcr->VolCatInfo.InChanger = vol->Slot > 0;
bstrncpy(dcr->pool_name, store->pool_name, sizeof(dcr->pool_name));
bstrncpy(dcr->pool_type, store->pool_type, sizeof(dcr->pool_type));
} else {
/* error */
Jmsg1(jcr, M_FATAL, 0, _("No suitable device found to read Volume \"%s\"\n"),
vol->VolumeName);
Dmsg1(rdbglvl, "No suitable device found to read Volume \"%s\"\n", vol->VolumeName);
goto get_out;
}
}
Dmsg2(rdbglvl, "MediaType dcr=%s dev=%s\n", dcr->media_type, dev->device->media_type);
dev->clear_unload();
if (dev->vol && dev->vol->is_swapping()) {
dev->vol->set_slot(vol->Slot);
Dmsg3(rdbglvl, "swapping: slot=%d Vol=%s dev=%s\n", dev->vol->get_slot(),
dev->vol->vol_name, dev->print_name());
}
init_device_wait_timers(dcr);
tape_previously_mounted = dev->can_read() || dev->can_append() ||
dev->is_labeled();
// tape_initially_mounted = tape_previously_mounted;
/* Volume info is always needed because of VolParts */
Dmsg1(rdbglvl, "dir_get_volume_info vol=%s\n", dcr->VolumeName);
if (!dcr->dir_get_volume_info(GET_VOL_INFO_FOR_READ)) {
Dmsg2(rdbglvl, "dir_get_vol_info failed for vol=%s: %s\n",
dcr->VolumeName, jcr->errmsg);
Jmsg1(jcr, M_WARNING, 0, "Read acquire: %s", jcr->errmsg);
}
dev->set_load(); /* set to load volume */
for ( ;; ) {
/* If not polling limit retries */
if (!dev->poll && retry++ > 10) {
break;
}
dev->clear_labeled(); /* force reread of label */
if (job_canceled(jcr)) {
char ed1[50];
Mmsg1(dev->errmsg, _("Job %s canceled.\n"), edit_int64(jcr->JobId, ed1));
Jmsg(jcr, M_INFO, 0, dev->errmsg);
goto get_out; /* error return */
}
dcr->do_unload();
dcr->do_swapping(false/*!is_writing*/);
dcr->do_load(false /*!is_writing*/);
set_dcr_from_vol(dcr, vol); /* refresh dcr with desired volume info */
/*
* This code ensures that the device is ready for
* reading. If it is a file, it opens it.
* If it is a tape, it checks the volume name
*/
Dmsg1(rdbglvl, "stored: open vol=%s\n", dcr->VolumeName);
if (!dev->open(dcr, OPEN_READ_ONLY)) {
if (!dev->poll) {
Jmsg3(jcr, M_WARNING, 0, _("Read open device %s Volume \"%s\" failed: ERR=%s\n"),
dev->print_name(), dcr->VolumeName, dev->bstrerror());
}
goto default_path;
}
Dmsg1(rdbglvl, "opened dev %s OK\n", dev->print_name());
/* Read Volume Label */
Dmsg0(rdbglvl, "calling read-vol-label\n");
vol_label_status = read_dev_volume_label(dcr);
switch (vol_label_status) {
case VOL_OK:
Dmsg0(rdbglvl, "Got correct volume.\n");
ok = true;
dev->VolCatInfo = dcr->VolCatInfo; /* structure assignment */
break; /* got it */
case VOL_IO_ERROR:
Dmsg0(rdbglvl, "IO Error\n");
/*
* Send error message generated by read_dev_volume_label()
* only we really had a tape mounted. This supresses superfluous
* error messages when nothing is mounted.
*/
if (tape_previously_mounted) {
Jmsg(jcr, M_WARNING, 0, "Read acquire: %s", jcr->errmsg);
}
goto default_path;
case VOL_NAME_ERROR:
Dmsg3(rdbglvl, "Vol name=%s want=%s drv=%s.\n", dev->VolHdr.VolumeName,
dcr->VolumeName, dev->print_name());
if (dev->is_volume_to_unload()) {
goto default_path;
}
dev->set_unload(); /* force unload of unwanted tape */
if (!unload_autochanger(dcr, -1)) {
/* at least free the device so we can re-open with correct volume */
dev->close(dcr);
free_volume(dev);
}
dev->set_load();
/* Fall through */
default:
Jmsg1(jcr, M_WARNING, 0, "Read acquire: %s", jcr->errmsg);
default_path:
Dmsg0(rdbglvl, "default path\n");
tape_previously_mounted = true;
/*
* If the device requires mount, close it, so the device can be ejected.
*/
if (dev->requires_mount()) {
dev->close(dcr);
free_volume(dev);
}
/* Call autochanger only once unless ask_sysop called */
if (try_autochanger) {
int status;
Dmsg2(rdbglvl, "calling autoload Vol=%s Slot=%d\n",
dcr->VolumeName, dcr->VolCatInfo.Slot);
status = autoload_device(dcr, 0, NULL);
if (status > 0) {
try_autochanger = false;
continue; /* try reading volume mounted */
}
}
/* Mount a specific volume and no other */
Dmsg0(rdbglvl, "calling dir_ask_sysop\n");
if (!dcr->dir_ask_sysop_to_mount_volume(ST_READREADY)) {
goto get_out; /* error return */
}
/* Volume info is always needed because of VolParts */
Dmsg1(150, "dir_get_volume_info vol=%s\n", dcr->VolumeName);
if (!dcr->dir_get_volume_info(GET_VOL_INFO_FOR_READ)) {
Dmsg2(150, "dir_get_vol_info failed for vol=%s: %s\n",
dcr->VolumeName, jcr->errmsg);
Jmsg1(jcr, M_WARNING, 0, "Read acquire: %s", jcr->errmsg);
}
dev->set_load(); /* set to load volume */
try_autochanger = true; /* permit trying the autochanger again */
continue; /* try reading again */
} /* end switch */
break;
} /* end for loop */
if (!ok) {
Jmsg1(jcr, M_FATAL, 0, _("Too many errors trying to mount device %s for reading.\n"),
dev->print_name());
goto get_out;
}
dev->clear_append();
dev->set_read();
jcr->sendJobStatus(JS_Running);
Jmsg(jcr, M_INFO, 0, _("Ready to read from volume \"%s\" on device %s.\n"),
dcr->VolumeName, dev->print_name());
get_out:
dev->Lock();
dcr->clear_reserved();
/*
* Normally we are blocked, but in at least one error case above
* we are not blocked because we unsuccessfully tried changing
* devices.
*/
if (dev->is_blocked()) {
dev->dunblock(DEV_LOCKED);
} else {
dev->Unlock(); /* dunblock() unlock the device too */
}
Dmsg2(rdbglvl, "dcr=%p dev=%p\n", dcr, dcr->dev);
Dmsg2(rdbglvl, "MediaType dcr=%s dev=%s\n", dcr->media_type, dev->device->media_type);
dev->Unlock_read_acquire();
Leave(rdbglvl);
return ok;
}
/*
* This job is done, so release the device. From a Unix standpoint,
* the device remains open.
*
* Note, if we were spooling, we may enter with the device blocked.
* We unblock at the end, only if it was us who blocked the
* device.
*
*/
bool release_device(DCR *dcr)
{
utime_t now;
JCR *jcr = dcr->jcr;
DEVICE *dev = dcr->dev;
bool ok = true;
char tbuf[100];
int was_blocked = BST_NOT_BLOCKED;
/*
* Capture job statistics now that we are done using this device.
*/
now = (utime_t)time(NULL);
update_job_statistics(jcr, now);
dev->Lock();
if (!dev->is_blocked()) {
block_device(dev, BST_RELEASING);
} else {
was_blocked = dev->blocked();
dev->set_blocked(BST_RELEASING);
}
lock_volumes();
Dmsg2(100, "release_device device %s is %s\n", dev->print_name(), dev->is_tape() ? "tape" : "disk");
/*
* If device is reserved, job never started, so release the reserve here
*/
dcr->clear_reserved();
if (dev->can_read()) {
VOLUME_CAT_INFO *vol = &dev->VolCatInfo;
dev->clear_read(); /* clear read bit */
Dmsg2(150, "dir_update_vol_info. label=%d Vol=%s\n",
dev->is_labeled(), vol->VolCatName);
if (dev->is_labeled() && vol->VolCatName[0] != 0) {
dcr->dir_update_volume_info(false, false); /* send Volume info to Director */
remove_read_volume(jcr, dcr->VolumeName);
volume_unused(dcr);
}
} else if (dev->num_writers > 0) {
/*
* Note if WEOT is set, we are at the end of the tape and may not be positioned correctly,
* so the job_media_record and update_vol_info have already been done,
* which means we skip them here.
*/
dev->num_writers--;
Dmsg1(100, "There are %d writers in release_device\n", dev->num_writers);
if (dev->is_labeled()) {
Dmsg2(200, "dir_create_jobmedia. Release vol=%s dev=%s\n",
dev->getVolCatName(), dev->print_name());
if (!dev->at_weot() && !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);
}
/*
* If no more writers, and no errors, and wrote something, write an EOF
*/
if (!dev->num_writers && dev->can_write() && dev->block_num > 0) {
dev->weof(1);
write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName);
}
if (!dev->at_weot()) {
dev->VolCatInfo.VolCatFiles = dev->file; /* set number of files */
/*
* Note! do volume update before close, which zaps VolCatInfo
*/
dcr->dir_update_volume_info(false, false); /* send Volume info to Director */
Dmsg2(200, "dir_update_vol_info. Release vol=%s dev=%s\n",
dev->getVolCatName(), dev->print_name());
}
if (dev->num_writers == 0) { /* if not being used */
volume_unused(dcr); /* we obviously are not using the volume */
}
}
} else {
/*
* If we reach here, it is most likely because the job has failed,
* since the device is not in read mode and there are no writers.
* It was probably reserved.
*/
volume_unused(dcr);
}
Dmsg3(100, "%d writers, %d reserve, dev=%s\n", dev->num_writers, dev->num_reserved(), dev->print_name());
/*
* If no writers, close if file or !CAP_ALWAYS_OPEN
*/
if (dev->num_writers == 0 && (!dev->is_tape() || !dev->has_cap(CAP_ALWAYSOPEN))) {
dev->close(dcr);
free_volume(dev);
}
unlock_volumes();
/*
* Fire off Alert command and include any output
*/
if (!job_canceled(jcr)) {
if (!dcr->device->drive_tapealert_enabled && dcr->device->alert_command) {
int status = 1;
POOLMEM *alert, *line;
BPIPE *bpipe;
alert = get_pool_memory(PM_FNAME);
line = get_pool_memory(PM_FNAME);
alert = edit_device_codes(dcr, alert, dcr->device->alert_command, "");
/*
* Wait maximum 5 minutes
*/
bpipe = open_bpipe(alert, 60 * 5, "r");
if (bpipe) {
while (bfgets(line, bpipe->rfd)) {
Jmsg(jcr, M_ALERT, 0, _("Alert: %s"), line);
}
status = close_bpipe(bpipe);
} else {
status = errno;
}
if (status != 0) {
berrno be;
Jmsg(jcr, M_ALERT, 0, _("3997 Bad alert command: %s: ERR=%s.\n"), alert, be.bstrerror(status));
}
Dmsg1(400, "alert status=%d\n", status);
free_pool_memory(alert);
free_pool_memory(line);
} else {
/*
* If all reservations are cleared for this device raise an event that SD plugins can register to.
*/
if (dev->num_reserved() == 0) {
generate_plugin_event(jcr, bsdEventDeviceReleased, dcr);
}
}
}
pthread_cond_broadcast(&dev->wait_next_vol);
Dmsg2(100, "JobId=%u broadcast wait_device_release at %s\n",
(uint32_t)jcr->JobId, bstrftimes(tbuf, sizeof(tbuf), (utime_t)time(NULL)));
release_device_cond();
/*
* If we are the thread that blocked the device, then unblock it
*/
if (pthread_equal(dev->no_wait_id, pthread_self())) {
dev->dunblock(true);
} else {
/*
* Otherwise, reset the prior block status and unlock
*/
dev->set_blocked(was_blocked);
dev->Unlock();
}
if (dcr->keep_dcr) {
detach_dcr_from_dev(dcr);
} else {
free_dcr(dcr);
}
Dmsg2(100, "Device %s released by JobId=%u\n", dev->print_name(), (uint32_t)jcr->JobId);
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;
}
/*
* Setup device, jcr, and prepare to access device.
* If the caller wants read access, acquire the device, otherwise,
* the caller will do it.
*/
static DCR *setup_to_access_device(JCR *jcr, char *dev_name,
const char *VolumeName, int mode)
{
DEVICE *dev;
char *p;
DEVRES *device;
DCR *dcr;
char VolName[MAX_NAME_LENGTH];
init_reservations_lock();
/*
* If no volume name already given and no bsr, and it is a file,
* try getting name from Filename
*/
if (VolumeName) {
bstrncpy(VolName, VolumeName, sizeof(VolName));
if (strlen(VolumeName) >= MAX_NAME_LENGTH) {
Jmsg0(jcr, M_ERROR, 0, _("Volume name or names is too long. Please use a .bsr file.\n"));
}
} else {
VolName[0] = 0;
}
if (!jcr->bsr && VolName[0] == 0) {
if (!bstrncmp(dev_name, "/dev/", 5)) {
/* Try stripping file part */
p = dev_name + strlen(dev_name);
while (p >= dev_name && !IsPathSeparator(*p))
p--;
if (IsPathSeparator(*p)) {
bstrncpy(VolName, p+1, sizeof(VolName));
*p = 0;
}
}
}
if ((device=find_device_res(dev_name, mode)) == NULL) {
Jmsg2(jcr, M_FATAL, 0, _("Cannot find device \"%s\" in config file %s.\n"),
dev_name, configfile);
return NULL;
}
dev = init_dev(jcr, device);
if (!dev) {
Jmsg1(jcr, M_FATAL, 0, _("Cannot init device %s\n"), dev_name);
return NULL;
}
device->dev = dev;
jcr->dcr = dcr = new_dcr(jcr, NULL, dev);
if (VolName[0]) {
bstrncpy(dcr->VolumeName, VolName, sizeof(dcr->VolumeName));
}
bstrncpy(dcr->dev_name, device->device_name, sizeof(dcr->dev_name));
create_restore_volume_list(jcr);
if (mode) { /* read only access? */
Dmsg0(100, "Acquire device for read\n");
if (!acquire_device_for_read(dcr)) {
return NULL;
}
jcr->read_dcr = dcr;
} else {
if (!first_open_device(dcr)) {
Jmsg1(jcr, M_FATAL, 0, _("Cannot open %s\n"), dev->print_name());
return NULL;
}
jcr->dcr = dcr; /* write dcr */
}
return dcr;
}
/*
* Authenticate Storage daemon connection
*/
bool authenticate_storage_daemon(JCR *jcr, STORERES *store)
{
BSOCK *sd = jcr->store_bsock;
char dirname[MAX_NAME_LENGTH];
int tls_local_need = BNET_TLS_NONE;
int tls_remote_need = BNET_TLS_NONE;
int compatible = true;
bool auth_success = false;
/*
* Send my name to the Storage daemon then do authentication
*/
bstrncpy(dirname, director->hdr.name, sizeof(dirname));
bash_spaces(dirname);
/* Timeout Hello after 1 min */
btimer_t *tid = start_bsock_timer(sd, AUTH_TIMEOUT);
if (!sd->fsend(hello, dirname)) {
stop_bsock_timer(tid);
Dmsg1(dbglvl, _("Error sending Hello to Storage daemon. ERR=%s\n"), bnet_strerror(sd));
Jmsg(jcr, M_FATAL, 0, _("Error sending Hello to Storage daemon. ERR=%s\n"), bnet_strerror(sd));
return 0;
}
/* TLS Requirement */
if (store->tls_enable) {
if (store->tls_require) {
tls_local_need = BNET_TLS_REQUIRED;
} else {
tls_local_need = BNET_TLS_OK;
}
}
if (store->tls_authenticate) {
tls_local_need = BNET_TLS_REQUIRED;
}
auth_success = cram_md5_respond(sd, store->password, &tls_remote_need, &compatible);
if (auth_success) {
auth_success = cram_md5_challenge(sd, store->password, tls_local_need, compatible);
if (!auth_success) {
Dmsg1(dbglvl, "cram_challenge failed for %s\n", sd->who());
}
} else {
Dmsg1(dbglvl, "cram_respond failed for %s\n", sd->who());
}
if (!auth_success) {
stop_bsock_timer(tid);
Dmsg0(dbglvl, _("Director and Storage daemon passwords or names not the same.\n"));
Jmsg2(jcr, M_FATAL, 0,
_("Director unable to authenticate with Storage daemon at \"%s:%d\". Possible causes:\n"
"Passwords or names not the same or\n"
"Maximum Concurrent Jobs exceeded on the SD or\n"
"SD networking messed up (restart daemon).\n"
"Please see " MANUAL_AUTH_URL " for help.\n"),
sd->host(), sd->port());
return 0;
}
/* Verify that the remote host is willing to meet our TLS requirements */
if (tls_remote_need < tls_local_need && tls_local_need != BNET_TLS_OK && tls_remote_need != BNET_TLS_OK) {
stop_bsock_timer(tid);
Jmsg(jcr, M_FATAL, 0, _("Authorization problem: Remote server did not advertise required TLS support.\n"));
return 0;
}
/* Verify that we are willing to meet the remote host's requirements */
if (tls_remote_need > tls_local_need && tls_local_need != BNET_TLS_OK && tls_remote_need != BNET_TLS_OK) {
stop_bsock_timer(tid);
Jmsg(jcr, M_FATAL, 0, _("Authorization problem: Remote server requires TLS.\n"));
return 0;
}
/* Is TLS Enabled? */
if (tls_local_need >= BNET_TLS_OK && tls_remote_need >= BNET_TLS_OK) {
/* Engage TLS! Full Speed Ahead! */
if (!bnet_tls_client(store->tls_ctx, sd, NULL)) {
stop_bsock_timer(tid);
Jmsg(jcr, M_FATAL, 0, _("TLS negotiation failed with SD at \"%s:%d\"\n"),
sd->host(), sd->port());
return 0;
}
if (store->tls_authenticate) { /* authentication only? */
sd->free_tls(); /* yes, stop tls */
}
}
Dmsg1(116, ">stored: %s", sd->msg);
if (sd->recv() <= 0) {
stop_bsock_timer(tid);
Jmsg3(jcr, M_FATAL, 0, _("bdird<stored: \"%s:%s\" bad response to Hello command: ERR=%s\n"),
sd->who(), sd->host(), sd->bstrerror());
return 0;
}
Dmsg1(110, "<stored: %s", sd->msg);
stop_bsock_timer(tid);
if (!bstrncmp(sd->msg, OKhello, sizeof(OKhello))) {
Dmsg0(dbglvl, _("Storage daemon rejected Hello command\n"));
Jmsg2(jcr, M_FATAL, 0, _("Storage daemon at \"%s:%d\" rejected Hello command\n"),
sd->host(), sd->port());
return 0;
}
return 1;
}
void b_free_jcr(const char *file, int line, JCR *jcr)
{
struct s_last_job *je;
Dmsg3(dbglvl, "Enter free_jcr jid=%u from %s:%d\n", jcr->JobId, file, line);
#else
void free_jcr(JCR *jcr)
{
struct s_last_job *je;
Dmsg3(dbglvl, "Enter free_jcr jid=%u use_count=%d Job=%s\n",
jcr->JobId, jcr->use_count(), jcr->Job);
#endif
lock_jcr_chain();
jcr->dec_use_count(); /* decrement use count */
if (jcr->use_count() < 0) {
Jmsg2(jcr, M_ERROR, 0, _("JCR use_count=%d JobId=%d\n"),
jcr->use_count(), jcr->JobId);
}
if (jcr->JobId > 0) {
Dmsg3(dbglvl, "Dec free_jcr jid=%u use_count=%d Job=%s\n",
jcr->JobId, jcr->use_count(), jcr->Job);
}
if (jcr->use_count() > 0) { /* if in use */
unlock_jcr_chain();
return;
}
if (jcr->JobId > 0) {
Dmsg3(dbglvl, "remove jcr jid=%u use_count=%d Job=%s\n",
jcr->JobId, jcr->use_count(), jcr->Job);
}
remove_jcr(jcr); /* remove Jcr from chain */
unlock_jcr_chain();
dequeue_messages(jcr);
job_end_pop(jcr); /* pop and call hooked routines */
Dmsg1(dbglvl, "End job=%d\n", jcr->JobId);
/*
* Keep some statistics
*/
switch (jcr->getJobType()) {
case JT_BACKUP:
case JT_VERIFY:
case JT_RESTORE:
case JT_MIGRATE:
case JT_COPY:
case JT_ADMIN:
/*
* Keep list of last jobs, but not Console where JobId==0
*/
if (jcr->JobId > 0) {
lock_last_jobs_list();
num_jobs_run++;
je = (struct s_last_job *)malloc(sizeof(struct s_last_job));
memset(je, 0, sizeof(struct s_last_job)); /* zero in case unset fields */
je->Errors = jcr->JobErrors;
je->JobType = jcr->getJobType();
je->JobId = jcr->JobId;
je->VolSessionId = jcr->VolSessionId;
je->VolSessionTime = jcr->VolSessionTime;
bstrncpy(je->Job, jcr->Job, sizeof(je->Job));
je->JobFiles = jcr->JobFiles;
je->JobBytes = jcr->JobBytes;
je->JobStatus = jcr->JobStatus;
je->JobLevel = jcr->getJobLevel();
je->start_time = jcr->start_time;
je->end_time = time(NULL);
if (!last_jobs) {
init_last_jobs_list();
}
last_jobs->append(je);
if (last_jobs->size() > max_last_jobs) {
je = (struct s_last_job *)last_jobs->first();
last_jobs->remove(je);
free(je);
}
unlock_last_jobs_list();
}
break;
default:
break;
}
close_msg(jcr); /* close messages for this job */
if (jcr->daemon_free_jcr) {
jcr->daemon_free_jcr(jcr); /* call daemon free routine */
}
free_common_jcr(jcr);
close_msg(NULL); /* flush any daemon messages */
Dmsg0(dbglvl, "Exit free_jcr\n");
}
/*
* Remove jcr from thread specific data, but
* but make sure it is us who are attached.
*/
void remove_jcr_from_tsd(JCR *jcr)
{
JCR *tjcr = get_jcr_from_tsd();
if (tjcr == jcr) {
set_jcr_in_tsd(INVALID_JCR);
}
}
/*
* See who is connecting and lookup the authentication information.
* First make him prove his identity and then prove our identity to the Remote daemon.
*/
static inline bool two_way_authenticate(int rcode, BSOCK *bs, JCR* jcr)
{
POOLMEM *dirname = get_pool_memory(PM_MESSAGE);
DIRRES *director = NULL;
int tls_local_need = BNET_TLS_NONE;
int tls_remote_need = BNET_TLS_NONE;
bool compatible = true; /* Want md5 compatible DIR */
bool auth_success = false;
alist *verify_list = NULL;
btimer_t *tid = NULL;
if (rcode != R_DIRECTOR) {
Dmsg1(dbglvl, "I only authenticate directors, not %d\n", rcode);
Jmsg1(jcr, M_FATAL, 0, _("I only authenticate directors, not %d\n"), rcode);
goto auth_fatal;
}
if (bs->msglen < 25 || bs->msglen > 500) {
Dmsg2(dbglvl, "Bad Hello command from Director at %s. Len=%d.\n",
bs->who(), bs->msglen);
char addr[64];
char *who = bnet_get_peer(bs, addr, sizeof(addr)) ? bs->who() : addr;
Jmsg2(jcr, M_FATAL, 0, _("Bad Hello command from Director at %s. Len=%d.\n"),
who, bs->msglen);
goto auth_fatal;
}
dirname = check_pool_memory_size(dirname, bs->msglen);
if (sscanf(bs->msg, "Hello Director %s calling", dirname) != 1) {
char addr[64];
char *who = bnet_get_peer(bs, addr, sizeof(addr)) ? bs->who() : addr;
bs->msg[100] = 0;
Dmsg2(dbglvl, "Bad Hello command from Director at %s: %s\n",
bs->who(), bs->msg);
Jmsg2(jcr, M_FATAL, 0, _("Bad Hello command from Director at %s: %s\n"),
who, bs->msg);
goto auth_fatal;
}
unbash_spaces(dirname);
foreach_res(director, R_DIRECTOR) {
if (bstrcmp(director->hdr.name, dirname))
break;
}
if (!director) {
char addr[64];
char *who = bnet_get_peer(bs, addr, sizeof(addr)) ? bs->who() : addr;
Jmsg2(jcr, M_FATAL, 0, _("Connection from unknown Director %s at %s rejected.\n"),
dirname, who);
goto auth_fatal;
}
if (have_tls) {
/*
* TLS Requirement
*/
if (director->tls_enable) {
if (director->tls_require) {
tls_local_need = BNET_TLS_REQUIRED;
} else {
tls_local_need = BNET_TLS_OK;
}
}
if (director->tls_authenticate) {
tls_local_need = BNET_TLS_REQUIRED;
}
if (director->tls_verify_peer) {
verify_list = director->tls_allowed_cns;
}
}
/*
* Timeout Hello after 10 min
*/
tid = start_bsock_timer(bs, AUTH_TIMEOUT);
/*
* Sanity check.
*/
ASSERT(director->password.encoding == p_encoding_md5);
/*
* Challenge the director
*/
auth_success = cram_md5_challenge(bs, director->password.value, tls_local_need, compatible);
if (job_canceled(jcr)) {
auth_success = false;
goto auth_fatal; /* quick exit */
}
if (auth_success) {
auth_success = cram_md5_respond(bs, director->password.value, &tls_remote_need, &compatible);
if (!auth_success) {
char addr[64];
char *who = bnet_get_peer(bs, addr, sizeof(addr)) ? bs->who() : addr;
Dmsg1(dbglvl, "cram_get_auth failed for %s\n", who);
}
} else {
char addr[64];
char *who = bnet_get_peer(bs, addr, sizeof(addr)) ? bs->who() : addr;
Dmsg1(dbglvl, "cram_auth failed for %s\n", who);
}
if (!auth_success) {
Emsg1(M_FATAL, 0, _("Incorrect password given by Director at %s.\n"),
bs->who());
goto auth_fatal;
}
/*
* Verify that the remote host is willing to meet our TLS requirements
*/
if (tls_remote_need < tls_local_need && tls_local_need != BNET_TLS_OK && tls_remote_need != BNET_TLS_OK) {
Jmsg0(jcr, M_FATAL, 0, _("Authorization problem: Remote server did not"
" advertize required TLS support.\n"));
Dmsg2(dbglvl, "remote_need=%d local_need=%d\n", tls_remote_need, tls_local_need);
auth_success = false;
goto auth_fatal;
}
/*
* Verify that we are willing to meet the remote host's requirements
*/
if (tls_remote_need > tls_local_need && tls_local_need != BNET_TLS_OK && tls_remote_need != BNET_TLS_OK) {
Jmsg0(jcr, M_FATAL, 0, _("Authorization problem: Remote server requires TLS.\n"));
Dmsg2(dbglvl, "remote_need=%d local_need=%d\n", tls_remote_need, tls_local_need);
auth_success = false;
goto auth_fatal;
}
if (tls_local_need >= BNET_TLS_OK && tls_remote_need >= BNET_TLS_OK) {
/*
* Engage TLS! Full Speed Ahead!
*/
if (!bnet_tls_server(director->tls_ctx, bs, verify_list)) {
Jmsg0(jcr, M_FATAL, 0, _("TLS negotiation failed.\n"));
auth_success = false;
goto auth_fatal;
}
if (director->tls_authenticate) { /* authentication only? */
bs->free_tls(); /* shutodown tls */
}
}
auth_fatal:
if (tid) {
stop_bsock_timer(tid);
tid = NULL;
}
free_pool_memory(dirname);
jcr->director = director;
/*
* Single thread all failures to avoid DOS
*/
if (!auth_success) {
P(mutex);
bmicrosleep(6, 0);
V(mutex);
}
return auth_success;
}
/*
* Note!!!! Part numbers now begin at 1. The part number is
* suppressed from the first part, which is just the Volume
* name. Each subsequent part is the Volumename.partnumber.
*
* Write a part (Vol, Vol.2, ...) from the spool to the DVD
* This routine does not update the part number, so normally, you
* should call open_next_part()
*
* It is also called from truncate_dvd to "blank" the medium, as
* well as from block.c when the DVD is full to write the last part.
*/
bool dvd_write_part(DCR *dcr)
{
DEVICE *dev = dcr->dev;
POOL_MEM archive_name(PM_FNAME);
/*
* Don't write empty part files.
* This is only useful when growisofs does not support write beyond
* the 4GB boundary.
* Example :
* - 3.9 GB on the volume, dvd-freespace reports 0.4 GB free
* - Write 0.2 GB on the volume, Bacula thinks it could still
* append data, it creates a new empty part.
* - dvd-freespace reports 0 GB free, as the 4GB boundary has
* been crossed
* - Bacula thinks he must finish to write to the device, so it
* tries to write the last part (0-byte), but dvd-writepart fails...
*
* There is one exception: when recycling a volume, we write a blank part
* file, so, then, we need to accept to write it.
*/
if (dev->part_size == 0 && !dev->truncating) {
Dmsg2(29, "dvd_write_part: device is %s, won't write blank part %d\n", dev->print_name(), dev->part);
/* Delete spool file */
make_spooled_dvd_filename(dev, archive_name);
unlink(archive_name.c_str());
dev->set_part_spooled(false);
Dmsg1(29, "========= unlink(%s)\n", archive_name.c_str());
Dsm_check(400);
return true;
}
POOL_MEM ocmd(PM_FNAME);
POOL_MEM results(PM_MESSAGE);
char* icmd;
int status;
int timeout;
char ed1[50];
dev->clear_freespace_ok(); /* need to update freespace */
Dsm_check(400);
Dmsg3(29, "dvd_write_part: device is %s, part is %d, is_mounted=%d\n", dev->print_name(), dev->part, dev->is_mounted());
icmd = dev->device->write_part_command;
dev->edit_mount_codes(ocmd, icmd);
/*
* original line follows
* timeout = dev->max_open_wait + (dev->max_part_size/(1350*1024/2));
* I modified this for a longer timeout; pre-formatting, blanking and
* writing can take quite a while
*/
/* Explanation of the timeout value, when writing the first part,
* by Arno Lehmann :
* 9 GB, write speed 1x: 6990 seconds (almost 2 hours...)
* Overhead: 900 seconds (starting, initializing, finalizing,probably
* reloading 15 minutes)
* Sum: 15780.
* A reasonable last-exit timeout would be 16000 seconds. Quite long -
* almost 4.5 hours, but hopefully, that timeout will only ever be needed
* in case of a serious emergency.
*/
if (dev->part == 1) {
timeout = 16000;
} else {
timeout = dev->max_open_wait + (dev->part_size/(1350*1024/4));
}
Dmsg2(20, "Write part: cmd=%s timeout=%d\n", ocmd.c_str(), timeout);
status = run_program_full_output(ocmd.c_str(), timeout, results.addr());
Dmsg2(20, "Write part status=%d result=%s\n", status, results.c_str());
dev->blank_dvd = false;
if (status != 0) {
Jmsg2(dcr->jcr, M_FATAL, 0, _("Error writing part %d to the DVD: ERR=%s\n"),
dev->part, results.c_str());
Mmsg1(dev->errmsg, _("Error while writing current part to the DVD: %s"),
results.c_str());
Dmsg1(100, "%s\n", dev->errmsg);
dev->dev_errno = EIO;
if (!dev->truncating) {
dcr->mark_volume_in_error();
}
Dsm_check(400);
return false;
}
Jmsg(dcr->jcr, M_INFO, 0, _("Part %d (%lld bytes) written to DVD.\n"), dev->part, dev->part_size);
Dmsg3(400, "dvd_write_part: Part %d (%lld bytes) written to DVD\nResults: %s\n",
dev->part, dev->part_size, results.c_str());
dev->num_dvd_parts++; /* there is now one more part on DVD */
dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
dcr->VolCatInfo.VolCatParts = dev->num_dvd_parts;
Dmsg1(100, "Update num_parts=%d\n", dev->num_dvd_parts);
/* Delete spool file */
make_spooled_dvd_filename(dev, archive_name);
unlink(archive_name.c_str());
dev->set_part_spooled(false);
Dmsg1(29, "========= unlink(%s)\n", archive_name.c_str());
Dsm_check(400);
/* growisofs umounted the device, so remount it (it will update the free space) */
dev->clear_mounted();
dev->mount(1);
Jmsg(dcr->jcr, M_INFO, 0, _("Remaining free space %s on %s\n"),
edit_uint64_with_commas(dev->free_space, ed1), dev->print_name());
Dsm_check(400);
return true;
}
int DCR::check_volume_label(bool &ask, bool &autochanger)
{
int vol_label_status;
/*
* If we are writing to a stream device, ASSUME the volume label
* is correct.
*/
if (dev->has_cap(CAP_STREAM)) {
vol_label_status = VOL_OK;
create_volume_label(dev, VolumeName, "Default", false /* not DVD */);
dev->VolHdr.LabelType = PRE_LABEL;
} else {
vol_label_status = read_dev_volume_label(this);
}
if (job_canceled(jcr)) {
goto check_bail_out;
}
Dmsg2(150, "Want dirVol=%s dirStat=%s\n", VolumeName,
VolCatInfo.VolCatStatus);
/*
* At this point, dev->VolCatInfo has what is in the drive, if anything,
* and dcr->VolCatInfo has what the Director wants.
*/
switch (vol_label_status) {
case VOL_OK:
Dmsg1(150, "Vol OK name=%s\n", dev->VolHdr.VolumeName);
dev->VolCatInfo = VolCatInfo; /* structure assignment */
break; /* got a Volume */
case VOL_NAME_ERROR:
VOLUME_CAT_INFO dcrVolCatInfo, devVolCatInfo;
char saveVolumeName[MAX_NAME_LENGTH];
Dmsg2(150, "Vol NAME Error Have=%s, want=%s\n", dev->VolHdr.VolumeName, VolumeName);
if (dev->is_volume_to_unload()) {
ask = true;
goto check_next_volume;
}
/* If not removable, Volume is broken */
if (!dev->is_removable()) {
Jmsg(jcr, M_WARNING, 0, _("Volume \"%s\" not on device %s.\n"),
VolumeName, dev->print_name());
mark_volume_in_error();
goto check_next_volume;
}
/*
* OK, we got a different volume mounted. First save the
* requested Volume info (dcr) structure, then query if
* this volume is really OK. If not, put back the desired
* volume name, mark it not in changer and continue.
*/
dcrVolCatInfo = VolCatInfo; /* structure assignment */
devVolCatInfo = dev->VolCatInfo; /* structure assignment */
/* Check if this is a valid Volume in the pool */
bstrncpy(saveVolumeName, VolumeName, sizeof(saveVolumeName));
bstrncpy(VolumeName, dev->VolHdr.VolumeName, sizeof(VolumeName));
if (!dir_get_volume_info(this, GET_VOL_INFO_FOR_WRITE)) {
POOL_MEM vol_info_msg;
pm_strcpy(vol_info_msg, jcr->dir_bsock->msg); /* save error message */
/* Restore desired volume name, note device info out of sync */
/* This gets the info regardless of the Pool */
bstrncpy(VolumeName, dev->VolHdr.VolumeName, sizeof(VolumeName));
if (autochanger && !dir_get_volume_info(this, GET_VOL_INFO_FOR_READ)) {
/*
* If we get here, we know we cannot write on the Volume,
* and we know that we cannot read it either, so it
* is not in the autochanger.
*/
mark_volume_not_inchanger();
}
dev->VolCatInfo = devVolCatInfo; /* structure assignment */
dev->set_unload(); /* unload this volume */
Jmsg(jcr, M_WARNING, 0, _("Director wanted Volume \"%s\".\n"
" Current Volume \"%s\" not acceptable because:\n"
" %s"),
dcrVolCatInfo.VolCatName, dev->VolHdr.VolumeName,
vol_info_msg.c_str());
ask = true;
/* Restore saved DCR before continuing */
bstrncpy(VolumeName, saveVolumeName, sizeof(VolumeName));
VolCatInfo = dcrVolCatInfo; /* structure assignment */
goto check_next_volume;
}
/*
* This was not the volume we expected, but it is OK with
* the Director, so use it.
*/
Dmsg1(150, "Got new Volume name=%s\n", VolumeName);
dev->VolCatInfo = VolCatInfo; /* structure assignment */
Dmsg1(100, "Call reserve_volume=%s\n", dev->VolHdr.VolumeName);
if (reserve_volume(this, dev->VolHdr.VolumeName) == NULL) {
Jmsg2(jcr, M_WARNING, 0, _("Could not reserve volume %s on %s\n"),
dev->VolHdr.VolumeName, dev->print_name());
ask = true;
goto check_next_volume;
}
break; /* got a Volume */
/*
* At this point, we assume we have a blank tape mounted.
*/
case VOL_IO_ERROR:
if (dev->is_dvd()) {
Jmsg(jcr, M_FATAL, 0, "%s", jcr->errmsg);
mark_volume_in_error();
goto check_bail_out; /* we could not write on DVD */
}
/* Fall through wanted */
case VOL_NO_LABEL:
switch (try_autolabel(true)) {
case try_next_vol:
goto check_next_volume;
case try_read_vol:
goto check_read_volume;
case try_error:
goto check_bail_out;
case try_default:
break;
}
/* NOTE! Fall-through wanted. */
case VOL_NO_MEDIA:
default:
Dmsg0(200, "VOL_NO_MEDIA or default.\n");
/* Send error message */
if (!dev->poll) {
} else {
Dmsg1(200, "Msg suppressed by poll: %s\n", jcr->errmsg);
}
ask = true;
/* Needed, so the medium can be changed */
if (dev->requires_mount()) {
dev->close();
}
goto check_next_volume;
}
return check_ok;
check_next_volume:
return check_next_vol;
check_bail_out:
return check_error;
check_read_volume:
return check_read_vol;
}
/**
* Set file modes, permissions and times
*
* fname is the original filename
* ofile is the output filename (may be in a different directory)
*
* Returns: true on success
* false on failure
*/
bool set_attributes(JCR *jcr, ATTR *attr, BFILE *ofd)
{
struct utimbuf ut;
mode_t old_mask;
bool ok = true;
boffset_t fsize;
if (uid_set) {
my_uid = getuid();
my_gid = getgid();
uid_set = true;
}
#if defined(HAVE_WIN32)
if (attr->stream == STREAM_UNIX_ATTRIBUTES_EX &&
set_win32_attributes(jcr, attr, ofd)) {
if (is_bopen(ofd)) {
bclose(ofd);
}
pm_strcpy(attr->ofname, "*none*");
return true;
}
if (attr->data_stream == STREAM_WIN32_DATA ||
attr->data_stream == STREAM_WIN32_GZIP_DATA ||
attr->data_stream == STREAM_WIN32_COMPRESSED_DATA) {
if (is_bopen(ofd)) {
bclose(ofd);
}
pm_strcpy(attr->ofname, "*none*");
return true;
}
/**
* If Windows stuff failed, e.g. attempt to restore Unix file
* to Windows, simply fall through and we will do it the
* universal way.
*/
#endif
old_mask = umask(0);
if (is_bopen(ofd)) {
char ec1[50], ec2[50];
fsize = blseek(ofd, 0, SEEK_END);
bclose(ofd); /* first close file */
if (attr->type == FT_REG && fsize > 0 && attr->statp.st_size > 0 &&
fsize != (boffset_t)attr->statp.st_size) {
Jmsg3(jcr, M_ERROR, 0, _("File size of restored file %s not correct. Original %s, restored %s.\n"),
attr->ofname, edit_uint64(attr->statp.st_size, ec1),
edit_uint64(fsize, ec2));
}
}
/**
* We do not restore sockets, so skip trying to restore their
* attributes.
*/
if (attr->type == FT_SPEC && S_ISSOCK(attr->statp.st_mode)) {
goto bail_out;
}
ut.actime = attr->statp.st_atime;
ut.modtime = attr->statp.st_mtime;
/* ***FIXME**** optimize -- don't do if already correct */
/**
* For link, change owner of link using lchown, but don't
* try to do a chmod as that will update the file behind it.
*/
if (attr->type == FT_LNK) {
/** Change owner of link, not of real file */
if (lchown(attr->ofname, attr->statp.st_uid, attr->statp.st_gid) < 0 && my_uid == 0) {
berrno be;
Jmsg2(jcr, M_ERROR, 0, _("Unable to set file owner %s: ERR=%s\n"),
attr->ofname, be.bstrerror());
ok = false;
}
} else {
if (chown(attr->ofname, attr->statp.st_uid, attr->statp.st_gid) < 0 && my_uid == 0) {
berrno be;
Jmsg2(jcr, M_ERROR, 0, _("Unable to set file owner %s: ERR=%s\n"),
attr->ofname, be.bstrerror());
ok = false;
}
if (chmod(attr->ofname, attr->statp.st_mode) < 0 && my_uid == 0) {
berrno be;
Jmsg2(jcr, M_ERROR, 0, _("Unable to set file modes %s: ERR=%s\n"),
attr->ofname, be.bstrerror());
ok = false;
}
/**
* Reset file times.
*/
if (utime(attr->ofname, &ut) < 0 && my_uid == 0) {
berrno be;
Jmsg2(jcr, M_ERROR, 0, _("Unable to set file times %s: ERR=%s\n"),
attr->ofname, be.bstrerror());
ok = false;
}
#ifdef HAVE_CHFLAGS
/**
* FreeBSD user flags
*
* Note, this should really be done before the utime() above,
* but if the immutable bit is set, it will make the utimes()
* fail.
*/
if (chflags(attr->ofname, attr->statp.st_flags) < 0 && my_uid == 0) {
berrno be;
Jmsg2(jcr, M_ERROR, 0, _("Unable to set file flags %s: ERR=%s\n"),
attr->ofname, be.bstrerror());
ok = false;
}
#endif
}
bail_out:
pm_strcpy(attr->ofname, "*none*");
umask(old_mask);
return ok;
}
/*
* See who is connecting and lookup the authentication information.
* First make him prove his identity and then prove our identity to the Remote daemon.
*/
static inline bool two_way_authenticate(int rcode, BSOCK *bs, JCR* jcr)
{
POOLMEM *dirname;
DIRRES *director = NULL;
int tls_local_need = BNET_TLS_NONE;
int tls_remote_need = BNET_TLS_NONE;
bool compatible = true; /* require md5 compatible DIR */
bool auth_success = false;
alist *verify_list = NULL;
if (rcode != R_DIRECTOR) {
Dmsg1(dbglvl, "I only authenticate Directors, not %d\n", rcode);
Jmsg1(jcr, M_FATAL, 0, _("I only authenticate Directors, not %d\n"), rcode);
return 0;
}
/*
* Sanity check.
*/
if (bs->msglen < 25 || bs->msglen > 500) {
Dmsg2(dbglvl, "Bad Hello command from Director at %s. Len=%d.\n",
bs->who(), bs->msglen);
Jmsg2(jcr, M_FATAL, 0, _("Bad Hello command from Director at %s. Len=%d.\n"),
bs->who(), bs->msglen);
return 0;
}
dirname = get_pool_memory(PM_MESSAGE);
dirname = check_pool_memory_size(dirname, bs->msglen);
if (sscanf(bs->msg, "Hello Director %127s calling", dirname) != 1) {
bs->msg[100] = 0;
Dmsg2(dbglvl, "Bad Hello command from Director at %s: %s\n",
bs->who(), bs->msg);
Jmsg2(jcr, M_FATAL, 0, _("Bad Hello command from Director at %s: %s\n"),
bs->who(), bs->msg);
return 0;
}
director = NULL;
unbash_spaces(dirname);
foreach_res(director, rcode) {
if (bstrcmp(director->hdr.name, dirname)) {
break;
}
}
if (!director) {
Dmsg2(dbglvl, "Connection from unknown Director %s at %s rejected.\n",
dirname, bs->who());
Jmsg(jcr, M_FATAL, 0, _("Connection from unknown Director %s at %s rejected.\n"
"Please see %s for help.\n"),
dirname, bs->who(), MANUAL_AUTH_URL);
free_pool_memory(dirname);
return 0;
}
/*
* TLS Requirement
*/
if (director->tls_enable) {
if (director->tls_require) {
tls_local_need = BNET_TLS_REQUIRED;
} else {
tls_local_need = BNET_TLS_OK;
}
}
if (director->tls_authenticate) {
tls_local_need = BNET_TLS_REQUIRED;
}
if (director->tls_verify_peer) {
verify_list = director->tls_allowed_cns;
}
ASSERT(director->password.encoding == p_encoding_md5);
/*
* Timeout Hello after 10 mins
*/
btimer_t *tid = start_bsock_timer(bs, AUTH_TIMEOUT);
auth_success = cram_md5_challenge(bs, director->password.value, tls_local_need, compatible);
if (auth_success) {
auth_success = cram_md5_respond(bs, director->password.value, &tls_remote_need, &compatible);
if (!auth_success) {
Dmsg1(dbglvl, "cram_get_auth failed with %s\n", bs->who());
}
} else {
Dmsg1(dbglvl, "cram_auth failed with %s\n", bs->who());
}
if (!auth_success) {
Jmsg(jcr, M_FATAL, 0, _("Incorrect password given by Director.\n"
"Please see %s for help.\n"), MANUAL_AUTH_URL);
auth_success = false;
goto auth_fatal;
}
/*
* Verify that the remote host is willing to meet our TLS requirements
*/
if (tls_remote_need < tls_local_need && tls_local_need != BNET_TLS_OK && tls_remote_need != BNET_TLS_OK) {
Jmsg0(jcr, M_FATAL, 0, _("Authorization problem: Remote server did not"
" advertize required TLS support.\n"));
Dmsg2(dbglvl, "remote_need=%d local_need=%d\n", tls_remote_need, tls_local_need);
auth_success = false;
goto auth_fatal;
}
/*
* Verify that we are willing to meet the remote host's requirements
*/
if (tls_remote_need > tls_local_need && tls_local_need != BNET_TLS_OK && tls_remote_need != BNET_TLS_OK) {
Jmsg0(jcr, M_FATAL, 0, _("Authorization problem: Remote server requires TLS.\n"));
Dmsg2(dbglvl, "remote_need=%d local_need=%d\n", tls_remote_need, tls_local_need);
auth_success = false;
goto auth_fatal;
}
if (tls_local_need >= BNET_TLS_OK && tls_remote_need >= BNET_TLS_OK) {
/*
* Engage TLS! Full Speed Ahead!
*/
if (!bnet_tls_server(director->tls_ctx, bs, verify_list)) {
Jmsg(jcr, M_FATAL, 0, _("TLS negotiation failed with DIR at \"%s:%d\"\n"),
bs->host(), bs->port());
auth_success = false;
goto auth_fatal;
}
if (director->tls_authenticate) { /* authenticate with tls only? */
bs->free_tls(); /* yes, shut it down */
}
}
auth_fatal:
stop_bsock_timer(tid);
free_pool_memory(dirname);
jcr->director = director;
return auth_success;
}
bool B_ACCURATE_LMDB::init(JCR *jcr, uint32_t nbfile)
{
int result;
MDB_env *env;
size_t mapsize = 10485760;
if (!m_db_env) {
result = mdb_env_create(&env);
if (result) {
Jmsg1(jcr, M_FATAL, 0, _("Unable to create MDB environment: %s\n"), mdb_strerror(result));
return false;
}
if ((nbfile * AVG_NR_BYTES_PER_ENTRY) > mapsize) {
size_t pagesize;
#ifdef HAVE_GETPAGESIZE
pagesize = getpagesize();
#else
pagesize = B_PAGE_SIZE;
#endif
mapsize = (((nbfile * AVG_NR_BYTES_PER_ENTRY) / pagesize) + 1) * pagesize;
}
result = mdb_env_set_mapsize(env, mapsize);
if (result) {
Jmsg1(jcr, M_FATAL, 0, _("Unable to set MDB mapsize: %s\n"), mdb_strerror(result));
goto bail_out;
}
/*
* Explicitly set the number of readers to 1.
*/
result = mdb_env_set_maxreaders(env, 1);
if (result) {
Jmsg1(jcr, M_FATAL, 0, _("Unable to set MDB maxreaders: %s\n"), mdb_strerror(result));
goto bail_out;
}
Mmsg(m_lmdb_name, "%s/.accurate_lmdb.%d", me->working_directory, jcr->JobId);
result = mdb_env_open(env, m_lmdb_name, MDB_NOSUBDIR | MDB_NOLOCK | MDB_NOSYNC, 0600);
if (result) {
Jmsg2(jcr, M_FATAL, 0, _("Unable create LDMD database %s: %s\n"), m_lmdb_name, mdb_strerror(result));
goto bail_out;
}
result = mdb_txn_begin(env, NULL, 0, &m_db_rw_txn);
if (result) {
Jmsg1(jcr, M_FATAL, 0, _("Unable to start a write transaction: %s\n"), mdb_strerror(result));
goto bail_out;
}
result = mdb_dbi_open(m_db_rw_txn, NULL, MDB_CREATE, &m_db_dbi);
if (result) {
Jmsg1(jcr, M_FATAL, 0, _("Unable to open LMDB internal database: %s\n"), mdb_strerror(result));
mdb_txn_abort(m_db_rw_txn);
m_db_rw_txn = NULL;
goto bail_out;
}
m_db_env = env;
}
if (!m_pay_load) {
m_pay_load = get_pool_memory(PM_MESSAGE);
}
if (!m_lmdb_name) {
m_pay_load = get_pool_memory(PM_FNAME);
}
if (!m_seen_bitmap) {
m_seen_bitmap = (char *)malloc(nbytes_for_bits(nbfile));
clear_all_bits(nbfile, m_seen_bitmap);
}
return true;
bail_out:
if (env) {
mdb_env_close(env);
}
return false;
}
/*
* 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;
}
