Re: [pbs-devel] [RFC proxmox-backup 6/6] sync: improve log output

[Thomas Lamprecht <t.lamprecht@proxmox.com>]

On 21.07.20 15:03, Fabian Grünbichler wrote:
> add a bit more info and simplify some log statements.
> 
> Signed-off-by: Fabian Grünbichler <f.gruenbichler@proxmox.com>
> ---
> 
> Notes:
>     I am not sure whether this idea of 'last successful sync' == 'last successful
>     backup' is such a good idea in any case..
>     
>     this also might be too verbose for busy datastores - maybe just printing a
>     count of skipped, already previously synced snapshots is better?

yeah, IMO the "skipping snapshot {} - already synced" is to much, can generated
easily some thousands to hundred thousands of log lines in a big and "old"
datastore.

I'd then also put the count of skipped, already previously synced and "remote
returned {} snapshots" into one single line.

> 
>  src/client/pull.rs | 15 ++++++++++-----
>  1 file changed, 10 insertions(+), 5 deletions(-)
> 
> diff --git a/src/client/pull.rs b/src/client/pull.rs
> index 421260a3..1718c752 100644
> --- a/src/client/pull.rs
> +++ b/src/client/pull.rs
> @@ -310,8 +310,10 @@ pub async fn pull_group(
>          "backup-id": group.backup_id(),
>      });
>  
> +    worker.log(format!("sync group {}", group));
>      let mut result = client.get(&path, Some(args)).await?;
>      let mut list: Vec<SnapshotListItem> = serde_json::from_value(result["data"].take())?;
> +    worker.log(format!("remote returned {} snapshots", list.len()));
>  
>      list.sort_unstable_by(|a, b| a.backup_time.cmp(&b.backup_time));
>  
> @@ -336,7 +338,10 @@ pub async fn pull_group(
>          remote_snapshots.insert(backup_time);
>  
>          if let Some(last_sync_time) = last_sync {
> -            if last_sync_time > backup_time { continue; }
> +            if last_sync_time > backup_time {
> +                worker.log(format!("skipping snapshot {} - already synced", snapshot));
> +                continue;
> +            }
>          }
>  
>          let options = HttpClientOptions::new()
> @@ -411,14 +416,14 @@ pub async fn pull_store(
>          let owner = tgt_store.create_backup_group(&group, &username)?;
>          // permission check
>          if owner != username { // only the owner is allowed to create additional snapshots
> -            worker.log(format!("sync group {}/{} failed - owner check failed ({} != {})",
> -                               item.backup_type, item.backup_id, username, owner));
> +            worker.log(format!("sync group {} failed - owner check failed ({} != {})",
> +                               group, username, owner));
>              errors = true;
>              continue; // do not stop here, instead continue
>          }
>  
>          if let Err(err) = pull_group(worker, client, src_repo, tgt_store.clone(), &group, delete).await {
> -            worker.log(format!("sync group {}/{} failed - {}", item.backup_type, item.backup_id, err));
> +            worker.log(format!("sync group {} failed - {}", group, err));
>              errors = true;
>              continue; // do not stop here, instead continue
>          }
> @@ -429,7 +434,7 @@ pub async fn pull_store(
>              let local_groups = BackupGroup::list_groups(&tgt_store.base_path())?;
>              for local_group in local_groups {
>                  if new_groups.contains(&local_group) { continue; }
> -                worker.log(format!("delete vanished group '{}/{}'", local_group.backup_type(), local_group.backup_id()));
> +                worker.log(format!("delete vanished group '{}'", local_group));
>                  if let Err(err) = tgt_store.remove_backup_group(&local_group) {
>                      worker.log(err.to_string());
>                      errors = true;
>