diff --git a/Cargo.lock b/Cargo.lock index f524888..3b1c4c1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1572,6 +1572,7 @@ dependencies = [ "integer-sqrt", "itertools", "lazy_static", + "log", "merge", "nix", "path-absolutize", @@ -1590,12 +1591,12 @@ dependencies = [ "serde_with", "sha1", "sha2", + "simplelog", "tempfile", "thiserror", "tokio", "toml", "users", - "vlog", "walkdir", "zstd", ] @@ -1818,6 +1819,17 @@ dependencies = [ "libc", ] +[[package]] +name = "simplelog" +version = "0.12.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "48dfff04aade74dd495b007c831cd6f4e0cee19c344dd9dc0884c0289b70a786" +dependencies = [ + "log", + "termcolor", + "time", +] + [[package]] name = "slab" version = "0.4.7" @@ -1972,8 +1984,15 @@ dependencies = [ "libc", "num_threads", "serde", + "time-macros", ] +[[package]] +name = "time-macros" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "42657b1a6f4d817cda8e7a0ace261fe0cc946cf3a80314390b22cc61ae080792" + [[package]] name = "tinyvec" version = "1.6.0" @@ -2163,12 +2182,6 @@ version = "0.9.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49874b5167b65d7193b8aba1567f5c7d93d001cafc34600cee003eda787e483f" -[[package]] -name = "vlog" -version = "0.1.4" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2266fcb904c50fb17fda4c9a751a1715629ecf8b21f4c9d78b4890fb71525d71" - [[package]] name = "walkdir" version = "2.3.2" diff --git a/Cargo.toml b/Cargo.toml index f2eb3b2..46b6967 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -31,7 +31,7 @@ derive_more = "0.99" derivative = "2" derive-getters = "0.2" lazy_static = "1" -vlog = "0.1" +log = "0.4" # async tokio = { version = "1", features = ["full"] } futures = "0.3" @@ -87,6 +87,7 @@ gethostname = "0.2" humantime = "2" users = "0.11" itertools = "0.10" +simplelog = "0.12" [dev-dependencies] rstest = "0.15" diff --git a/README.md b/README.md index 7cee7de..e78c425 100644 --- a/README.md +++ b/README.md @@ -10,6 +10,7 @@ It reads and writes the [restic][1] repo format desribed in the [design document and can therefore be used as a complete replacement for restic. + Note that rustic currently is in an beta release and misses tests. It is not yet considered to be ready for use in a production environment. diff --git a/rustic.log b/rustic.log new file mode 100644 index 0000000..e69de29 diff --git a/screenshots/rustic-restore.png b/screenshots/rustic-restore.png new file mode 100644 index 0000000..a3059fc Binary files /dev/null and b/screenshots/rustic-restore.png differ diff --git a/screenshots/rustic.png b/screenshots/rustic.png index b835a04..cfa306c 100644 Binary files a/screenshots/rustic.png and b/screenshots/rustic.png differ diff --git a/src/archiver/archiver_impl.rs b/src/archiver/archiver_impl.rs index aadfa2e..88c0f7b 100644 --- a/src/archiver/archiver_impl.rs +++ b/src/archiver/archiver_impl.rs @@ -7,8 +7,8 @@ use bytesize::ByteSize; use chrono::Local; use futures::{stream::FuturesOrdered, StreamExt}; use indicatif::ProgressBar; +use log::*; use tokio::spawn; -use vlog::*; use crate::backend::DecryptWriteBackend; use crate::blob::{BlobType, Metadata, Node, NodeType, Packer, Tree}; @@ -82,15 +82,15 @@ impl Archiver { let filename = self.path.join(node.name()); match self.parent.is_parent(&node) { ParentResult::Matched(_) => { - v2!("unchanged file: {:?}", filename); + debug!("unchanged file: {:?}", filename); self.summary.files_unmodified += 1; } ParentResult::NotMatched => { - v2!("changed file: {:?}", filename); + debug!("changed file: {:?}", filename); self.summary.files_changed += 1; } ParentResult::NotFound => { - v2!("new file: {:?}", filename); + debug!("new file: {:?}", filename); self.summary.files_new += 1; } } @@ -173,18 +173,18 @@ impl Archiver { match self.parent.is_parent(&node) { ParentResult::Matched(p_node) if node.subtree() == p_node.subtree() => { - v2!("unchanged tree: {:?}", self.path); + debug!("unchanged tree: {:?}", self.path); self.add_dir(node, dirsize); self.summary.dirs_unmodified += 1; return Ok(()); } ParentResult::NotFound => { - v2!("new tree: {:?} {}", self.path, dirsize_bytes); + debug!("new tree: {:?} {}", self.path, dirsize_bytes); self.summary.dirs_new += 1; } _ => { // "Matched" trees where the subree id does not match or unmach - v2!("changed tree: {:?} {}", self.path, dirsize_bytes); + debug!("changed tree: {:?} {}", self.path, dirsize_bytes); self.summary.dirs_changed += 1; } } @@ -215,7 +215,7 @@ impl Archiver { p.inc(size); return Ok(()); } else { - ve1!( + warn!( "missing blobs in index for unchanged file {:?}; re-reading file", self.path.join(node.name()) ); diff --git a/src/backend/cache.rs b/src/backend/cache.rs index 0bb4f6c..18b4c70 100644 --- a/src/backend/cache.rs +++ b/src/backend/cache.rs @@ -7,7 +7,7 @@ use anyhow::{anyhow, Result}; use async_trait::async_trait; use bytes::Bytes; use dirs::cache_dir; -use vlog::*; +use log::*; use walkdir::WalkDir; use super::{FileType, Id, ReadBackend, WriteBackend}; @@ -202,9 +202,9 @@ impl Cache { } pub async fn read_full(&self, tpe: FileType, id: &Id) -> Result { - v3!("cache reading tpe: {:?}, id: {}", &tpe, &id); + trace!("cache reading tpe: {:?}, id: {}", &tpe, &id); let data = fs::read(self.path(tpe, id))?; - v3!("cache hit!"); + trace!("cache hit!"); Ok(data.into()) } @@ -215,7 +215,7 @@ impl Cache { offset: u32, length: u32, ) -> Result { - v3!( + trace!( "cache reading tpe: {:?}, id: {}, offset: {}", &tpe, &id, @@ -225,12 +225,12 @@ impl Cache { file.seek(SeekFrom::Start(offset as u64))?; let mut vec = vec![0; length as usize]; file.read_exact(&mut vec)?; - v3!("cache hit!"); + trace!("cache hit!"); Ok(vec.into()) } async fn write_bytes(&self, tpe: FileType, id: &Id, buf: Bytes) -> Result<()> { - v3!("cache writing tpe: {:?}, id: {}", &tpe, &id); + trace!("cache writing tpe: {:?}, id: {}", &tpe, &id); fs::create_dir_all(self.dir(tpe, id))?; let filename = self.path(tpe, id); let mut file = fs::OpenOptions::new() @@ -242,7 +242,7 @@ impl Cache { } async fn remove(&self, tpe: FileType, id: &Id) -> Result<()> { - v3!("cache writing tpe: {:?}, id: {}", &tpe, &id); + trace!("cache writing tpe: {:?}, id: {}", &tpe, &id); let filename = self.path(tpe, id); fs::remove_file(filename)?; Ok(()) diff --git a/src/backend/ignore.rs b/src/backend/ignore.rs index 792964a..3bf1a69 100644 --- a/src/backend/ignore.rs +++ b/src/backend/ignore.rs @@ -7,6 +7,7 @@ use bytesize::ByteSize; use chrono::{TimeZone, Utc}; use clap::Parser; use ignore::{overrides::OverrideBuilder, DirEntry, Walk, WalkBuilder}; +use log::*; use merge::Merge; use serde::Deserialize; use serde_with::{serde_as, DisplayFromStr}; @@ -153,7 +154,7 @@ impl ReadSource for LocalSource { if let Err(e) = entry.and_then(|e| e.metadata()).map(|m| { size += if m.is_dir() { 0 } else { m.len() }; }) { - eprintln!("ignoring error {}", e); + warn!("ignoring error {}", e); } } Ok(size) diff --git a/src/backend/local.rs b/src/backend/local.rs index 0dce0b3..0fc258a 100644 --- a/src/backend/local.rs +++ b/src/backend/local.rs @@ -7,10 +7,10 @@ use anyhow::Result; use async_trait::async_trait; use bytes::Bytes; use filetime::{set_file_atime, set_file_mtime, FileTime}; +use log::*; use nix::sys::stat::{mknod, Mode, SFlag}; use nix::unistd::chown; use nix::unistd::{Gid, Group, Uid, User}; -use vlog::*; use walkdir::WalkDir; use super::node::{Metadata, Node, NodeType}; @@ -143,7 +143,7 @@ impl WriteBackend for LocalBackend { _cacheable: bool, buf: Bytes, ) -> Result<()> { - v3!("writing tpe: {:?}, id: {}", &tpe, &id); + trace!("writing tpe: {:?}, id: {}", &tpe, &id); let filename = self.path(tpe, id); let mut file = fs::OpenOptions::new() .create(true) @@ -156,7 +156,7 @@ impl WriteBackend for LocalBackend { } async fn remove(&self, tpe: FileType, id: &Id, _cacheable: bool) -> Result<()> { - v3!("writing tpe: {:?}, id: {}", &tpe, &id); + trace!("writing tpe: {:?}, id: {}", &tpe, &id); let filename = self.path(tpe, id); fs::remove_file(filename)?; Ok(()) diff --git a/src/backend/rclone.rs b/src/backend/rclone.rs index 5240345..22a3f5f 100644 --- a/src/backend/rclone.rs +++ b/src/backend/rclone.rs @@ -7,12 +7,12 @@ use std::sync::Arc; use anyhow::{anyhow, bail, Result}; use async_trait::async_trait; use bytes::Bytes; +use log::*; use rand::distributions::{Alphanumeric, DistString}; use rand::thread_rng; use sha1::{Digest, Sha1}; use tempfile::{Builder, TempDir}; use tokio::task::spawn_blocking; -use vlog::*; use super::{FileType, Id, ReadBackend, RestBackend, WriteBackend}; @@ -38,7 +38,7 @@ fn htpasswd() -> Result<(TempDir, PathBuf, String, String)> { struct ChildToKill(Child); impl Drop for ChildToKill { fn drop(&mut self) { - v3!("killing rclone."); + debug!("killing rclone."); self.0.kill().unwrap(); } } @@ -62,7 +62,7 @@ impl RcloneBackend { "--htpasswd", file.to_str().unwrap(), ]; - v3!("starting rclone with args {args:?}"); + debug!("starting rclone with args {args:?}"); let mut child = Command::new("rclone") .args(args) .stderr(Stdio::piped()) @@ -87,7 +87,7 @@ impl RcloneBackend { break url.trim_end().to_string(); } } - None if !line.is_empty() => v1!("rclone output: {line}"), + None if !line.is_empty() => info!("rclone output: {line}"), _ => {} } }; @@ -98,7 +98,7 @@ impl RcloneBackend { break; } if !line.is_empty() { - v3!("rclone output: {line}"); + info!("rclone output: {line}"); } }); @@ -108,7 +108,7 @@ impl RcloneBackend { let url = "http://".to_string() + &user + ":" + &pass + "@" + &url[7..]; - v3!("using REST backend with url {url}."); + debug!("using REST backend with url {url}."); let rest = RestBackend::new(&url); Ok(Self { _child_data: Arc::new((ChildToKill(child), tmp_dir)), diff --git a/src/backend/rest.rs b/src/backend/rest.rs index 5420aa8..58b25cc 100644 --- a/src/backend/rest.rs +++ b/src/backend/rest.rs @@ -4,9 +4,9 @@ use anyhow::{bail, Result}; use async_trait::async_trait; use backoff::{backoff::Backoff, ExponentialBackoff, ExponentialBackoffBuilder}; use bytes::Bytes; +use log::*; use reqwest::{Client, Url}; use serde::Deserialize; -use vlog::*; use super::{FileType, Id, ReadBackend, WriteBackend}; @@ -34,7 +34,7 @@ pub struct RestBackend { // TODO for backoff: Handle transient vs permanent errors! fn notify(err: reqwest::Error, duration: Duration) { - println!("Error {err} at {duration:?}, retrying"); + warn!("Error {err} at {duration:?}, retrying"); } impl RestBackend { @@ -218,7 +218,7 @@ impl WriteBackend for RestBackend { _cacheable: bool, buf: Bytes, ) -> Result<()> { - v3!("writing tpe: {:?}, id: {}", &tpe, &id); + trace!("writing tpe: {:?}, id: {}", &tpe, &id); let req_builder = self.client.post(self.url(tpe, id)).body(buf); Ok(backoff::future::retry_notify( self.backoff.clone(), @@ -232,7 +232,7 @@ impl WriteBackend for RestBackend { } async fn remove(&self, tpe: FileType, id: &Id, _cacheable: bool) -> Result<()> { - v3!("removing tpe: {:?}, id: {}", &tpe, &id); + trace!("removing tpe: {:?}, id: {}", &tpe, &id); Ok(backoff::future::retry_notify( self.backoff.clone(), || async { diff --git a/src/commands/backup.rs b/src/commands/backup.rs index 3e1c4a8..88acb11 100644 --- a/src/commands/backup.rs +++ b/src/commands/backup.rs @@ -4,11 +4,11 @@ use anyhow::{anyhow, Result}; use chrono::{Duration, Local}; use clap::{AppSettings, Parser}; use gethostname::gethostname; +use log::*; use merge::Merge; use path_absolutize::*; use serde::Deserialize; use serde_with::{serde_as, DisplayFromStr}; -use vlog::*; use super::{bytes, progress_bytes, progress_counter, RusticConfig}; use crate::archiver::{Archiver, Parent}; @@ -103,16 +103,16 @@ pub(super) async fn execute( let sources = match (opts.sources.is_empty(), config_opts.is_empty()) { (false, _) => opts.sources.clone(), (true, false) => { - v1!("using all backup sources from config file."); + info!("using all backup sources from config file."); config_opts.iter().map(|opt| opt.source.clone()).collect() } (true, true) => { - v1!("no backup source given."); + warn!("no backup source given."); return Ok(()); } }; - let index = IndexBackend::only_full_trees(&be.clone(), progress_counter()).await?; + let index = IndexBackend::only_full_trees(&be.clone(), progress_counter("")).await?; for source in sources { let mut opts = opts.clone(); @@ -126,7 +126,7 @@ pub(super) async fn execute( let mut be = DryRunBackend::new(be.clone(), opts.dry_run); be.set_zstd(zstd); - v1!("\nbacking up {source}..."); + info!("starting to backup \"{source}\"..."); let index = index.clone(); let backup_stdin = source == "-"; let backup_path = if backup_stdin { @@ -150,7 +150,7 @@ pub(super) async fn execute( (false, false, None) => SnapshotFile::latest( &be, |snap| snap.hostname == hostname && snap.paths.contains(&backup_path_str), - progress_counter(), + progress_counter(""), ) .await .ok(), @@ -159,11 +159,11 @@ pub(super) async fn execute( let parent_tree = match &parent { Some(snap) => { - v1!("using parent {}", snap.id); + info!("using parent {}", snap.id); Some(snap.tree) } None => { - v1!("using no parent"); + info!("using no parent"); None } }; @@ -191,9 +191,8 @@ pub(super) async fn execute( let parent = Parent::new(&index, parent_tree, opts.ignore_ctime, opts.ignore_inode).await; let snap = if backup_stdin { - v1!("starting backup from stdin..."); let mut archiver = Archiver::new(be, index, &config, parent, snap)?; - let p = progress_bytes(); + let p = progress_bytes("starting backup from stdin..."); archiver .backup_reader( std::io::stdin(), @@ -204,70 +203,66 @@ pub(super) async fn execute( None, None, ), - p, + p.clone(), ) .await?; - archiver.finalize_snapshot().await? + let snap = archiver.finalize_snapshot().await?; + p.finish_with_message("done"); + snap } else { let src = LocalSource::new(opts.ignore_opts.clone(), backup_path)?; - let size = if get_verbosity_level() == 1 { - v1!("determining size of backup source..."); - src.size()? - } else { - 0 + let p = progress_bytes("determining size..."); + if !p.is_hidden() { + let size = src.size()?; + p.set_length(size); }; - v1!("starting backup..."); + p.set_prefix("backing up..."); let mut archiver = Archiver::new(be, index.clone(), &config, parent, snap)?; - let p = progress_bytes(); - p.set_length(size); for item in src { match item { Err(e) => { - eprintln!("ignoring error {}\n", e) + warn!("ignoring error {}\n", e) } Ok((path, node)) => { if let Err(e) = archiver.add_entry(&path, node, p.clone()).await { - eprintln!("ignoring error {} for {:?}\n", e, path); + warn!("ignoring error {} for {:?}\n", e, path); } } } } + let snap = archiver.finalize_snapshot().await?; p.finish_with_message("done"); - archiver.finalize_snapshot().await? + snap }; let summary = snap.summary.unwrap(); - v1!( + println!( "Files: {} new, {} changed, {} unchanged", - summary.files_new, - summary.files_changed, - summary.files_unmodified + summary.files_new, summary.files_changed, summary.files_unmodified ); - v1!( + println!( "Dirs: {} new, {} changed, {} unchanged", - summary.dirs_new, - summary.dirs_changed, - summary.dirs_unmodified + summary.dirs_new, summary.dirs_changed, summary.dirs_unmodified ); - v2!("Data Blobs: {} new", summary.data_blobs); - v2!("Tree Blobs: {} new", summary.tree_blobs); - v1!( + debug!("Data Blobs: {} new", summary.data_blobs); + debug!("Tree Blobs: {} new", summary.tree_blobs); + println!( "Added to the repo: {} (raw: {})", bytes(summary.data_added_packed), bytes(summary.data_added) ); - v1!( + println!( "processed {} files, {}", summary.total_files_processed, bytes(summary.total_bytes_processed) ); - v1!("snapshot {} successfully saved.", snap.id); + println!("snapshot {} successfully saved.", snap.id); - v1!("backup of {source} done."); + info!("backup of \"{source}\" done."); } Ok(()) diff --git a/src/commands/cat.rs b/src/commands/cat.rs index 3e808c2..401f0d5 100644 --- a/src/commands/cat.rs +++ b/src/commands/cat.rs @@ -80,8 +80,8 @@ async fn cat_blob(be: &impl DecryptReadBackend, tpe: BlobType, opt: IdOpt) -> Re async fn cat_tree(be: &impl DecryptReadBackend, opts: TreeOpts) -> Result<()> { let (id, path) = opts.snap.split_once(':').unwrap_or((&opts.snap, "")); - let snap = SnapshotFile::from_str(be, id, |_| true, progress_counter()).await?; - let index = IndexBackend::new(be, progress_counter()).await?; + let snap = SnapshotFile::from_str(be, id, |_| true, progress_counter("")).await?; + let index = IndexBackend::new(be, progress_counter("")).await?; let id = Tree::subtree_id(&index, snap.tree, Path::new(path)).await?; let data = index.blob_from_backend(&BlobType::Tree, &id).await?; println!("{}", String::from_utf8(data.to_vec())?); diff --git a/src/commands/check.rs b/src/commands/check.rs index fa31a50..61d65bf 100644 --- a/src/commands/check.rs +++ b/src/commands/check.rs @@ -3,11 +3,13 @@ use std::collections::HashMap; use anyhow::Result; use clap::Parser; use futures::{stream, StreamExt, TryStreamExt}; -use vlog::*; +use indicatif::ProgressBar; +use log::*; use super::{progress_bytes, progress_counter}; use crate::backend::{Cache, DecryptReadBackend, FileType, ReadBackend}; use crate::blob::{BlobType, NodeType, TreeStreamerOnce}; +use crate::commands::helpers::progress_spinner; use crate::id::Id; use crate::index::{IndexBackend, IndexCollector, IndexType, IndexedBackend}; use crate::repo::{IndexFile, IndexPack, SnapshotFile}; @@ -32,7 +34,6 @@ pub(super) async fn execute( ) -> Result<()> { if !opts.trust_cache { if let Some(cache) = &cache { - v1!("checking snapshots and index in cache..."); for file_type in [FileType::Snapshot, FileType::Index] { // list files in order to clean up the cache // @@ -40,31 +41,29 @@ pub(super) async fn execute( // TODO: Only list the files once... let _ = be.list_with_size(file_type).await?; - check_cache_files(cache, raw_be, file_type).await?; + let p = progress_bytes(format!("checking {} in cache...", file_type.name())); + check_cache_files(cache, raw_be, file_type, p).await?; } } } if let Some(hot_be) = hot_be { - v1!("checking snapshots and index in hot repo..."); for file_type in [FileType::Snapshot, FileType::Index] { check_hot_files(raw_be, hot_be, file_type).await?; } } - v1!("checking packs in index and from pack list..."); let index_collector = check_packs(be, hot_be).await?; if !opts.trust_cache { if let Some(cache) = &cache { - v1!("checking packs in cache..."); - check_cache_files(cache, raw_be, FileType::Pack).await?; + let p = progress_bytes("checking packs in cache..."); + check_cache_files(cache, raw_be, FileType::Pack, p).await?; } } let be = IndexBackend::new_from_index(be, index_collector.into_index()); - v1!("checking snapshots and trees..."); check_snapshots(&be).await?; if opts.read_data { @@ -79,6 +78,7 @@ async fn check_hot_files( be_hot: &impl ReadBackend, file_type: FileType, ) -> Result<()> { + let p = progress_spinner(format!("checking {} in hot repo...", file_type.name())); let mut files = be .list_with_size(file_type) .await? @@ -89,8 +89,8 @@ async fn check_hot_files( for (id, size_hot) in files_hot { match files.remove(&id) { - None => eprintln!("hot file {} does not exist in repo", id.to_hex()), - Some(size) if size != size_hot => eprintln!( + None => error!("hot file {} does not exist in repo", id.to_hex()), + Some(size) if size != size_hot => error!( "file {}: hot size: {}, actual size: {}", id.to_hex(), size_hot, @@ -101,8 +101,9 @@ async fn check_hot_files( } for (id, _) in files { - eprintln!("hot file {} is missing!", id.to_hex()); + error!("hot file {} is missing!", id.to_hex()); } + p.finish(); Ok(()) } @@ -111,6 +112,7 @@ async fn check_cache_files( cache: &Cache, be: &impl ReadBackend, file_type: FileType, + p: ProgressBar, ) -> Result<()> { let files = cache.list_with_size(file_type).await?; @@ -118,7 +120,6 @@ async fn check_cache_files( return Ok(()); } - let p = progress_bytes(); let total_size = files.iter().map(|(_, size)| *size as u64).sum(); p.set_length(total_size); @@ -134,7 +135,7 @@ async fn check_cache_files( let data_cached = cache.read_full(file_type, &id).await.unwrap(); let data = be.read_full(file_type, &id).await.unwrap(); if data_cached != data { - eprintln!( + error!( "Cached file Type: {:?}, Id: {} is not identical to backend!", file_type, id ); @@ -170,14 +171,14 @@ async fn check_packs( blobs.sort_unstable(); for blob in blobs { if blob.tpe != blob_type { - eprintln!( + error!( "pack {}: blob {} blob type does not match: {:?}, expected: {:?}", p.id, blob.id, blob.tpe, blob_type ); } if blob.offset != expected_offset { - eprintln!( + error!( "pack {}: blob {} offset in index: {}, expected: {}", p.id, blob.id, blob.offset, expected_offset ); @@ -186,8 +187,7 @@ async fn check_packs( } }; - v1!("- reading index..."); - let p = progress_counter(); + let p = progress_counter("reading index..."); let mut stream = be.stream_all::(p.clone()).await?; while let Some(index) = stream.try_next().await? { let index = index.1; @@ -202,12 +202,14 @@ async fn check_packs( p.finish(); if let Some(hot_be) = hot_be { - v1!("- listing packs in hot repo..."); + let p = progress_spinner("listing packs in hot repo..."); check_packs_list(hot_be, tree_packs).await?; + p.finish(); } - v1!("- listing packs..."); + let p = progress_spinner("listing packs..."); check_packs_list(be, packs).await?; + p.finish(); Ok(index_collector) } @@ -215,8 +217,8 @@ async fn check_packs( async fn check_packs_list(be: &impl ReadBackend, mut packs: HashMap) -> Result<()> { for (id, size) in be.list_with_size(FileType::Pack).await? { match packs.remove(&id) { - None => eprintln!("pack {} not referenced in index", id.to_hex()), - Some(index_size) if index_size != size => eprintln!( + None => error!("pack {} not referenced in index", id.to_hex()), + Some(index_size) if index_size != size => error!( "pack {}: size computed by index: {}, actual size: {}", id.to_hex(), index_size, @@ -227,7 +229,7 @@ async fn check_packs_list(be: &impl ReadBackend, mut packs: HashMap) -> } for (id, _) in packs { - eprintln!( + error!( "pack {} is referenced by the index but not presend!", id.to_hex() ); @@ -237,8 +239,7 @@ async fn check_packs_list(be: &impl ReadBackend, mut packs: HashMap) -> // check if all snapshots and contained trees can be loaded and contents exist in the index async fn check_snapshots(index: &(impl IndexedBackend + Unpin)) -> Result<()> { - v1!(" - reading snapshots..."); - let p = progress_counter(); + let p = progress_counter("reading snapshots..."); let snap_trees: Vec<_> = index .be() .stream_all::(p.clone()) @@ -248,9 +249,8 @@ async fn check_snapshots(index: &(impl IndexedBackend + Unpin)) -> Result<()> { .await?; p.finish(); - v1!(" - checking trees..."); - let mut tree_streamer = - TreeStreamerOnce::new(index.clone(), snap_trees, progress_counter()).await?; + let p = progress_counter("checking trees..."); + let mut tree_streamer = TreeStreamerOnce::new(index.clone(), snap_trees, p).await?; while let Some(item) = tree_streamer.try_next().await? { let (path, tree) = item; for node in tree.nodes() { @@ -258,11 +258,11 @@ async fn check_snapshots(index: &(impl IndexedBackend + Unpin)) -> Result<()> { NodeType::File => { for (i, id) in node.content().iter().enumerate() { if id.is_null() { - eprintln!("file {:?} blob {} has null ID", path.join(node.name()), i); + error!("file {:?} blob {} has null ID", path.join(node.name()), i); } if !index.has_data(id) { - eprintln!( + error!( "file {:?} blob {} is missig in index", path.join(node.name()), id @@ -274,10 +274,10 @@ async fn check_snapshots(index: &(impl IndexedBackend + Unpin)) -> Result<()> { NodeType::Dir => { match node.subtree() { None => { - eprintln!("dir {:?} subtree does not exist", path.join(node.name())) + error!("dir {:?} subtree does not exist", path.join(node.name())) } Some(tree) if tree.is_null() => { - eprintln!("dir {:?} subtree has null ID", path.join(node.name())) + error!("dir {:?} subtree has null ID", path.join(node.name())) } _ => {} // subtree is ok } diff --git a/src/commands/diff.rs b/src/commands/diff.rs index 298646e..52b7f63 100644 --- a/src/commands/diff.rs +++ b/src/commands/diff.rs @@ -3,11 +3,11 @@ use std::path::Path; use anyhow::Result; use clap::Parser; use futures::StreamExt; -use vlog::*; use super::progress_counter; use crate::backend::DecryptReadBackend; use crate::blob::{NodeStreamer, NodeType, Tree}; +use crate::commands::helpers::progress_spinner; use crate::index::IndexBackend; use crate::repo::SnapshotFile; @@ -26,13 +26,14 @@ pub(super) async fn execute(be: &(impl DecryptReadBackend + Unpin), opts: Opts) let (id1, path1) = opts.snap1.split_once(':').unwrap_or((&opts.snap1, "")); let (id2, path2) = opts.snap2.split_once(':').unwrap_or((&opts.snap2, path1)); - v1!("getting snapshots..."); + let p = progress_spinner("getting snapshots..."); + p.finish(); let snaps = SnapshotFile::from_ids(be, &[id1.to_string(), id2.to_string()]).await?; let snap1 = &snaps[0]; let snap2 = &snaps[1]; - let index = IndexBackend::new(be, progress_counter()).await?; + let index = IndexBackend::new(be, progress_counter("")).await?; let id1 = Tree::subtree_id(&index, snap1.tree, Path::new(path1)).await?; let id2 = Tree::subtree_id(&index, snap2.tree, Path::new(path2)).await?; diff --git a/src/commands/forget.rs b/src/commands/forget.rs index 2b24cf5..694a9be 100644 --- a/src/commands/forget.rs +++ b/src/commands/forget.rs @@ -145,14 +145,9 @@ pub(super) async fn execute( forget_snaps ), (false, false) => { - println!("removing snapshots..."); - be.delete_list( - FileType::Snapshot, - true, - forget_snaps.clone(), - progress_counter(), - ) - .await?; + let p = progress_counter("removing snapshots..."); + be.delete_list(FileType::Snapshot, true, forget_snaps.clone(), p) + .await?; } } diff --git a/src/commands/helpers.rs b/src/commands/helpers.rs index 255407b..abf21da 100644 --- a/src/commands/helpers.rs +++ b/src/commands/helpers.rs @@ -1,3 +1,4 @@ +use std::borrow::Cow; use std::fmt::Write; use std::fs::File; use std::io::BufReader; @@ -10,10 +11,10 @@ use bytesize::ByteSize; use futures::{stream::FuturesUnordered, TryStreamExt}; use indicatif::HumanDuration; use indicatif::{ProgressBar, ProgressState, ProgressStyle}; +use log::*; use rpassword::{prompt_password, read_password_from_bufread}; use tokio::spawn; use tokio::time::sleep; -use vlog::*; use crate::backend::{DecryptReadBackend, FileType, ReadBackend}; use crate::crypto::Key; @@ -67,27 +68,34 @@ pub async fn get_key( bail!("incorrect password!"); } -pub fn progress_counter() -> ProgressBar { - if get_verbosity_level() == 1 { - let p = ProgressBar::new(0).with_style( - ProgressStyle::default_bar() - .template("[{elapsed_precise}] {bar:40.cyan/blue} {pos:>10}/{len:10}") - .unwrap(), - ); - p.enable_steady_tick(Duration::from_millis(100)); - p - } else { - ProgressBar::hidden() - } +pub fn progress_spinner(prefix: impl Into>) -> ProgressBar { + let p = ProgressBar::new(0).with_style( + ProgressStyle::default_bar() + .template("[{elapsed_precise}] {prefix:30} {spinner}") + .unwrap(), + ); + p.set_prefix(prefix); + p.enable_steady_tick(Duration::from_millis(100)); + p +} + +pub fn progress_counter(prefix: impl Into>) -> ProgressBar { + let p = ProgressBar::new(0).with_style( + ProgressStyle::default_bar() + .template("[{elapsed_precise}] {prefix:30} {bar:40.cyan/blue} {pos:>10}/{len:10}") + .unwrap(), + ); + p.enable_steady_tick(Duration::from_millis(100)); + p.set_prefix(prefix); + p } pub fn no_progress() -> ProgressBar { ProgressBar::hidden() } -pub fn progress_bytes() -> ProgressBar { - if get_verbosity_level() == 1 { - let p = ProgressBar::new(0).with_style( +pub fn progress_bytes(prefix: impl Into>) -> ProgressBar { + let p = ProgressBar::new(0).with_style( ProgressStyle::default_bar() .with_key("my_eta", |s: &ProgressState, w: &mut dyn Write| match (s.pos(), s.len()){ @@ -95,21 +103,21 @@ pub fn progress_bytes() -> ProgressBar { (pos,Some(len)) => write!(w,"{:#}", HumanDuration(Duration::from_secs(s.elapsed().as_secs() * (len-pos)/pos))), (_, _) => write!(w,"-"), }.unwrap()) - .template("[{elapsed_precise}] {bar:40.cyan/blue} {bytes:>10}/{total_bytes:10} {bytes_per_sec:12} (ETA {my_eta})") + .template("[{elapsed_precise}] {prefix:30} {bar:40.cyan/blue} {bytes:>10}/{total_bytes:10} {bytes_per_sec:12} (ETA {my_eta})") .unwrap() ); - p.enable_steady_tick(Duration::from_secs(1)); - p - } else { - ProgressBar::hidden() - } + p.set_prefix(prefix); + p.enable_steady_tick(Duration::from_millis(100)); + p } pub fn warm_up_command(packs: Vec, command: &str) -> Result<()> { + let p = progress_counter("warming up packs..."); + p.set_length(packs.len() as u64); for pack in packs { let id = pack.to_hex(); let actual_command = command.replace("%id", &id); - v1!("calling {actual_command}..."); + debug!("calling {actual_command}..."); let mut commands: Vec<_> = actual_command.split(' ').collect(); let status = Command::new(commands[0]) .args(&mut commands[1..]) @@ -118,6 +126,7 @@ pub fn warm_up_command(packs: Vec, command: &str) -> Result<()> { bail!("warm-up command was not successful for pack {id}. {status}"); } } + p.finish(); Ok(()) } @@ -125,7 +134,7 @@ pub async fn warm_up(be: &impl DecryptReadBackend, packs: Vec) -> Result<()> let mut be = be.clone(); be.set_option("retry", "false")?; - let p = progress_counter(); + let p = progress_counter("warming up packs..."); p.set_length(packs.len() as u64); let mut stream = FuturesUnordered::new(); @@ -152,7 +161,8 @@ pub async fn warm_up(be: &impl DecryptReadBackend, packs: Vec) -> Result<()> pub async fn wait(d: Option) { if let Some(wait) = d { - v1!("waiting {}...", wait); + let p = progress_spinner(format!("waiting {}...", wait)); sleep(*wait).await; + p.finish(); } } diff --git a/src/commands/ls.rs b/src/commands/ls.rs index 224dc07..270a14f 100644 --- a/src/commands/ls.rs +++ b/src/commands/ls.rs @@ -18,8 +18,8 @@ pub(super) struct Opts { pub(super) async fn execute(be: &(impl DecryptReadBackend + Unpin), opts: Opts) -> Result<()> { let (id, path) = opts.snap.split_once(':').unwrap_or((&opts.snap, "")); - let snap = SnapshotFile::from_str(be, id, |_| true, progress_counter()).await?; - let index = IndexBackend::new(be, progress_counter()).await?; + let snap = SnapshotFile::from_str(be, id, |_| true, progress_counter("")).await?; + let index = IndexBackend::new(be, progress_counter("")).await?; let tree = Tree::subtree_id(&index, snap.tree, Path::new(path)).await?; let mut tree_streamer = NodeStreamer::new(index, tree).await?; diff --git a/src/commands/mod.rs b/src/commands/mod.rs index 2fe40d0..338219b 100644 --- a/src/commands/mod.rs +++ b/src/commands/mod.rs @@ -1,9 +1,12 @@ +use std::fs::File; use std::path::PathBuf; use anyhow::{bail, Result}; use clap::{Parser, Subcommand}; use merge::Merge; use serde::Deserialize; +use serde_with::{serde_as, DisplayFromStr}; +use simplelog::*; use crate::backend::{ Cache, CachedBackend, ChooseBackend, DecryptBackend, DecryptReadBackend, FileType, @@ -31,8 +34,8 @@ mod snapshots; mod tag; use helpers::*; +use log::*; use rustic_config::RusticConfig; -use vlog::*; #[derive(Parser)] #[clap(about, version)] @@ -54,6 +57,7 @@ struct Opts { command: Command, } +#[serde_as] #[derive(Default, Parser, Deserialize, Merge)] #[serde(default, rename_all = "kebab-case")] struct GlobalOpts { @@ -89,21 +93,15 @@ struct GlobalOpts { )] password_command: Option, - /// Increase verbosity (can be used multiple times) - #[clap(long, short = 'v', global = true, parse(from_occurrences))] - #[merge(strategy = merge::num::overwrite_zero)] - verbose: i8, + /// Use this log level [default: info] + #[clap(long, global = true, env = "RUSTIC_LOG_LEVEL")] + #[serde_as(as = "Option")] + log_level: Option, - /// Don't be verbose at all - #[clap( - long, - short = 'q', - global = true, - parse(from_occurrences), - conflicts_with = "verbose" - )] - #[merge(strategy = merge::num::overwrite_zero)] - quiet: i8, + /// Write log messages to the given file instead of printing them. + /// Note: warnings and errors are still additionally printed unless they are ignored by --log-level + #[clap(long, global = true, env = "RUSTIC_LOG_FILE", value_name = "LOGFILE")] + log_file: Option, /// Don't use a cache. #[clap(long, global = true, env = "RUSTIC_NO_CACHE")] @@ -176,11 +174,40 @@ pub async fn execute() -> Result<()> { let command: Vec<_> = std::env::args_os().into_iter().collect(); let args = Opts::parse_from(&command); + // get global options from command line / env and config file let config_file = RusticConfig::new(&args.config_profile)?; - let mut opts = args.global; config_file.merge_into("global", &mut opts)?; + // start logger + let level_filter = opts.log_level.unwrap_or(LevelFilter::Info); + match opts.log_file { + None => TermLogger::init( + level_filter, + ConfigBuilder::new() + .set_time_level(LevelFilter::Off) + .build(), + TerminalMode::Stderr, + ColorChoice::Auto, + )?, + + Some(file) => CombinedLogger::init(vec![ + TermLogger::new( + level_filter.max(LevelFilter::Warn), + ConfigBuilder::new() + .set_time_level(LevelFilter::Off) + .build(), + TerminalMode::Stderr, + ColorChoice::Auto, + ), + WriteLogger::new( + level_filter, + Config::default(), + File::options().create(true).append(true).open(file)?, + ), + ])?, + } + if let Command::SelfUpdate(opts) = args.command { self_update::execute(opts).await?; return Ok(()); @@ -192,9 +219,6 @@ pub async fn execute() -> Result<()> { .collect::>() .join(" "); - let verbosity = (1 + opts.verbose - opts.quiet).clamp(0, 3); - set_verbosity_level(verbosity as usize); - let be = match &opts.repository { Some(repo) => ChooseBackend::from_url(repo)?, None => bail!("No repository given. Please use the --repository option."), @@ -228,7 +252,7 @@ pub async fn execute() -> Result<()> { opts.password_command.as_deref(), ) .await?; - ve1!("password is correct."); + info!("password is correct."); let dbe = DecryptBackend::new(&be, key.clone()); let config: ConfigFile = dbe.get_file(&config_ids[0]).await?; @@ -241,8 +265,8 @@ pub async fn execute() -> Result<()> { .then(|| Cache::new(config.id, opts.cache_dir).ok()) .flatten(); match &cache { - None => ve1!("using no cache"), - Some(cache) => ve1!("using cache at {}", cache.location()), + None => info!("using no cache"), + Some(cache) => info!("using cache at {}", cache.location()), } let be_cached = CachedBackend::new(be.clone(), cache.clone()); let dbe = DecryptBackend::new(&be_cached, key.clone()); diff --git a/src/commands/prune.rs b/src/commands/prune.rs index af5fcfe..b818b56 100644 --- a/src/commands/prune.rs +++ b/src/commands/prune.rs @@ -8,11 +8,12 @@ use chrono::{DateTime, Duration, Local}; use clap::{AppSettings, Parser}; use derive_more::Add; use futures::{future, TryStreamExt}; -use vlog::*; +use log::*; use super::{bytes, no_progress, progress_bytes, progress_counter, wait, warm_up, warm_up_command}; use crate::backend::{Cache, DecryptFullBackend, DecryptReadBackend, FileType}; use crate::blob::{BlobType, BlobTypeMap, NodeType, PackSizer, Repacker, TreeStreamerOnce}; +use crate::commands::helpers::progress_spinner; use crate::id::Id; use crate::index::{IndexBackend, IndexCollector, IndexType, IndexedBackend, Indexer, ReadIndex}; use crate::repo::{ConfigFile, IndexBlob, IndexFile, IndexPack, SnapshotFile}; @@ -92,10 +93,9 @@ pub(super) async fn execute( bail!("--repack-uncompressed makes no sense for v1 repo!"); } - v1!("reading index..."); let mut index_files = Vec::new(); - let p = progress_counter(); + let p = progress_counter("reading index..."); let mut stream = be.stream_all::(p.clone()).await?; let mut index_collector = IndexCollector::new(IndexType::OnlyTrees); @@ -110,15 +110,16 @@ pub(super) async fn execute( p.finish(); if let Some(cache) = &cache { - v1!("cleaning up packs from cache..."); + let p = progress_spinner("cleaning up packs from cache..."); cache .remove_not_in_list(FileType::Pack, index_collector.tree_packs()) .await?; + p.finish(); } match (cache.is_some(), opts.cache_only) { (true, true) => return Ok(()), (false, true) => { - ve1!("Warning: option --cache-only used without a cache."); + warn!("Warning: option --cache-only used without a cache."); return Ok(()); } _ => {} @@ -133,12 +134,13 @@ pub(super) async fn execute( }; // list existing pack files - v1!("geting packs from repository..."); + let p = progress_spinner("geting packs from repository..."); let existing_packs: HashMap<_, _> = be .list_with_size(FileType::Pack) .await? .into_iter() .collect(); + p.finish(); let mut pruner = Pruner::new(used_ids, existing_packs, index_files); pruner.count_used_blobs(); @@ -166,10 +168,8 @@ pub(super) async fn execute( pruner.print_stats(); if opts.warm_up { - v1!("warming up needed data pack files..."); warm_up(be, pruner.repack_packs()).await?; } else if opts.warm_up_command.is_some() { - v1!("warming up needed data pack files..."); warm_up_command( pruner.repack_packs(), opts.warm_up_command.as_ref().unwrap(), @@ -495,7 +495,7 @@ impl Pruner { // check that all used blobs are present in index for (id, count) in &self.used_ids { if *count == 0 { - eprintln!("used blob {} is missing", id); + error!("used blob {} is missing", id); bail!("missing blobs"); } } @@ -744,92 +744,88 @@ impl Pruner { let blob_stat = self.stats.total_blobs(); let size_stat = self.stats.total_size(); - v2!( + debug!( "used: {:>10} blobs, {:>10}", blob_stat.used, bytes(size_stat.used) ); - v2!( + debug!( "unused: {:>10} blobs, {:>10}", blob_stat.unused, bytes(size_stat.unused) ); - v2!( + debug!( "total: {:>10} blobs, {:>10}", blob_stat.total(), bytes(size_stat.total()) ); - v1!(""); - - v1!( + println!( "to repack: {:>10} packs, {:>10} blobs, {:>10}", pack_stat.repack, blob_stat.repack, bytes(size_stat.repack) ); - v1!( + println!( "this removes: {:>10} blobs, {:>10}", blob_stat.repackrm, bytes(size_stat.repackrm) ); - v1!( + println!( "to delete: {:>10} packs, {:>10} blobs, {:>10}", pack_stat.unused, blob_stat.remove, bytes(size_stat.remove) ); if !self.existing_packs.is_empty() { - v1!( + println!( "unindexed: {:>10} packs, ?? blobs, {:>10}", self.existing_packs.len(), bytes(self.stats.size_unref) ); } - v1!( + println!( "total prune: {:>10} blobs, {:>10}", blob_stat.repackrm + blob_stat.remove, bytes(size_stat.repackrm + size_stat.remove + self.stats.size_unref) ); - v1!( + println!( "remaining: {:>10} blobs, {:>10}", blob_stat.total_after_prune(), bytes(size_stat.total_after_prune()) ); - v1!( + println!( "unused size after prune: {:>10} ({:.2}% of remaining size)", bytes(size_stat.unused_after_prune()), size_stat.unused_after_prune() as f64 / size_stat.total_after_prune() as f64 * 100.0 ); - v1!(""); + println!(); - v1!( + println!( "packs marked for deletion: {:>10}, {:>10}", self.stats.packs_to_delete.total(), bytes(self.stats.size_to_delete.total()), ); - v1!( + println!( " - complete deletion: {:>10}, {:>10}", self.stats.packs_to_delete.remove, bytes(self.stats.size_to_delete.remove), ); - v1!( + println!( " - keep marked: {:>10}, {:>10}", self.stats.packs_to_delete.keep, bytes(self.stats.size_to_delete.keep), ); - v1!( + println!( " - recover: {:>10}, {:>10}", self.stats.packs_to_delete.recover, bytes(self.stats.size_to_delete.recover), ); - v2!(""); - - v2!( + debug!( "index files to rebuild: {} / {}", self.index_files.len(), self.stats.index_files @@ -892,13 +888,13 @@ impl Pruner { // mark unreferenced packs for deletion if !self.existing_packs.is_empty() { if opts.instant_delete { - v1!("removing not needed unindexed pack files..."); + let p = progress_counter("removing unindexed packs..."); let existing_packs: Vec<_> = self.existing_packs.into_iter().map(|(id, _)| id).collect(); - be.delete_list(FileType::Pack, true, existing_packs, progress_counter()) + be.delete_list(FileType::Pack, true, existing_packs, p) .await?; } else { - v1!("marking not needed unindexed pack files for deletion..."); + info!("marking not needed unindexed pack files for deletion..."); for (id, size) in self.existing_packs { let pack = IndexPack { id, @@ -914,17 +910,12 @@ impl Pruner { // process packs by index_file let p = match (self.index_files.is_empty(), self.stats.packs.repack > 0) { (true, _) => { - v1!("nothing to do!"); - no_progress() - } - (false, true) => { - v1!("repacking packs and rebuilding index..."); - progress_bytes() - } - (false, false) => { - v1!("rebuilding index..."); + info!("nothing to do!"); no_progress() } + // TODO: Use a MultiProgressBar here + (false, true) => progress_bytes("repacking // rebuilding index..."), + (false, false) => progress_spinner("rebuilding index..."), }; p.set_length(self.stats.total_size().repack - self.stats.total_size().repackrm); @@ -1011,20 +1002,20 @@ impl Pruner { p.finish(); if !data_packs_remove.is_empty() { - v1!("removing old data pack files..."); - be.delete_list(FileType::Pack, false, data_packs_remove, progress_counter()) + let p = progress_counter("removing old data packs..."); + be.delete_list(FileType::Pack, false, data_packs_remove, p) .await?; } if !tree_packs_remove.is_empty() { - v1!("removing old tree pack files..."); - be.delete_list(FileType::Pack, true, tree_packs_remove, progress_counter()) + let p = progress_counter("removing old tree packs..."); + be.delete_list(FileType::Pack, true, tree_packs_remove, p) .await?; } if !indexes_remove.is_empty() { - v1!("removing old index files..."); - be.delete_list(FileType::Index, true, indexes_remove, progress_counter()) + let p = progress_counter("removing old index files..."); + be.delete_list(FileType::Index, true, indexes_remove, p) .await?; } @@ -1107,9 +1098,8 @@ async fn find_used_blobs( ignore_snaps: Vec, ) -> Result> { let ignore_snaps: HashSet<_> = ignore_snaps.into_iter().collect(); - v1!("reading snapshots..."); - let p = progress_counter(); + let p = progress_counter("reading snapshots..."); let snap_trees: Vec<_> = index .be() .stream_all::(p.clone()) @@ -1122,11 +1112,10 @@ async fn find_used_blobs( .await?; p.finish(); - v1!("finding used blobs..."); let mut ids: HashMap<_, _> = snap_trees.iter().map(|id| (*id, 0)).collect(); + let p = progress_counter("finding used blobs..."); - let mut tree_streamer = - TreeStreamerOnce::new(index.clone(), snap_trees, progress_counter()).await?; + let mut tree_streamer = TreeStreamerOnce::new(index.clone(), snap_trees, p).await?; while let Some(item) = tree_streamer.try_next().await? { let (_, tree) = item; for node in tree.nodes() { diff --git a/src/commands/repoinfo.rs b/src/commands/repoinfo.rs index d55dcb1..d05bdd4 100644 --- a/src/commands/repoinfo.rs +++ b/src/commands/repoinfo.rs @@ -1,8 +1,8 @@ use anyhow::Result; use clap::Parser; use futures::TryStreamExt; +use log::*; use prettytable::{format, row, Table}; -use vlog::*; use super::{bytes, progress_counter}; use crate::backend::{DecryptReadBackend, ReadBackend, ALL_FILE_TYPES}; @@ -23,8 +23,7 @@ pub(super) async fn execute( fileinfo("hot repository files", hot_be).await?; } - v1!("scanning index..."); - let p = progress_counter(); + let p = progress_counter("scanning index..."); let mut stream = be.stream_all::(p.clone()).await?; #[derive(Default)] @@ -130,7 +129,7 @@ pub(super) async fn execute( } async fn fileinfo(text: &str, be: &impl ReadBackend) -> Result<()> { - v1!("scanning files..."); + info!("scanning files..."); let mut table = Table::new(); let mut total_count = 0; diff --git a/src/commands/restore.rs b/src/commands/restore.rs index a7df2af..ed3764c 100644 --- a/src/commands/restore.rs +++ b/src/commands/restore.rs @@ -9,12 +9,13 @@ use clap::{AppSettings, Parser}; use derive_getters::Dissolve; use futures::{stream::FuturesUnordered, TryStreamExt}; use ignore::{DirEntry, WalkBuilder}; +use log::*; use tokio::spawn; -use vlog::*; use super::{bytes, progress_bytes, progress_counter, wait, warm_up, warm_up_command}; use crate::backend::{DecryptReadBackend, FileType, LocalBackend}; use crate::blob::{Node, NodeStreamer, NodeType, Tree}; +use crate::commands::helpers::progress_spinner; use crate::crypto::hash; use crate::id::Id; use crate::index::{IndexBackend, IndexedBackend}; @@ -62,35 +63,34 @@ pub(super) async fn execute(be: &(impl DecryptReadBackend + Unpin), opts: Opts) if !command.contains("%id") { bail!("warm-up command must contain %id!") } - v1!("using warm-up command {command}") + info!("using warm-up command {command}") } let (id, path) = opts.snap.split_once(':').unwrap_or((&opts.snap, "")); - let snap = SnapshotFile::from_str(be, id, |_| true, progress_counter()).await?; + let snap = SnapshotFile::from_str(be, id, |_| true, progress_counter("")).await?; - let index = IndexBackend::new(be, progress_counter()).await?; + let index = IndexBackend::new(be, progress_counter("")).await?; let tree = Tree::subtree_id(&index, snap.tree, Path::new(path)).await?; let dest = LocalBackend::new(&opts.dest); - v1!("collecting restore information and allocating non-existing files..."); + let p = progress_spinner("collecting file information..."); let file_infos = allocate_and_collect(&dest, index.clone(), tree, &opts).await?; - v1!("total restore size: {}", bytes(file_infos.total_size)); + p.finish(); + info!("total restore size: {}", bytes(file_infos.total_size)); if file_infos.matched_size > 0 { - v1!( + info!( "using {} of existing file contents.", bytes(file_infos.matched_size) ); } if file_infos.total_size == file_infos.matched_size { - v1!("all file contents are fine."); + info!("all file contents are fine."); } else { if opts.warm_up { - v1!("warming up needed data pack files..."); warm_up(be, file_infos.to_packs()).await?; } else if opts.warm_up_command.is_some() { - v1!("warming up needed data pack files..."); warm_up_command( file_infos.to_packs(), opts.warm_up_command.as_ref().unwrap(), @@ -98,17 +98,17 @@ pub(super) async fn execute(be: &(impl DecryptReadBackend + Unpin), opts: Opts) } wait(opts.warm_up_wait).await; if !opts.dry_run { - v1!("restoring missing file contents..."); restore_contents(be, &dest, file_infos).await?; } } if !opts.dry_run { - v1!("setting metadata..."); + let p = progress_spinner("setting metadata..."); restore_metadata(&dest, index, tree, &opts).await?; + p.finish(); } - v1!("done."); + info!("restore done."); Ok(()) } @@ -157,7 +157,7 @@ async fn allocate_and_collect( } (true, false, false) => dest.remove_file(entry.path())?, (false, _, _) => { - v2!("additional entry: {:?}", entry.path()); + debug!("additional entry: {:?}", entry.path()); additional_existing = true; } } @@ -166,7 +166,7 @@ async fn allocate_and_collect( }; let mut process_node = |path: &PathBuf, node: &Node| -> Result<_> { - v3!("processing {:?}", path); + debug!("processing {:?}", path); match node.node_type() { NodeType::Dir => { if !opts.dry_run { @@ -234,7 +234,7 @@ async fn allocate_and_collect( } if additional_existing { - v1!("Note: additionals entries exist in destination"); + warn!("Note: additionals entries exist in destination"); } // empty dir stack and remove dirs @@ -254,7 +254,7 @@ async fn restore_contents( ) -> Result<()> { let (filenames, restore_info, total_size, matched_size) = file_infos.dissolve(); - let p = progress_bytes(); + let p = progress_bytes("restoring file contents..."); p.set_length(total_size - matched_size); let mut stream = FuturesUnordered::new(); @@ -356,20 +356,20 @@ async fn restore_metadata( } fn set_metadata(dest: &LocalBackend, path: &PathBuf, node: &Node, opts: &Opts) { - v3!("processing {:?}", path); + debug!("setting metadata for {:?}", path); dest.create_special(path, node) - .unwrap_or_else(|_| eprintln!("restore {:?}: creating special file failed.", path)); + .unwrap_or_else(|_| warn!("restore {:?}: creating special file failed.", path)); if opts.numeric_id { dest.set_uid_gid(path, node.meta()) - .unwrap_or_else(|_| eprintln!("restore {:?}: setting UID/GID failed.", path)); + .unwrap_or_else(|_| warn!("restore {:?}: setting UID/GID failed.", path)); } else { dest.set_user_group(path, node.meta()) - .unwrap_or_else(|_| eprintln!("restore {:?}: setting User/Group failed.", path)); + .unwrap_or_else(|_| warn!("restore {:?}: setting User/Group failed.", path)); } dest.set_permission(path, node.meta()) - .unwrap_or_else(|_| eprintln!("restore {:?}: chmod failed.", path)); + .unwrap_or_else(|_| warn!("restore {:?}: chmod failed.", path)); dest.set_times(path, node.meta()) - .unwrap_or_else(|_| eprintln!("restore {:?}: setting file times failed.", path)); + .unwrap_or_else(|_| warn!("restore {:?}: setting file times failed.", path)); } /// struct that contains information of file contents grouped by diff --git a/src/commands/rustic_config.rs b/src/commands/rustic_config.rs index 399fd4f..b68d27b 100644 --- a/src/commands/rustic_config.rs +++ b/src/commands/rustic_config.rs @@ -20,6 +20,8 @@ impl RusticConfig { let path = path.join(profile.to_string() + ".toml"); let config = if path.exists() { + // TODO: This should be log::info! - however, the logging config + // can be stored in the config file and is needed to initialize the logger eprintln!("using config {}", path.display()); let data = std::fs::read_to_string(path)?; toml::from_str(&data)? diff --git a/src/commands/tag.rs b/src/commands/tag.rs index fd150d4..e1115c7 100644 --- a/src/commands/tag.rs +++ b/src/commands/tag.rs @@ -108,11 +108,11 @@ pub(super) async fn execute( old_snap_ids ), (false, false) => { - println!("saving new snapshots..."); - be.save_list(snapshots, progress_counter()).await?; + let p = progress_counter("saving new snapshots..."); + be.save_list(snapshots, p).await?; - println!("deleting old snapshots..."); - be.delete_list(FileType::Snapshot, true, old_snap_ids, progress_counter()) + let p = progress_counter("deleting old snapshots..."); + be.delete_list(FileType::Snapshot, true, old_snap_ids, p) .await?; } } diff --git a/src/index/mod.rs b/src/index/mod.rs index c6a9d72..a1308e1 100644 --- a/src/index/mod.rs +++ b/src/index/mod.rs @@ -9,7 +9,6 @@ use derive_getters::Getters; use derive_more::Constructor; use futures::StreamExt; use indicatif::ProgressBar; -use vlog::*; use crate::backend::{DecryptReadBackend, FileType}; use crate::blob::BlobType; @@ -125,7 +124,7 @@ impl IndexBackend { p: ProgressBar, mut collector: IndexCollector, ) -> Result { - v1!("reading index..."); + p.set_prefix("reading index..."); let mut stream = be .stream_all::(p.clone()) .await? diff --git a/src/repo/snapshotfile.rs b/src/repo/snapshotfile.rs index 0e30bcc..f2d10fe 100644 --- a/src/repo/snapshotfile.rs +++ b/src/repo/snapshotfile.rs @@ -8,10 +8,10 @@ use clap::Parser; use derivative::Derivative; use futures::{future, TryStreamExt}; use indicatif::ProgressBar; +use log::*; use merge::Merge; use serde::{Deserialize, Serialize}; use serde_with::{serde_as, DisplayFromStr}; -use vlog::*; use super::Id; use crate::backend::{DecryptReadBackend, FileType, RepoFile}; @@ -130,7 +130,7 @@ impl SnapshotFile { predicate: impl FnMut(&Self) -> bool, p: ProgressBar, ) -> Result { - v1!("getting latest snapshot..."); + p.set_prefix("getting latest snapshot..."); let mut latest: Option = None; let mut pred = predicate; let mut snaps = be.stream_all::(p.clone()).await?; @@ -153,7 +153,7 @@ impl SnapshotFile { /// Get a SnapshotFile from the backend by (part of the) id pub async fn from_id(be: &B, id: &str) -> Result { - v1!("getting snapshot..."); + info!("getting snapshot..."); let id = be.find_id(FileType::Snapshot, id).await?; SnapshotFile::from_backend(be, &id).await }