[pbs-devel] [PATCH proxmox-backup] log: retrieve `ReaderEnvironment` debug flag from tracing

[pbs-devel] [PATCH proxmox-backup] log: retrieve `ReaderEnvironment` debug flag from tracing

[Gabriel Goller]

Don't hardcode the debug flag but retrieve the currently enabled level
using tracing. This will change the default log-behavior and disable
some logs that have been printed previously. F.e.: the "protocol upgrade
done" message is not visible anymore per default because it is printed
with debug.

Signed-off-by: Gabriel Goller <g.goller@proxmox.com>
---

Note that this still keeps the behavior of the client controlling the
log-level of the server, except if the server has a minimum log level of
warn.

 src/api2/backup/environment.rs | 11 ++++++++---
 src/api2/reader/environment.rs |  2 +-
 src/server/pull.rs             | 11 +++++++++--
 3 files changed, 18 insertions(+), 6 deletions(-)

diff --git a/src/api2/backup/environment.rs b/src/api2/backup/environment.rs
index 51f4a15b3c95..5bd508d00753 100644
--- a/src/api2/backup/environment.rs
+++ b/src/api2/backup/environment.rs
@@ -2,6 +2,7 @@ use anyhow::{bail, format_err, Error};
 use nix::dir::Dir;
 use std::collections::HashMap;
 use std::sync::{Arc, Mutex};
+use tracing::info;
 
 use ::serde::Serialize;
 use serde_json::{json, Value};
@@ -141,7 +142,7 @@ impl BackupEnvironment {
             auth_id,
             worker,
             datastore,
-            debug: false,
+            debug: tracing::enabled!(tracing::Level::DEBUG),
             formatter: JSON_FORMATTER,
             backup_dir,
             last_backup: None,
@@ -687,12 +688,16 @@ impl BackupEnvironment {
     }
 
     pub fn log<S: AsRef<str>>(&self, msg: S) {
-        self.worker.log_message(msg);
+        info!("{}", msg.as_ref());
     }
 
     pub fn debug<S: AsRef<str>>(&self, msg: S) {
         if self.debug {
-            self.worker.log_message(msg);
+            // This is kinda weird, we would like to use debug! here and automatically filter it,
+            // but self.debug is set from the client-side and the logs are printed on client and
+            // server side. This means that if the client sets the log level to debug, both server
+            // and client need to have 'debug' logs printed.
+            info!("{}", msg.as_ref());
         }
     }
 
diff --git a/src/api2/reader/environment.rs b/src/api2/reader/environment.rs
index 37039da2f573..25593bd0eeba 100644
--- a/src/api2/reader/environment.rs
+++ b/src/api2/reader/environment.rs
@@ -39,7 +39,7 @@ impl ReaderEnvironment {
             auth_id,
             worker,
             datastore,
-            debug: false,
+            debug: tracing::enabled!(tracing::Level::DEBUG),
             formatter: JSON_FORMATTER,
             backup_dir,
             allowed_chunks: Arc::new(RwLock::new(HashSet::new())),
diff --git a/src/server/pull.rs b/src/server/pull.rs
index 1ff9b92ab177..ff4b3a4168fa 100644
--- a/src/server/pull.rs
+++ b/src/server/pull.rs
@@ -278,8 +278,15 @@ impl PullSource for RemoteSource {
         ns: &BackupNamespace,
         dir: &BackupDir,
     ) -> Result<Arc<dyn PullReader>, Error> {
-        let backup_reader =
-            BackupReader::start(&self.client, None, self.repo.store(), ns, dir, true).await?;
+        let backup_reader = BackupReader::start(
+            &self.client,
+            None,
+            self.repo.store(),
+            ns,
+            dir,
+            tracing::enabled!(tracing::Level::DEBUG),
+        )
+        .await?;
         Ok(Arc::new(RemoteReader {
             backup_reader,
             dir: dir.clone(),
-- 
2.43.0



_______________________________________________
pbs-devel mailing list
pbs-devel@lists.proxmox.com
https://lists.proxmox.com/cgi-bin/mailman/listinfo/pbs-devel

Re: [pbs-devel] [PATCH proxmox-backup] log: retrieve `ReaderEnvironment` debug flag from tracing

[Christian Ebner]

one comment inline

On 7/15/24 17:13, Gabriel Goller wrote:
> Don't hardcode the debug flag but retrieve the currently enabled level
> using tracing. This will change the default log-behavior and disable
> some logs that have been printed previously. F.e.: the "protocol upgrade
> done" message is not visible anymore per default because it is printed
> with debug.
> 
> Signed-off-by: Gabriel Goller <g.goller@proxmox.com>
> ---
> 
> Note that this still keeps the behavior of the client controlling the
> log-level of the server, except if the server has a minimum log level of
> warn.
> 
>   src/api2/backup/environment.rs | 11 ++++++++---
>   src/api2/reader/environment.rs |  2 +-
>   src/server/pull.rs             | 11 +++++++++--
>   3 files changed, 18 insertions(+), 6 deletions(-)
> 
> diff --git a/src/api2/backup/environment.rs b/src/api2/backup/environment.rs
> index 51f4a15b3c95..5bd508d00753 100644
> --- a/src/api2/backup/environment.rs
> +++ b/src/api2/backup/environment.rs
> @@ -2,6 +2,7 @@ use anyhow::{bail, format_err, Error};
>   use nix::dir::Dir;
>   use std::collections::HashMap;
>   use std::sync::{Arc, Mutex};
> +use tracing::info;
>   
>   use ::serde::Serialize;
>   use serde_json::{json, Value};
> @@ -141,7 +142,7 @@ impl BackupEnvironment {
>               auth_id,
>               worker,
>               datastore,
> -            debug: false,
> +            debug: tracing::enabled!(tracing::Level::DEBUG),
>               formatter: JSON_FORMATTER,
>               backup_dir,
>               last_backup: None,
> @@ -687,12 +688,16 @@ impl BackupEnvironment {
>       }
>   
>       pub fn log<S: AsRef<str>>(&self, msg: S) {
> -        self.worker.log_message(msg);
> +        info!("{}", msg.as_ref());
>       }
>   
>       pub fn debug<S: AsRef<str>>(&self, msg: S) {
>           if self.debug {
> -            self.worker.log_message(msg);
> +            // This is kinda weird, we would like to use debug! here and automatically filter it,
> +            // but self.debug is set from the client-side and the logs are printed on client and
> +            // server side. This means that if the client sets the log level to debug, both server
> +            // and client need to have 'debug' logs printed.
> +            info!("{}", msg.as_ref());

This is indeed a bit odd: The fact that the client can set the `debug` 
flag when upgrading to the backup protocol, but cannot and should not 
control the filter level makes this a bit strange.

So I would suggest to rename this method to something like 
`client_debug` (or something better fitting?) an instead of calling the 
`info` macro directly, call `self.log` instead if `self.debug` is set. 
By this, it should at least be a bit more clear what is going on and one 
cannot accidentally loose these debug messages as the same codepath is 
then used for generating the event.

>           }
>       }
>   
> diff --git a/src/api2/reader/environment.rs b/src/api2/reader/environment.rs
> index 37039da2f573..25593bd0eeba 100644
> --- a/src/api2/reader/environment.rs
> +++ b/src/api2/reader/environment.rs
> @@ -39,7 +39,7 @@ impl ReaderEnvironment {
>               auth_id,
>               worker,
>               datastore,
> -            debug: false,
> +            debug: tracing::enabled!(tracing::Level::DEBUG),
>               formatter: JSON_FORMATTER,
>               backup_dir,
>               allowed_chunks: Arc::new(RwLock::new(HashSet::new())),
> diff --git a/src/server/pull.rs b/src/server/pull.rs
> index 1ff9b92ab177..ff4b3a4168fa 100644
> --- a/src/server/pull.rs
> +++ b/src/server/pull.rs
> @@ -278,8 +278,15 @@ impl PullSource for RemoteSource {
>           ns: &BackupNamespace,
>           dir: &BackupDir,
>       ) -> Result<Arc<dyn PullReader>, Error> {
> -        let backup_reader =
> -            BackupReader::start(&self.client, None, self.repo.store(), ns, dir, true).await?;
> +        let backup_reader = BackupReader::start(
> +            &self.client,
> +            None,
> +            self.repo.store(),
> +            ns,
> +            dir,
> +            tracing::enabled!(tracing::Level::DEBUG),
> +        )
> +        .await?;
>           Ok(Arc::new(RemoteReader {
>               backup_reader,
>               dir: dir.clone(),



_______________________________________________
pbs-devel mailing list
pbs-devel@lists.proxmox.com
https://lists.proxmox.com/cgi-bin/mailman/listinfo/pbs-devel

Re: [pbs-devel] [PATCH proxmox-backup] log: retrieve `ReaderEnvironment` debug flag from tracing

[Christian Ebner]

On 7/16/24 10:21, Christian Ebner wrote:
> 
> This is indeed a bit odd: The fact that the client can set the `debug` 
> flag when upgrading to the backup protocol, but cannot and should not 
> control the filter level makes this a bit strange.
> 
> So I would suggest to rename this method to something like 
> `client_debug` (or something better fitting?) an instead of calling the 
> `info` macro directly, call `self.log` instead if `self.debug` is set. 
> By this, it should at least be a bit more clear what is going on and one 
> cannot accidentally loose these debug messages as the same codepath is 
> then used for generating the event.
> 
Forgot to mention that by having a `debug` and a `client_debug` method, 
it would also be possible to differentiate log events generated by 
client request and ones only by level set for the server.



_______________________________________________
pbs-devel mailing list
pbs-devel@lists.proxmox.com
https://lists.proxmox.com/cgi-bin/mailman/listinfo/pbs-devel

Re: [pbs-devel] [PATCH proxmox-backup] log: retrieve `ReaderEnvironment` debug flag from tracing

[Gabriel Goller]

On 16.07.2024 10:21, Christian Ebner wrote:
>one comment inline
>
>On 7/15/24 17:13, Gabriel Goller wrote:
>>@@ -687,12 +688,16 @@ impl BackupEnvironment {
>>      }
>>      pub fn log<S: AsRef<str>>(&self, msg: S) {
>>-        self.worker.log_message(msg);
>>+        info!("{}", msg.as_ref());
>>      }
>>      pub fn debug<S: AsRef<str>>(&self, msg: S) {
>>          if self.debug {
>>-            self.worker.log_message(msg);
>>+            // This is kinda weird, we would like to use debug! here and automatically filter it,
>>+            // but self.debug is set from the client-side and the logs are printed on client and
>>+            // server side. This means that if the client sets the log level to debug, both server
>>+            // and client need to have 'debug' logs printed.
>>+            info!("{}", msg.as_ref());
>
>This is indeed a bit odd: The fact that the client can set the `debug` 
>flag when upgrading to the backup protocol, but cannot and should not 
>control the filter level makes this a bit strange.

Yeah, this is indeed kind of weird.
But I don't even think it's that stupid, because the output will be
printed on both server and client, so the client setting the loglevel is
fine I guess.

>So I would suggest to rename this method to something like 
>`client_debug` (or something better fitting?) 

Hmm, I don't know, the function doesn't only print to the client, it
also prints to the tasklog and thus on the server.

>and instead of calling the `info` macro directly, call `self.log`
>instead if `self.debug` is set. By this, it should at least be a bit
>more clear what is going on and one cannot accidentally loose these
>debug messages as the same codepath is then used for generating the
>event.

Yeah, that's a good idea...


I also though about adding the same stuff to the ReaderEnvironment as it
basically does the same thing.


_______________________________________________
pbs-devel mailing list
pbs-devel@lists.proxmox.com
https://lists.proxmox.com/cgi-bin/mailman/listinfo/pbs-devel