From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id 9EDB3650D0 for ; Wed, 22 Jul 2020 09:31:41 +0200 (CEST) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id 8FD451DD4C for ; Wed, 22 Jul 2020 09:31:41 +0200 (CEST) Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com [212.186.127.180]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by firstgate.proxmox.com (Proxmox) with ESMTPS id 32F611DD3F for ; Wed, 22 Jul 2020 09:31:40 +0200 (CEST) Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1]) by proxmox-new.maurer-it.com (Proxmox) with ESMTP id EE7DC4330D for ; Wed, 22 Jul 2020 09:31:39 +0200 (CEST) To: Proxmox Backup Server development discussion , =?UTF-8?Q?Fabian_Gr=c3=bcnbichler?= References: <20200721130337.934653-1-f.gruenbichler@proxmox.com> <20200721130337.934653-7-f.gruenbichler@proxmox.com> From: Thomas Lamprecht Message-ID: <83fde4ca-9ebd-f240-7b10-aeb241ece75f@proxmox.com> Date: Wed, 22 Jul 2020 09:31:39 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:79.0) Gecko/20100101 Thunderbird/79.0 MIME-Version: 1.0 In-Reply-To: <20200721130337.934653-7-f.gruenbichler@proxmox.com> Content-Type: text/plain; charset=utf-8 Content-Language: en-US Content-Transfer-Encoding: quoted-printable X-SPAM-LEVEL: Spam detection results: 0 AWL 0.009 Adjusted score from AWL reputation of From: address KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment NICE_REPLY_A -0.001 Looks like a legit reply (A) RCVD_IN_DNSWL_MED -2.3 Sender listed at https://www.dnswl.org/, medium trust SPF_HELO_NONE 0.001 SPF: HELO does not publish an SPF Record SPF_PASS -0.001 SPF: sender matches SPF record URIBL_BLOCKED 0.001 ADMINISTRATOR NOTICE: The query to URIBL was blocked. See http://wiki.apache.org/spamassassin/DnsBlocklists#dnsbl-block for more information. [pull.rs] Subject: Re: [pbs-devel] [RFC proxmox-backup 6/6] sync: improve log output X-BeenThere: pbs-devel@lists.proxmox.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Proxmox Backup Server development discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 22 Jul 2020 07:31:41 -0000 On 21.07.20 15:03, Fabian Gr=C3=BCnbichler wrote: > add a bit more info and simplify some log statements. >=20 > Signed-off-by: Fabian Gr=C3=BCnbichler > --- >=20 > Notes: > I am not sure whether this idea of 'last successful sync' =3D=3D 'l= ast successful > backup' is such a good idea in any case.. > =20 > this also might be too verbose for busy datastores - maybe just pri= nting a > count of skipped, already previously synced snapshots is better? yeah, IMO the "skipping snapshot {} - already synced" is to much, can gen= erated 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 "re= mote returned {} snapshots" into one single line. >=20 > src/client/pull.rs | 15 ++++++++++----- > 1 file changed, 10 insertions(+), 5 deletions(-) >=20 > 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(), > }); > =20 > + worker.log(format!("sync group {}", group)); > let mut result =3D client.get(&path, Some(args)).await?; > let mut list: Vec =3D serde_json::from_value(res= ult["data"].take())?; > + worker.log(format!("remote returned {} snapshots", list.len())); > =20 > list.sort_unstable_by(|a, b| a.backup_time.cmp(&b.backup_time)); > =20 > @@ -336,7 +338,10 @@ pub async fn pull_group( > remote_snapshots.insert(backup_time); > =20 > if let Some(last_sync_time) =3D last_sync { > - if last_sync_time > backup_time { continue; } > + if last_sync_time > backup_time { > + worker.log(format!("skipping snapshot {} - already syn= ced", snapshot)); > + continue; > + } > } > =20 > let options =3D HttpClientOptions::new() > @@ -411,14 +416,14 @@ pub async fn pull_store( > let owner =3D tgt_store.create_backup_group(&group, &username)= ?; > // permission check > if owner !=3D username { // only the owner is allowed to creat= e additional snapshots > - worker.log(format!("sync group {}/{} failed - owner check = failed ({} !=3D {})", > - item.backup_type, item.backup_id, usern= ame, owner)); > + worker.log(format!("sync group {} failed - owner check fai= led ({} !=3D {})", > + group, username, owner)); > errors =3D true; > continue; // do not stop here, instead continue > } > =20 > if let Err(err) =3D pull_group(worker, client, src_repo, tgt_s= tore.clone(), &group, delete).await { > - worker.log(format!("sync group {}/{} failed - {}", item.ba= ckup_type, item.backup_id, err)); > + worker.log(format!("sync group {} failed - {}", group, err= )); > errors =3D true; > continue; // do not stop here, instead continue > } > @@ -429,7 +434,7 @@ pub async fn pull_store( > let local_groups =3D BackupGroup::list_groups(&tgt_store.b= ase_path())?; > for local_group in local_groups { > if new_groups.contains(&local_group) { continue; } > - worker.log(format!("delete vanished group '{}/{}'", lo= cal_group.backup_type(), local_group.backup_id())); > + worker.log(format!("delete vanished group '{}'", local= _group)); > if let Err(err) =3D tgt_store.remove_backup_group(&loc= al_group) { > worker.log(err.to_string()); > errors =3D true; >=20