lazy_static = "1.4"
libc = "0.2"
nix = "0.24"
+log = "0.4"
openssl = "0.10"
percent-encoding = "2.1"
pin-project-lite = "0.2"
pub struct BackupWriter {
h2: H2Client,
abort: AbortHandle,
- verbose: bool,
crypt_config: Option<Arc<CryptConfig>>,
}
type UploadResultReceiver = oneshot::Receiver<Result<(), Error>>;
impl BackupWriter {
- fn new(
- h2: H2Client,
- abort: AbortHandle,
- crypt_config: Option<Arc<CryptConfig>>,
- verbose: bool,
- ) -> Arc<Self> {
+ fn new(h2: H2Client, abort: AbortHandle, crypt_config: Option<Arc<CryptConfig>>) -> Arc<Self> {
Arc::new(Self {
h2,
abort,
crypt_config,
- verbose,
})
}
.start_h2_connection(req, String::from(PROXMOX_BACKUP_PROTOCOL_ID_V1!()))
.await?;
- Ok(BackupWriter::new(h2, abort, crypt_config, debug))
+ Ok(BackupWriter::new(h2, abort, crypt_config))
}
pub async fn get(&self, path: &str, param: Option<Value>) -> Result<Value, Error> {
None
},
options.compress,
- self.verbose,
)
.await?;
let size_dirty = upload_stats.size - upload_stats.size_reused;
let size: HumanByte = upload_stats.size.into();
- let archive = if self.verbose {
+ let archive = if log::log_enabled!(log::Level::Debug) {
archive_name
} else {
pbs_tools::format::strip_server_file_extension(archive_name)
};
+
if archive_name != CATALOG_NAME {
let speed: HumanByte =
((size_dirty * 1_000_000) / (upload_stats.duration.as_micros() as usize)).into();
let size_dirty: HumanByte = size_dirty.into();
let size_compressed: HumanByte = upload_stats.size_compressed.into();
- println!(
+ log::info!(
"{}: had to backup {} of {} (compressed {}) in {:.2}s",
archive,
size_dirty,
size_compressed,
upload_stats.duration.as_secs_f64()
);
- println!("{}: average backup speed: {}/s", archive, speed);
+ log::info!("{}: average backup speed: {}/s", archive, speed);
} else {
- println!("Uploaded backup catalog ({})", size);
+ log::info!("Uploaded backup catalog ({})", size);
}
if upload_stats.size_reused > 0 && upload_stats.size > 1024 * 1024 {
let reused_percent = upload_stats.size_reused as f64 * 100. / upload_stats.size as f64;
let reused: HumanByte = upload_stats.size_reused.into();
- println!(
+ log::info!(
"{}: backup was done incrementally, reused {} ({:.1}%)",
- archive, reused, reused_percent
+ archive,
+ reused,
+ reused_percent
);
}
- if self.verbose && upload_stats.chunk_count > 0 {
- println!(
+ if log::log_enabled!(log::Level::Debug) && upload_stats.chunk_count > 0 {
+ log::debug!(
"{}: Reused {} from {} chunks.",
- archive, upload_stats.chunk_reused, upload_stats.chunk_count
+ archive,
+ upload_stats.chunk_reused,
+ upload_stats.chunk_count
);
- println!(
+ log::debug!(
"{}: Average chunk size was {}.",
archive,
HumanByte::from(upload_stats.size / upload_stats.chunk_count)
);
- println!(
+ log::debug!(
"{}: Average time per request: {} microseconds.",
archive,
(upload_stats.duration.as_micros()) / (upload_stats.chunk_count as u128)
})
}
- fn response_queue(
- verbose: bool,
- ) -> (
+ fn response_queue() -> (
mpsc::Sender<h2::client::ResponseFuture>,
oneshot::Receiver<Result<(), Error>>,
) {
response
.map_err(Error::from)
.and_then(H2Client::h2api_response)
- .map_ok(move |result| {
- if verbose {
- println!("RESPONSE: {:?}", result)
- }
- })
+ .map_ok(move |result| log::debug!("RESPONSE: {:?}", result))
.map_err(|err| format_err!("pipelined request failed: {}", err))
})
.map(|result| {
h2: H2Client,
wid: u64,
path: String,
- verbose: bool,
) -> (UploadQueueSender, UploadResultReceiver) {
let (verify_queue_tx, verify_queue_rx) = mpsc::channel(64);
let (verify_result_tx, verify_result_rx) = oneshot::channel();
digest_list.push(hex::encode(&digest));
offset_list.push(offset);
}
- if verbose { println!("append chunks list len ({})", digest_list.len()); }
+ log::debug!("append chunks list len ({})", digest_list.len());
let param = json!({ "wid": wid, "digest-list": digest_list, "offset-list": offset_list });
let request = H2Client::request_builder("localhost", "PUT", &path, None, Some("application/json")).unwrap();
let param_data = bytes::Bytes::from(param.to_string().into_bytes());
known_chunks.insert(*index.index_digest(i).unwrap());
}
- if self.verbose {
- println!(
- "{}: known chunks list length is {}",
- archive_name,
- index.index_count()
- );
- }
+ log::debug!(
+ "{}: known chunks list length is {}",
+ archive_name,
+ index.index_count()
+ );
Ok(index)
}
known_chunks.insert(*index.index_digest(i).unwrap());
}
- if self.verbose {
- println!(
- "{}: known chunks list length is {}",
- archive_name,
- index.index_count()
- );
- }
+ log::debug!(
+ "{}: known chunks list length is {}",
+ archive_name,
+ index.index_count()
+ );
Ok(index)
}
known_chunks: Arc<Mutex<HashSet<[u8; 32]>>>,
crypt_config: Option<Arc<CryptConfig>>,
compress: bool,
- verbose: bool,
) -> impl Future<Output = Result<UploadStats, Error>> {
let total_chunks = Arc::new(AtomicUsize::new(0));
let total_chunks2 = total_chunks.clone();
let is_fixed_chunk_size = prefix == "fixed";
let (upload_queue, upload_result) =
- Self::append_chunk_queue(h2.clone(), wid, append_chunk_path, verbose);
+ Self::append_chunk_queue(h2.clone(), wid, append_chunk_path);
let start_time = std::time::Instant::now();
let digest = chunk_info.digest;
let digest_str = hex::encode(&digest);
- /* too verbose, needs finer verbosity setting granularity
- if verbose {
- println!("upload new chunk {} ({} bytes, offset {})", digest_str,
- chunk_info.chunk_len, offset);
- }
- */
+ log::trace!(
+ "upload new chunk {} ({} bytes, offset {})",
+ digest_str,
+ chunk_info.chunk_len,
+ offset
+ );
let chunk_data = chunk_info.chunk.into_inner();
let param = json!({
}
/// Upload speed test - prints result to stderr
- pub async fn upload_speedtest(&self, verbose: bool) -> Result<f64, Error> {
+ pub async fn upload_speedtest(&self) -> Result<f64, Error> {
let mut data = vec![];
// generate pseudo random byte sequence
for i in 0..1024 * 1024 {
let mut repeat = 0;
- let (upload_queue, upload_result) = Self::response_queue(verbose);
+ let (upload_queue, upload_result) = Self::response_queue();
let start_time = std::time::Instant::now();
break;
}
- if verbose {
- eprintln!("send test data ({} bytes)", data.len());
- }
+ log::debug!("send test data ({} bytes)", data.len());
let request =
H2Client::request_builder("localhost", "POST", "speedtest", None, None).unwrap();
let request_future = self
let _ = upload_result.await?;
- eprintln!(
+ log::info!(
"Uploaded {} chunks in {} seconds.",
repeat,
start_time.elapsed().as_secs()
);
let speed = ((item_len * (repeat as usize)) as f64) / start_time.elapsed().as_secs_f64();
- eprintln!(
+ log::info!(
"Time per request: {} microseconds.",
(start_time.elapsed().as_micros()) / (repeat as u128)
);
match shell.complete_path(complete_me) {
Ok(list) => list,
Err(err) => {
- eprintln!("error during completion: {}", err);
+ log::error!("error during completion: {}", err);
Vec::new()
}
}
let args = match cli::shellword_split(&line) {
Ok(args) => args,
Err(err) => {
- println!("Error: {}", err);
+ log::error!("Error: {}", err);
continue;
}
};
if let Err(err) =
store_fingerprint(prefix.as_ref().unwrap(), &server, &fingerprint)
{
- eprintln!("{}", err);
+ log::error!("{}", err);
}
}
*verified_fingerprint.lock().unwrap() = Some(fingerprint);
true
}
Err(err) => {
- eprintln!("certificate validation failed - {}", err);
+ log::error!("certificate validation failed - {}", err);
false
}
},
*auth2.write().unwrap() = auth;
}
Err(err) => {
- eprintln!("re-authentication failed: {}", err);
+ log::error!("re-authentication failed: {}", err);
return;
}
}
if expected_fingerprint == fp_string {
return Ok(Some(fp_string));
} else {
- eprintln!("WARNING: certificate fingerprint does not match expected fingerprint!");
- eprintln!("expected: {}", expected_fingerprint);
+ log::warn!("WARNING: certificate fingerprint does not match expected fingerprint!");
+ log::warn!("expected: {}", expected_fingerprint);
}
}
// If we're on a TTY, query the user
if interactive && tty::stdin_isatty() {
- eprintln!("fingerprint: {}", fp_string);
+ log::info!("fingerprint: {}", fp_string);
loop {
eprint!("Are you sure you want to continue connecting? (y/n): ");
let _ = std::io::stdout().flush();
.handshake(upgraded)
.await?;
- let connection = connection.map_err(|_| eprintln!("HTTP/2.0 connection failed"));
+ let connection = connection.map_err(|_| log::error!("HTTP/2.0 connection failed"));
let (connection, abort) = futures::future::abortable(connection);
// A cancellable future returns an Option which is None when cancelled and
pub entries_max: usize,
/// Skip lost+found directory
pub skip_lost_and_found: bool,
- /// Verbose output
- pub verbose: bool,
}
fn detect_fs_type(fd: RawFd) -> Result<i64, Error> {
}
/// Creates a tar file from `path` and writes it into `output`
-pub async fn create_tar<T, W, P>(
- output: W,
- accessor: Accessor<T>,
- path: P,
- verbose: bool,
-) -> Result<(), Error>
+pub async fn create_tar<T, W, P>(output: W, accessor: Accessor<T>, path: P) -> Result<(), Error>
where
T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
W: tokio::io::AsyncWrite + Unpin + Send + 'static,
let metadata = realfile.entry().metadata();
let realpath = Path::new(link);
- if verbose {
- eprintln!("adding '{}' to tar", path.display());
- }
+ log::debug!("adding '{}' to tar", path.display());
let stripped_path = match realpath.strip_prefix(prefix) {
Ok(path) => path,
}
}
EntryKind::Symlink(link) if !link.data.is_empty() => {
- if verbose {
- eprintln!("adding '{}' to tar", path.display());
- }
+ log::debug!("adding '{}' to tar", path.display());
let realpath = Path::new(link);
let mut header = tar::Header::new_gnu();
header.set_entry_type(tar::EntryType::Symlink);
.map_err(|err| format_err!("could not send symlink entry: {}", err))?;
}
EntryKind::Fifo => {
- if verbose {
- eprintln!("adding '{}' to tar", path.display());
- }
+ log::debug!("adding '{}' to tar", path.display());
let mut header = tar::Header::new_gnu();
header.set_entry_type(tar::EntryType::Fifo);
add_metadata_to_header(&mut header, metadata);
.map_err(|err| format_err!("could not send fifo entry: {}", err))?;
}
EntryKind::Directory => {
- if verbose {
- eprintln!("adding '{}' to tar", path.display());
- }
+ log::debug!("adding '{}' to tar", path.display());
// we cannot add the root path itself
if path != Path::new("/") {
let mut header = tar::Header::new_gnu();
}
}
EntryKind::Device(device) => {
- if verbose {
- eprintln!("adding '{}' to tar", path.display());
- }
+ log::debug!("adding '{}' to tar", path.display());
let entry_type = if metadata.stat.is_chardev() {
tar::EntryType::Char
} else {
}
tarencoder.finish().await.map_err(|err| {
- eprintln!("error during finishing of zip: {}", err);
+ log::error!("error during finishing of zip: {}", err);
err
})?;
Ok(())
}
-pub async fn create_zip<T, W, P>(
- output: W,
- accessor: Accessor<T>,
- path: P,
- verbose: bool,
-) -> Result<(), Error>
+pub async fn create_zip<T, W, P>(output: W, accessor: Accessor<T>, path: P) -> Result<(), Error>
where
T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
W: tokio::io::AsyncWrite + Unpin + Send + 'static,
match entry.kind() {
EntryKind::File { .. } => {
- if verbose {
- eprintln!("adding '{}' to zip", path.display());
- }
+ log::debug!("adding '{}' to zip", path.display());
let entry = ZipEntry::new(
path,
metadata.stat.mtime.secs,
.ok_or(format_err!("error looking up '{:?}'", path))?;
let realfile = accessor.follow_hardlink(&entry).await?;
let metadata = realfile.entry().metadata();
- if verbose {
- eprintln!("adding '{}' to zip", path.display());
- }
+ log::debug!("adding '{}' to zip", path.display());
let entry = ZipEntry::new(
path,
metadata.stat.mtime.secs,
.map_err(|err| format_err!("could not send file entry: {}", err))?;
}
EntryKind::Directory => {
- if verbose {
- eprintln!("adding '{}' to zip", path.display());
- }
+ log::debug!("adding '{}' to zip", path.display());
let entry = ZipEntry::new(
path,
metadata.stat.mtime.secs,
destination: DEST,
decoder: Accessor<T>,
path: PATH,
- verbose: bool,
) -> Result<(), Error>
where
T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
.await?
.ok_or(format_err!("error opening '{:?}'", path.as_ref()))?;
- recurse_files_extractor(&mut extractor, file, verbose).await
+ recurse_files_extractor(&mut extractor, file).await
}
pub async fn extract_sub_dir_seq<S, DEST>(
destination: DEST,
mut decoder: Decoder<S>,
- verbose: bool,
) -> Result<(), Error>
where
S: pxar::decoder::SeqRead + Unpin + Send + 'static,
let mut extractor = get_extractor(destination, root.metadata().clone())?;
- if let Err(err) = seq_files_extractor(&mut extractor, decoder, verbose).await {
- eprintln!("error extracting pxar archive: {}", err);
+ if let Err(err) = seq_files_extractor(&mut extractor, decoder).await {
+ log::error!("error extracting pxar archive: {}", err);
}
Ok(())
async fn recurse_files_extractor<'a, T>(
extractor: &'a mut Extractor,
file: FileEntry<T>,
- verbose: bool,
) -> Result<(), Error>
where
T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
let metadata = entry.metadata();
let (file_name_os, file_name) = get_filename(entry)?;
- if verbose {
- eprintln!("extracting: {}", file.path().display());
- }
+ log::debug!("extracting: {}", file.path().display());
match file.kind() {
EntryKind::Directory => {
let dir = file.enter_directory().await?;
let mut seq_decoder = dir.decode_full().await?;
seq_decoder.enable_goodbye_entries(true);
- seq_files_extractor(extractor, seq_decoder, verbose).await?;
+ seq_files_extractor(extractor, seq_decoder).await?;
extractor.leave_directory()?;
}
EntryKind::File { size, .. } => {
async fn seq_files_extractor<'a, T>(
extractor: &'a mut Extractor,
mut decoder: pxar::decoder::aio::Decoder<T>,
- verbose: bool,
) -> Result<(), Error>
where
T: pxar::decoder::SeqRead,
let metadata = entry.metadata();
let (file_name_os, file_name) = get_filename(&entry)?;
- if verbose && !matches!(entry.kind(), EntryKind::GoodbyeTable) {
- eprintln!("extracting: {}", entry.path().display());
+ if !matches!(entry.kind(), EntryKind::GoodbyeTable) {
+ log::debug!("extracting: {}", entry.path().display());
}
if let Err(err) = async {
.await
{
let display = entry.path().display().to_string();
- eprintln!(
+ log::error!(
"error extracting {}: {}",
if matches!(entry.kind(), EntryKind::GoodbyeTable) {
"<directory>"
/// Here's how we deal with errors:
///
- /// Any error will be printed if the verbose flag was set, otherwise the message will be
- /// silently dropped.
+ /// Any error will be logged if a log level of at least 'debug' was set, otherwise the
+ /// message will be silently dropped.
///
/// Opaque errors will cause the fuse main loop to bail out with that error.
///
) {
let final_result = match err.downcast::<io::Error>() {
Ok(err) => {
- if err.kind() == io::ErrorKind::Other && self.verbose {
- eprintln!("an IO error occurred: {}", err);
+ if err.kind() == io::ErrorKind::Other {
+ log::error!("an IO error occurred: {}", err);
}
// fail the request
}
Err(err) => {
// `bail` (non-`io::Error`) is used for fatal errors which should actually cancel:
- if self.verbose {
- eprintln!("internal error: {}, bailing out", err);
- }
+ log::error!("internal error: {}, bailing out", err);
Err(err)
}
};
},
err = err_recv.next() => match err {
Some(err) => if self.verbose {
- eprintln!("cancelling fuse main loop due to error: {}", err);
+ log::error!("cancelling fuse main loop due to error: {}", err);
return Err(err);
},
None => panic!("error channel was closed unexpectedly"),
}
}
other => {
- if self.verbose {
- eprintln!("Received unexpected fuse request");
- }
+ log::error!("Received unexpected fuse request");
other.fail(libc::ENOSYS).map_err(Error::from)
}
};
}
if !xattr::is_valid_xattr_name(xattr.name()) {
- eprintln!("skipping invalid xattr named {:?}", xattr.name());
+ log::info!("skipping invalid xattr named {:?}", xattr.name());
continue;
}
acl.add_entry_full(acl::ACL_GROUP_OBJ, None, mode)?;
if !metadata.acl.users.is_empty() || !metadata.acl.groups.is_empty() {
- eprintln!(
+ log::warn!(
"Warning: {:?}: Missing GROUP_OBJ entry in ACL, resetting to value of MASK",
path_info,
);
StdChannelWriter::new(tx),
));
- let verbose = options.verbose;
-
let writer = pxar::encoder::sync::StandardWriter::new(writer);
if let Err(err) = crate::pxar::create_archive(
dir,
writer,
crate::pxar::Flags::DEFAULT,
move |path| {
- if verbose {
- println!("{:?}", path);
- }
+ log::debug!("{:?}", path);
Ok(())
},
Some(catalog),
let abort_future = async move {
while signal_stream.recv().await.is_some() {
- println!("got shutdown request (SIGINT)");
+ log::info!("got shutdown request (SIGINT)");
let prev_count = abort_count2.fetch_add(1, Ordering::SeqCst);
if prev_count >= 1 {
- println!("forced exit (task still running)");
+ log::info!("forced exit (task still running)");
break;
}
}
}
if strip_date && t.len() > 27 && &t[25..27] == ": " {
let line = &t[27..];
- println!("{}", line);
+ log::info!("{}", line);
} else {
- println!("{}", t);
+ log::info!("{}", t);
}
start += 1;
}
(None, master_pubkey) => match read_optional_default_encryption_key()? {
None => bail!("--crypt-mode without --keyfile and no default key file available"),
enc_key => {
- eprintln!("Encrypting with default encryption key!");
+ log::info!("Encrypting with default encryption key!");
let master_pubkey = match master_pubkey {
None => read_optional_default_master_pubkey()?,
master_pubkey => master_pubkey,