public inbox for pbs-devel@lists.proxmox.com
 help / color / mirror / Atom feed
* [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction
@ 2024-04-10 11:48 Gabriel Goller
  2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 1/3] removed task_log! macro and moved to tracing Gabriel Goller
                   ` (3 more replies)
  0 siblings, 4 replies; 5+ messages in thread
From: Gabriel Goller @ 2024-04-10 11:48 UTC (permalink / raw)
  To: pbs-devel

Removed the task_log! (and friends task_warn!, task_debug!, etc.) macro
and introduced the `tracing` crate. We now initiate the tracing crate
using a single layer, which is logging to the syslog and the tasklog.
It uses the `syslog` crate and the original `FileLogger`.

To write to the task logs from the worker threads and tasks, we now
have a task_local logger (and warning counter), which
will get instantiated when a task/thread is created. This means that
when we call `info!` or any other `tracing` log macros (with the "tasklog"
attribute), it will get the file_logger from TLS and write to the file.


v2: 
 - Rebase onto master
 - Split proxmox-backup commit into two

v1, thanks @Wolfgang, @Lukas:
 - Combined syslog and tasklog to single layer
 - Infer the logging target from the FileLogger TLS

RFC v2, thanks @Dominik, @Thomas:
 - Remove the 'tasklog = true' attribute and infer the context
    - Wrap the worker_thread or worker_task in a span with name
      'worker_task'
    - All events in the span with name 'worker_task' get logged to the
      file_logger, everything else goes to syslog (Error events go to
      both)
 - Remove the `Option<>` around the `FileLogger` in TLS
 - Clippy fixes

proxmox-backup:

Gabriel Goller (2):
  removed task_log! macro and moved to tracing
  removed task_log! macro and moved to tracing in api

 Cargo.toml                       |   7 +
 pbs-datastore/Cargo.toml         |   1 +
 pbs-datastore/src/chunk_store.rs |  30 +---
 pbs-datastore/src/datastore.rs   |  70 ++++-----
 src/api2/admin/datastore.rs      |  26 ++--
 src/api2/config/acme.rs          |  20 +--
 src/api2/config/datastore.rs     |  16 +-
 src/api2/config/prune.rs         |  14 +-
 src/api2/node/apt.rs             |  13 +-
 src/api2/node/certificates.rs    |  64 ++++----
 src/api2/node/disks/directory.rs |  13 +-
 src/api2/node/disks/mod.rs       |  12 +-
 src/api2/node/disks/zfs.rs       |  30 ++--
 src/api2/node/mod.rs             |  11 +-
 src/api2/pull.rs                 |  33 ++--
 src/api2/tape/backup.rs          |  72 ++++-----
 src/api2/tape/drive.rs           | 146 +++++++-----------
 src/api2/tape/restore.rs         | 254 ++++++++++---------------------
 src/backup/verify.rs             | 103 ++++---------
 src/bin/proxmox-backup-api.rs    |  10 +-
 src/bin/proxmox-backup-proxy.rs  |  42 ++---
 src/server/gc_job.rs             |   6 +-
 src/server/prune_job.rs          |  26 ++--
 src/server/pull.rs               | 230 +++++++++-------------------
 src/server/realm_sync_job.rs     |  40 ++---
 src/server/verify_job.rs         |  10 +-
 src/tape/drive/mod.rs            |  34 ++---
 src/tape/pool_writer/mod.rs      |  88 +++++------
 src/tools/disks/mod.rs           |  21 +--
 tests/worker-task-abort.rs       |   9 +-
 30 files changed, 513 insertions(+), 938 deletions(-)


proxmox:

Gabriel Goller (1):
  proxmox-log: added tracing infra

 Cargo.toml                                    |   6 +
 proxmox-log/Cargo.toml                        |  23 ++++
 proxmox-log/debian/changelog                  |   5 +
 proxmox-log/debian/control                    |  53 +++++++++
 proxmox-log/debian/copyright                  |  18 +++
 proxmox-log/debian/debcargo.toml              |   7 ++
 .../src/file_logger.rs                        |   2 +-
 proxmox-log/src/lib.rs                        |  34 ++++++
 proxmox-log/src/syslog_tasklog_layer.rs       | 106 +++++++++++++++++
 proxmox-rest-server/Cargo.toml                |   2 +
 proxmox-rest-server/src/api_config.rs         |   3 +-
 proxmox-rest-server/src/lib.rs                |   3 -
 proxmox-rest-server/src/rest.rs               |   4 +-
 proxmox-rest-server/src/worker_task.rs        | 108 +++++++++---------
 proxmox-sys/src/worker_task_context.rs        |  47 --------
 15 files changed, 315 insertions(+), 106 deletions(-)
 create mode 100644 proxmox-log/Cargo.toml
 create mode 100644 proxmox-log/debian/changelog
 create mode 100644 proxmox-log/debian/control
 create mode 100644 proxmox-log/debian/copyright
 create mode 100644 proxmox-log/debian/debcargo.toml
 rename {proxmox-rest-server => proxmox-log}/src/file_logger.rs (98%)
 create mode 100644 proxmox-log/src/lib.rs
 create mode 100644 proxmox-log/src/syslog_tasklog_layer.rs


Summary over all repositories:
  45 files changed, 828 insertions(+), 1044 deletions(-)

-- 
Generated by git-murpp 0.5.0




^ permalink raw reply	[flat|nested] 5+ messages in thread

* [pbs-devel] [PATCH proxmox-backup v2 1/3] removed task_log! macro and moved to tracing
  2024-04-10 11:48 [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
@ 2024-04-10 11:48 ` Gabriel Goller
  2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 2/3] removed task_log! macro and moved to tracing in api Gabriel Goller
                   ` (2 subsequent siblings)
  3 siblings, 0 replies; 5+ messages in thread
From: Gabriel Goller @ 2024-04-10 11:48 UTC (permalink / raw)
  To: pbs-devel

Imported `proxmox-log` and substituted all `task_log!`
(and task_warn!, task_error!) invocations with tracing calls (info!,
warn!, etc..). Removed worker references where it isn't necessary
anymore.

Signed-off-by: Gabriel Goller <g.goller@proxmox.com>
---
 Cargo.toml                       |   7 +
 pbs-datastore/Cargo.toml         |   1 +
 pbs-datastore/src/chunk_store.rs |  30 +---
 pbs-datastore/src/datastore.rs   |  70 ++++------
 src/backup/verify.rs             | 103 ++++----------
 src/bin/proxmox-backup-api.rs    |  10 +-
 src/bin/proxmox-backup-proxy.rs  |  42 ++----
 src/server/gc_job.rs             |   6 +-
 src/server/prune_job.rs          |  26 ++--
 src/server/pull.rs               | 230 ++++++++++---------------------
 src/server/realm_sync_job.rs     |  40 ++----
 src/server/verify_job.rs         |  10 +-
 src/tape/drive/mod.rs            |  34 ++---
 src/tape/pool_writer/mod.rs      |  88 +++++-------
 src/tools/disks/mod.rs           |  21 ++-
 tests/worker-task-abort.rs       |   9 +-
 16 files changed, 249 insertions(+), 478 deletions(-)

diff --git a/Cargo.toml b/Cargo.toml
index 4616e476..a7d20ea7 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -63,6 +63,7 @@ proxmox-http = { version = "0.9.0", features = [ "client", "http-helpers", "webs
 proxmox-human-byte = "0.1"
 proxmox-io = "1.0.1" # tools and client use "tokio" feature
 proxmox-lang = "1.1"
+proxmox-log = "0.1"
 proxmox-ldap = "0.2.1"
 proxmox-metrics = "0.3"
 proxmox-openid = "0.10.0"
@@ -144,6 +145,8 @@ tokio = "1.6"
 tokio-openssl = "0.6.1"
 tokio-stream = "0.1.0"
 tokio-util = { version = "0.7", features = [ "io" ] }
+tracing = "0.1"
+tracing-subscriber = "0.3.16"
 tower-service = "0.3.0"
 udev = "0.4"
 url = "2.1"
@@ -191,6 +194,8 @@ tokio = { workspace = true, features = [ "fs", "io-util", "io-std", "macros", "n
 tokio-openssl.workspace = true
 tokio-stream.workspace = true
 tokio-util = { workspace = true, features = [ "codec" ] }
+tracing.workspace = true
+tracing-subscriber.workspace = true
 tower-service.workspace = true
 udev.workspace = true
 url.workspace = true
@@ -209,6 +214,7 @@ proxmox-http = { workspace = true, features = [ "client-trait", "proxmox-async",
 proxmox-human-byte.workspace = true
 proxmox-io.workspace = true
 proxmox-lang.workspace = true
+proxmox-log.workspace = true
 proxmox-ldap.workspace = true
 proxmox-metrics.workspace = true
 proxmox-openid.workspace = true
@@ -255,6 +261,7 @@ proxmox-rrd.workspace = true
 #proxmox-human-byte = { path = "../proxmox/proxmox-human-byte" }
 #proxmox-io = { path = "../proxmox/proxmox-io" }
 #proxmox-lang = { path = "../proxmox/proxmox-lang" }
+#proxmox-log = { path = "../proxmox/proxmox-log" }
 #proxmox-ldap = { path = "../proxmox/proxmox-ldap" }
 #proxmox-metrics = { path = "../proxmox/proxmox-metrics" }
 #proxmox-openid = { path = "../proxmox/proxmox-openid" }
diff --git a/pbs-datastore/Cargo.toml b/pbs-datastore/Cargo.toml
index b793dc5b..fcb11ac4 100644
--- a/pbs-datastore/Cargo.toml
+++ b/pbs-datastore/Cargo.toml
@@ -20,6 +20,7 @@ openssl.workspace = true
 serde.workspace = true
 serde_json.workspace = true
 tokio = { workspace = true, features = [] }
+tracing.workspace = true
 walkdir.workspace = true
 zstd.workspace = true
 
diff --git a/pbs-datastore/src/chunk_store.rs b/pbs-datastore/src/chunk_store.rs
index 9f6289c9..8402d2fe 100644
--- a/pbs-datastore/src/chunk_store.rs
+++ b/pbs-datastore/src/chunk_store.rs
@@ -3,6 +3,7 @@ use std::path::{Path, PathBuf};
 use std::sync::{Arc, Mutex};
 
 use anyhow::{bail, format_err, Error};
+use tracing::info;
 
 use pbs_api_types::{DatastoreFSyncLevel, GarbageCollectionStatus};
 use proxmox_io::ReadExt;
@@ -10,7 +11,6 @@ use proxmox_sys::fs::{create_dir, create_path, file_type_from_file_stat, CreateO
 use proxmox_sys::process_locker::{
     ProcessLockExclusiveGuard, ProcessLockSharedGuard, ProcessLocker,
 };
-use proxmox_sys::task_log;
 use proxmox_sys::WorkerTaskContext;
 
 use crate::file_formats::{
@@ -92,7 +92,6 @@ impl ChunkStore {
         path: P,
         uid: nix::unistd::Uid,
         gid: nix::unistd::Gid,
-        worker: Option<&dyn WorkerTaskContext>,
         sync_level: DatastoreFSyncLevel,
     ) -> Result<Self, Error>
     where
@@ -143,9 +142,7 @@ impl ChunkStore {
             }
             let percentage = (i * 100) / (64 * 1024);
             if percentage != last_percentage {
-                if let Some(worker) = worker {
-                    task_log!(worker, "Chunkstore create: {}%", percentage)
-                }
+                info!("Chunkstore create: {}%", percentage);
                 last_percentage = percentage;
             }
         }
@@ -374,7 +371,7 @@ impl ChunkStore {
         for (entry, percentage, bad) in self.get_chunk_iterator()? {
             if last_percentage != percentage {
                 last_percentage = percentage;
-                task_log!(worker, "processed {}% ({} chunks)", percentage, chunk_count,);
+                info!("processed {}% ({} chunks)", percentage, chunk_count,);
             }
 
             worker.check_abort()?;
@@ -578,15 +575,8 @@ fn test_chunk_store1() {
     let user = nix::unistd::User::from_uid(nix::unistd::Uid::current())
         .unwrap()
         .unwrap();
-    let chunk_store = ChunkStore::create(
-        "test",
-        &path,
-        user.uid,
-        user.gid,
-        None,
-        DatastoreFSyncLevel::None,
-    )
-    .unwrap();
+    let chunk_store =
+        ChunkStore::create("test", &path, user.uid, user.gid, DatastoreFSyncLevel::None).unwrap();
 
     let (chunk, digest) = crate::data_blob::DataChunkBuilder::new(&[0u8, 1u8])
         .build()
@@ -598,14 +588,8 @@ fn test_chunk_store1() {
     let (exists, _) = chunk_store.insert_chunk(&chunk, &digest).unwrap();
     assert!(exists);
 
-    let chunk_store = ChunkStore::create(
-        "test",
-        &path,
-        user.uid,
-        user.gid,
-        None,
-        DatastoreFSyncLevel::None,
-    );
+    let chunk_store =
+        ChunkStore::create("test", &path, user.uid, user.gid, DatastoreFSyncLevel::None);
     assert!(chunk_store.is_err());
 
     if let Err(_e) = std::fs::remove_dir_all(".testdir") { /* ignore */ }
diff --git a/pbs-datastore/src/datastore.rs b/pbs-datastore/src/datastore.rs
index 0685cc84..f1a951ba 100644
--- a/pbs-datastore/src/datastore.rs
+++ b/pbs-datastore/src/datastore.rs
@@ -7,6 +7,7 @@ use std::sync::{Arc, Mutex};
 use anyhow::{bail, format_err, Error};
 use lazy_static::lazy_static;
 use nix::unistd::{unlinkat, UnlinkatFlags};
+use tracing::{info, warn};
 
 use proxmox_human_byte::HumanByte;
 use proxmox_schema::ApiType;
@@ -16,7 +17,6 @@ use proxmox_sys::fs::{file_read_optional_string, replace_file, CreateOptions};
 use proxmox_sys::fs::{lock_dir_noblock, DirLockGuard};
 use proxmox_sys::process_locker::ProcessLockSharedGuard;
 use proxmox_sys::WorkerTaskContext;
-use proxmox_sys::{task_log, task_warn};
 
 use pbs_api_types::{
     Authid, BackupNamespace, BackupType, ChunkOrder, DataStoreConfig, DatastoreFSyncLevel,
@@ -965,8 +965,7 @@ impl DataStore {
             let digest = index.index_digest(pos).unwrap();
             if !self.inner.chunk_store.cond_touch_chunk(digest, false)? {
                 let hex = hex::encode(digest);
-                task_warn!(
-                    worker,
+                warn!(
                     "warning: unable to access non-existent chunk {hex}, required by {file_name:?}"
                 );
 
@@ -1032,8 +1031,7 @@ impl DataStore {
 
             let percentage = (i + 1) * 100 / image_count;
             if percentage > last_percentage {
-                task_log!(
-                    worker,
+                info!(
                     "marked {}% ({} of {} index files)",
                     percentage,
                     i + 1,
@@ -1044,8 +1042,7 @@ impl DataStore {
         }
 
         if strange_paths_count > 0 {
-            task_log!(
-                worker,
+            info!(
                 "found (and marked) {} index files outside of expected directory scheme",
                 strange_paths_count,
             );
@@ -1085,11 +1082,11 @@ impl DataStore {
                 ..Default::default()
             };
 
-            task_log!(worker, "Start GC phase1 (mark used chunks)");
+            info!("Start GC phase1 (mark used chunks)");
 
             self.mark_used_chunks(&mut gc_status, worker)?;
 
-            task_log!(worker, "Start GC phase2 (sweep unused chunks)");
+            info!("Start GC phase2 (sweep unused chunks)");
             self.inner.chunk_store.sweep_unused_chunks(
                 oldest_writer,
                 phase1_start_time,
@@ -1097,30 +1094,27 @@ impl DataStore {
                 worker,
             )?;
 
-            task_log!(
-                worker,
+            info!(
                 "Removed garbage: {}",
                 HumanByte::from(gc_status.removed_bytes),
             );
-            task_log!(worker, "Removed chunks: {}", gc_status.removed_chunks);
+            info!("Removed chunks: {}", gc_status.removed_chunks);
             if gc_status.pending_bytes > 0 {
-                task_log!(
-                    worker,
+                info!(
                     "Pending removals: {} (in {} chunks)",
                     HumanByte::from(gc_status.pending_bytes),
                     gc_status.pending_chunks,
                 );
             }
             if gc_status.removed_bad > 0 {
-                task_log!(worker, "Removed bad chunks: {}", gc_status.removed_bad);
+                info!("Removed bad chunks: {}", gc_status.removed_bad);
             }
 
             if gc_status.still_bad > 0 {
-                task_log!(worker, "Leftover bad chunks: {}", gc_status.still_bad);
+                info!("Leftover bad chunks: {}", gc_status.still_bad);
             }
 
-            task_log!(
-                worker,
+            info!(
                 "Original data usage: {}",
                 HumanByte::from(gc_status.index_data_bytes),
             );
@@ -1128,15 +1122,14 @@ impl DataStore {
             if gc_status.index_data_bytes > 0 {
                 let comp_per =
                     (gc_status.disk_bytes as f64 * 100.) / gc_status.index_data_bytes as f64;
-                task_log!(
-                    worker,
+                info!(
                     "On-Disk usage: {} ({:.2}%)",
                     HumanByte::from(gc_status.disk_bytes),
                     comp_per,
                 );
             }
 
-            task_log!(worker, "On-Disk chunks: {}", gc_status.disk_chunks);
+            info!("On-Disk chunks: {}", gc_status.disk_chunks);
 
             let deduplication_factor = if gc_status.disk_bytes > 0 {
                 (gc_status.index_data_bytes as f64) / (gc_status.disk_bytes as f64)
@@ -1144,11 +1137,11 @@ impl DataStore {
                 1.0
             };
 
-            task_log!(worker, "Deduplication factor: {:.2}", deduplication_factor);
+            info!("Deduplication factor: {:.2}", deduplication_factor);
 
             if gc_status.disk_chunks > 0 {
                 let avg_chunk = gc_status.disk_bytes / (gc_status.disk_chunks as u64);
-                task_log!(worker, "Average chunk size: {}", HumanByte::from(avg_chunk));
+                info!("Average chunk size: {}", HumanByte::from(avg_chunk));
             }
 
             if let Ok(serialized) = serde_json::to_string(&gc_status) {
@@ -1380,11 +1373,7 @@ impl DataStore {
     /// Destroy a datastore. This requires that there are no active operations on the datastore.
     ///
     /// This is a synchronous operation and should be run in a worker-thread.
-    pub fn destroy(
-        name: &str,
-        destroy_data: bool,
-        worker: &dyn WorkerTaskContext,
-    ) -> Result<(), Error> {
+    pub fn destroy(name: &str, destroy_data: bool) -> Result<(), Error> {
         let config_lock = pbs_config::datastore::lock_config()?;
 
         let (mut config, _digest) = pbs_config::datastore::config()?;
@@ -1408,13 +1397,13 @@ impl DataStore {
             let remove = |subdir, ok: &mut bool| {
                 if let Err(err) = std::fs::remove_dir_all(base.join(subdir)) {
                     if err.kind() != io::ErrorKind::NotFound {
-                        task_warn!(worker, "failed to remove {subdir:?} subdirectory: {err}");
+                        warn!("failed to remove {subdir:?} subdirectory: {err}");
                         *ok = false;
                     }
                 }
             };
 
-            task_log!(worker, "Deleting datastore data...");
+            info!("Deleting datastore data...");
             remove("ns", &mut ok); // ns first
             remove("ct", &mut ok);
             remove("vm", &mut ok);
@@ -1423,7 +1412,7 @@ impl DataStore {
             if ok {
                 if let Err(err) = std::fs::remove_file(base.join(".gc-status")) {
                     if err.kind() != io::ErrorKind::NotFound {
-                        task_warn!(worker, "failed to remove .gc-status file: {err}");
+                        warn!("failed to remove .gc-status file: {err}");
                         ok = false;
                     }
                 }
@@ -1437,7 +1426,7 @@ impl DataStore {
 
         // now the config
         if ok {
-            task_log!(worker, "Removing datastore from config...");
+            info!("Removing datastore from config...");
             let _lock = pbs_config::datastore::lock_config()?;
             let _ = config.sections.remove(name);
             pbs_config::datastore::save_config(&config)?;
@@ -1448,35 +1437,32 @@ impl DataStore {
             if ok {
                 if let Err(err) = std::fs::remove_file(base.join(".lock")) {
                     if err.kind() != io::ErrorKind::NotFound {
-                        task_warn!(worker, "failed to remove .lock file: {err}");
+                        warn!("failed to remove .lock file: {err}");
                         ok = false;
                     }
                 }
             }
 
             if ok {
-                task_log!(worker, "Finished deleting data.");
+                info!("Finished deleting data.");
 
                 match std::fs::remove_dir(base) {
-                    Ok(()) => task_log!(worker, "Removed empty datastore directory."),
+                    Ok(()) => info!("Removed empty datastore directory."),
                     Err(err) if err.kind() == io::ErrorKind::NotFound => {
                         // weird, but ok
                     }
                     Err(err) if err.is_errno(nix::errno::Errno::EBUSY) => {
-                        task_warn!(
-                            worker,
-                            "Cannot delete datastore directory (is it a mount point?)."
-                        )
+                        warn!("Cannot delete datastore directory (is it a mount point?).")
                     }
                     Err(err) if err.is_errno(nix::errno::Errno::ENOTEMPTY) => {
-                        task_warn!(worker, "Datastore directory not empty, not deleting.")
+                        warn!("Datastore directory not empty, not deleting.")
                     }
                     Err(err) => {
-                        task_warn!(worker, "Failed to remove datastore directory: {err}");
+                        warn!("Failed to remove datastore directory: {err}");
                     }
                 }
             } else {
-                task_log!(worker, "There were errors deleting data.");
+                info!("There were errors deleting data.");
             }
         }
 
diff --git a/src/backup/verify.rs b/src/backup/verify.rs
index c972e532..dfad8824 100644
--- a/src/backup/verify.rs
+++ b/src/backup/verify.rs
@@ -5,8 +5,9 @@ use std::sync::{Arc, Mutex};
 use std::time::Instant;
 
 use anyhow::{bail, format_err, Error};
+use tracing::info;
 
-use proxmox_sys::{task_log, WorkerTaskContext};
+use proxmox_sys::WorkerTaskContext;
 
 use pbs_api_types::{
     print_ns_and_snapshot, print_store_and_ns, Authid, BackupNamespace, BackupType, CryptMode,
@@ -69,11 +70,7 @@ fn verify_blob(backup_dir: &BackupDir, info: &FileInfo) -> Result<(), Error> {
     }
 }
 
-fn rename_corrupted_chunk(
-    datastore: Arc<DataStore>,
-    digest: &[u8; 32],
-    worker: &dyn WorkerTaskContext,
-) {
+fn rename_corrupted_chunk(datastore: Arc<DataStore>, digest: &[u8; 32]) {
     let (path, digest_str) = datastore.chunk_path(digest);
 
     let mut counter = 0;
@@ -89,17 +86,12 @@ fn rename_corrupted_chunk(
 
     match std::fs::rename(&path, &new_path) {
         Ok(_) => {
-            task_log!(worker, "corrupted chunk renamed to {:?}", &new_path);
+            info!("corrupted chunk renamed to {:?}", &new_path);
         }
         Err(err) => {
             match err.kind() {
                 std::io::ErrorKind::NotFound => { /* ignored */ }
-                _ => task_log!(
-                    worker,
-                    "could not rename corrupted chunk {:?} - {}",
-                    &path,
-                    err
-                ),
+                _ => info!("could not rename corrupted chunk {:?} - {}", &path, err),
             }
         }
     };
@@ -117,7 +109,6 @@ fn verify_index_chunks(
     let mut read_bytes = 0;
     let mut decoded_bytes = 0;
 
-    let worker2 = Arc::clone(&verify_worker.worker);
     let datastore2 = Arc::clone(&verify_worker.datastore);
     let corrupt_chunks2 = Arc::clone(&verify_worker.corrupt_chunks);
     let verified_chunks2 = Arc::clone(&verify_worker.verified_chunks);
@@ -130,7 +121,7 @@ fn verify_index_chunks(
             let chunk_crypt_mode = match chunk.crypt_mode() {
                 Err(err) => {
                     corrupt_chunks2.lock().unwrap().insert(digest);
-                    task_log!(worker2, "can't verify chunk, unknown CryptMode - {}", err);
+                    info!("can't verify chunk, unknown CryptMode - {}", err);
                     errors2.fetch_add(1, Ordering::SeqCst);
                     return Ok(());
                 }
@@ -138,20 +129,18 @@ fn verify_index_chunks(
             };
 
             if chunk_crypt_mode != crypt_mode {
-                task_log!(
-                    worker2,
+                info!(
                     "chunk CryptMode {:?} does not match index CryptMode {:?}",
-                    chunk_crypt_mode,
-                    crypt_mode
+                    chunk_crypt_mode, crypt_mode
                 );
                 errors2.fetch_add(1, Ordering::SeqCst);
             }
 
             if let Err(err) = chunk.verify_unencrypted(size as usize, &digest) {
                 corrupt_chunks2.lock().unwrap().insert(digest);
-                task_log!(worker2, "{}", err);
+                info!("{}", err);
                 errors2.fetch_add(1, Ordering::SeqCst);
-                rename_corrupted_chunk(datastore2.clone(), &digest, &worker2);
+                rename_corrupted_chunk(datastore2.clone(), &digest);
             } else {
                 verified_chunks2.lock().unwrap().insert(digest);
             }
@@ -175,11 +164,7 @@ fn verify_index_chunks(
             .contains(digest)
         {
             let digest_str = hex::encode(digest);
-            task_log!(
-                verify_worker.worker,
-                "chunk {} was marked as corrupt",
-                digest_str
-            );
+            info!("chunk {} was marked as corrupt", digest_str);
             errors.fetch_add(1, Ordering::SeqCst);
             true
         } else {
@@ -218,17 +203,9 @@ fn verify_index_chunks(
                     .lock()
                     .unwrap()
                     .insert(info.digest);
-                task_log!(
-                    verify_worker.worker,
-                    "can't verify chunk, load failed - {}",
-                    err
-                );
+                info!("can't verify chunk, load failed - {}", err);
                 errors.fetch_add(1, Ordering::SeqCst);
-                rename_corrupted_chunk(
-                    verify_worker.datastore.clone(),
-                    &info.digest,
-                    &verify_worker.worker,
-                );
+                rename_corrupted_chunk(verify_worker.datastore.clone(), &info.digest);
             }
             Ok(chunk) => {
                 let size = info.size();
@@ -251,15 +228,9 @@ fn verify_index_chunks(
 
     let error_count = errors.load(Ordering::SeqCst);
 
-    task_log!(
-        verify_worker.worker,
+    info!(
         "  verified {:.2}/{:.2} MiB in {:.2} seconds, speed {:.2}/{:.2} MiB/s ({} errors)",
-        read_bytes_mib,
-        decoded_bytes_mib,
-        elapsed,
-        read_speed,
-        decode_speed,
-        error_count,
+        read_bytes_mib, decoded_bytes_mib, elapsed, read_speed, decode_speed, error_count,
     );
 
     if errors.load(Ordering::SeqCst) > 0 {
@@ -329,8 +300,7 @@ pub fn verify_backup_dir(
     filter: Option<&dyn Fn(&BackupManifest) -> bool>,
 ) -> Result<bool, Error> {
     if !backup_dir.full_path().exists() {
-        task_log!(
-            verify_worker.worker,
+        info!(
             "SKIPPED: verify {}:{} - snapshot does not exist (anymore).",
             verify_worker.datastore.name(),
             backup_dir.dir(),
@@ -348,8 +318,7 @@ pub fn verify_backup_dir(
             verify_backup_dir_with_lock(verify_worker, backup_dir, upid, filter, snap_lock)
         }
         Err(err) => {
-            task_log!(
-                verify_worker.worker,
+            info!(
                 "SKIPPED: verify {}:{} - could not acquire snapshot lock: {}",
                 verify_worker.datastore.name(),
                 backup_dir.dir(),
@@ -371,8 +340,7 @@ pub fn verify_backup_dir_with_lock(
     let manifest = match backup_dir.load_manifest() {
         Ok((manifest, _)) => manifest,
         Err(err) => {
-            task_log!(
-                verify_worker.worker,
+            info!(
                 "verify {}:{} - manifest load error: {}",
                 verify_worker.datastore.name(),
                 backup_dir.dir(),
@@ -384,8 +352,7 @@ pub fn verify_backup_dir_with_lock(
 
     if let Some(filter) = filter {
         if !filter(&manifest) {
-            task_log!(
-                verify_worker.worker,
+            info!(
                 "SKIPPED: verify {}:{} (recently verified)",
                 verify_worker.datastore.name(),
                 backup_dir.dir(),
@@ -394,8 +361,7 @@ pub fn verify_backup_dir_with_lock(
         }
     }
 
-    task_log!(
-        verify_worker.worker,
+    info!(
         "verify {}:{}",
         verify_worker.datastore.name(),
         backup_dir.dir()
@@ -406,7 +372,7 @@ pub fn verify_backup_dir_with_lock(
     let mut verify_result = VerifyState::Ok;
     for info in manifest.files() {
         let result = proxmox_lang::try_block!({
-            task_log!(verify_worker.worker, "  check {}", info.filename);
+            info!("  check {}", info.filename);
             match archive_type(&info.filename)? {
                 ArchiveType::FixedIndex => verify_fixed_index(verify_worker, backup_dir, info),
                 ArchiveType::DynamicIndex => verify_dynamic_index(verify_worker, backup_dir, info),
@@ -418,8 +384,7 @@ pub fn verify_backup_dir_with_lock(
         verify_worker.worker.fail_on_shutdown()?;
 
         if let Err(err) = result {
-            task_log!(
-                verify_worker.worker,
+            info!(
                 "verify {}:{}/{} failed: {}",
                 verify_worker.datastore.name(),
                 backup_dir.dir(),
@@ -463,8 +428,7 @@ pub fn verify_backup_group(
     let mut list = match group.list_backups() {
         Ok(list) => list,
         Err(err) => {
-            task_log!(
-                verify_worker.worker,
+            info!(
                 "verify {}, group {} - unable to list backups: {}",
                 print_store_and_ns(verify_worker.datastore.name(), group.backup_ns()),
                 group.group(),
@@ -475,8 +439,7 @@ pub fn verify_backup_group(
     };
 
     let snapshot_count = list.len();
-    task_log!(
-        verify_worker.worker,
+    info!(
         "verify group {}:{} ({} snapshots)",
         verify_worker.datastore.name(),
         group.group(),
@@ -494,9 +457,8 @@ pub fn verify_backup_group(
             ));
         }
         progress.done_snapshots = pos as u64 + 1;
-        task_log!(verify_worker.worker, "percentage done: {}", progress);
+        info!("percentage done: {}", progress);
     }
-
     Ok(errors)
 }
 
@@ -516,16 +478,11 @@ pub fn verify_all_backups(
     filter: Option<&dyn Fn(&BackupManifest) -> bool>,
 ) -> Result<Vec<String>, Error> {
     let mut errors = Vec::new();
-    let worker = Arc::clone(&verify_worker.worker);
 
-    task_log!(
-        worker,
-        "verify datastore {}",
-        verify_worker.datastore.name()
-    );
+    info!("verify datastore {}", verify_worker.datastore.name());
 
     let owner_filtered = if let Some(owner) = &owner {
-        task_log!(worker, "limiting to backups owned by {}", owner);
+        info!("limiting to backups owned by {}", owner);
         true
     } else {
         false
@@ -553,7 +510,7 @@ pub fn verify_all_backups(
                 }
                 Err(err) => {
                     // we don't filter by owner, but we want to log the error
-                    task_log!(worker, "error on iterating groups in ns '{ns}' - {err}");
+                    info!("error on iterating groups in ns '{ns}' - {err}");
                     errors.push(err.to_string());
                     None
                 }
@@ -563,7 +520,7 @@ pub fn verify_all_backups(
             })
             .collect::<Vec<BackupGroup>>(),
         Err(err) => {
-            task_log!(worker, "unable to list backups: {}", err,);
+            info!("unable to list backups: {}", err,);
             return Ok(errors);
         }
     };
@@ -571,7 +528,7 @@ pub fn verify_all_backups(
     list.sort_unstable_by(|a, b| a.group().cmp(b.group()));
 
     let group_count = list.len();
-    task_log!(worker, "found {} groups", group_count);
+    info!("found {} groups", group_count);
 
     let mut progress = StoreProgress::new(group_count as u64);
 
diff --git a/src/bin/proxmox-backup-api.rs b/src/bin/proxmox-backup-api.rs
index e46557a0..5555fbc3 100644
--- a/src/bin/proxmox-backup-api.rs
+++ b/src/bin/proxmox-backup-api.rs
@@ -7,6 +7,7 @@ use http::Response;
 use hyper::{Body, StatusCode};
 
 use proxmox_lang::try_block;
+use proxmox_log::init_logger;
 use proxmox_router::RpcEnvironmentType;
 use proxmox_sys::fs::CreateOptions;
 
@@ -15,6 +16,7 @@ use proxmox_rest_server::{daemon, ApiConfig, RestServer};
 use proxmox_backup::auth_helpers::*;
 use proxmox_backup::config;
 use proxmox_backup::server::auth::check_pbs_auth;
+use tracing_subscriber::filter::LevelFilter;
 
 fn main() {
     pbs_tools::setup_libc_malloc_opts();
@@ -40,13 +42,7 @@ fn get_index() -> Pin<Box<dyn Future<Output = Response<Body>> + Send>> {
 }
 
 async fn run() -> Result<(), Error> {
-    if let Err(err) = syslog::init(
-        syslog::Facility::LOG_DAEMON,
-        log::LevelFilter::Info,
-        Some("proxmox-backup-api"),
-    ) {
-        bail!("unable to inititialize syslog - {}", err);
-    }
+    init_logger("PBS_LOG", LevelFilter::INFO, "proxmox-backup-api")?;
 
     config::create_configdir()?;
 
diff --git a/src/bin/proxmox-backup-proxy.rs b/src/bin/proxmox-backup-proxy.rs
index f79ec2f5..96539350 100644
--- a/src/bin/proxmox-backup-proxy.rs
+++ b/src/bin/proxmox-backup-proxy.rs
@@ -7,6 +7,9 @@ use http::request::Parts;
 use http::Response;
 use hyper::header;
 use hyper::{Body, StatusCode};
+use proxmox_log::init_logger;
+use tracing::{info, warn};
+use tracing_subscriber::filter::LevelFilter;
 use url::form_urlencoded;
 
 use openssl::ssl::SslAcceptor;
@@ -18,7 +21,6 @@ use proxmox_router::{RpcEnvironment, RpcEnvironmentType};
 use proxmox_sys::fs::{CreateOptions, FileSystemInformation};
 use proxmox_sys::linux::procfs::{Loadavg, ProcFsMemInfo, ProcFsNetDev, ProcFsStat};
 use proxmox_sys::logrotate::LogRotate;
-use proxmox_sys::{task_log, task_warn};
 
 use pbs_datastore::DataStore;
 
@@ -181,21 +183,7 @@ async fn get_index_future(env: RestEnvironment, parts: Parts) -> Response<Body>
 }
 
 async fn run() -> Result<(), Error> {
-    // Note: To debug early connection error use
-    // PROXMOX_DEBUG=1 ./target/release/proxmox-backup-proxy
-    let debug = std::env::var("PROXMOX_DEBUG").is_ok();
-
-    if let Err(err) = syslog::init(
-        syslog::Facility::LOG_DAEMON,
-        if debug {
-            log::LevelFilter::Debug
-        } else {
-            log::LevelFilter::Info
-        },
-        Some("proxmox-backup-proxy"),
-    ) {
-        bail!("unable to inititialize syslog - {err}");
-    }
+    init_logger("PBS_LOG", LevelFilter::INFO, "proxmox-backup-proxy")?;
 
     proxmox_backup::auth_helpers::setup_auth_context(false);
 
@@ -300,7 +288,7 @@ async fn run() -> Result<(), Error> {
     })?;
 
     let connections = proxmox_rest_server::connection::AcceptBuilder::new()
-        .debug(debug)
+        .debug(tracing::enabled!(tracing::Level::DEBUG))
         .rate_limiter_lookup(Arc::new(lookup_rate_limiter))
         .tcp_keepalive_time(PROXMOX_BACKUP_TCP_KEEPALIVE_TIME);
 
@@ -749,7 +737,7 @@ async fn schedule_task_log_rotate() {
         false,
         move |worker| {
             job.start(&worker.upid().to_string())?;
-            task_log!(worker, "starting task log rotation");
+            info!("starting task log rotation");
 
             let result = try_block!({
                 let max_size = 512 * 1024 - 1; // an entry has ~ 100b, so > 5000 entries/file
@@ -774,9 +762,9 @@ async fn schedule_task_log_rotate() {
                 )?;
 
                 if has_rotated {
-                    task_log!(worker, "task log archive was rotated");
+                    info!("task log archive was rotated");
                 } else {
-                    task_log!(worker, "task log archive was not rotated");
+                    info!("task log archive was not rotated");
                 }
 
                 let max_size = 32 * 1024 * 1024 - 1;
@@ -792,9 +780,9 @@ async fn schedule_task_log_rotate() {
                 if logrotate.rotate(max_size)? {
                     println!("rotated access log, telling daemons to re-open log file");
                     proxmox_async::runtime::block_on(command_reopen_access_logfiles())?;
-                    task_log!(worker, "API access log was rotated");
+                    info!("API access log was rotated");
                 } else {
-                    task_log!(worker, "API access log was not rotated");
+                    info!("API access log was not rotated");
                 }
 
                 let mut logrotate = LogRotate::new(
@@ -807,15 +795,15 @@ async fn schedule_task_log_rotate() {
                 if logrotate.rotate(max_size)? {
                     println!("rotated auth log, telling daemons to re-open log file");
                     proxmox_async::runtime::block_on(command_reopen_auth_logfiles())?;
-                    task_log!(worker, "API authentication log was rotated");
+                    info!("API authentication log was rotated");
                 } else {
-                    task_log!(worker, "API authentication log was not rotated");
+                    info!("API authentication log was not rotated");
                 }
 
                 if has_rotated {
-                    task_log!(worker, "cleaning up old task logs");
-                    if let Err(err) = cleanup_old_tasks(&worker, true) {
-                        task_warn!(worker, "could not completely cleanup old tasks: {err}");
+                    info!("cleaning up old task logs");
+                    if let Err(err) = cleanup_old_tasks(true) {
+                        warn!("could not completely cleanup old tasks: {err}");
                     }
                 }
 
diff --git a/src/server/gc_job.rs b/src/server/gc_job.rs
index 41375d72..da3b002c 100644
--- a/src/server/gc_job.rs
+++ b/src/server/gc_job.rs
@@ -1,7 +1,7 @@
 use anyhow::Error;
 use std::sync::Arc;
 
-use proxmox_sys::task_log;
+use tracing::info;
 
 use pbs_api_types::Authid;
 use pbs_datastore::DataStore;
@@ -30,9 +30,9 @@ pub fn do_garbage_collection_job(
         move |worker| {
             job.start(&worker.upid().to_string())?;
 
-            task_log!(worker, "starting garbage collection on store {store}");
+            info!("starting garbage collection on store {store}");
             if let Some(event_str) = schedule {
-                task_log!(worker, "task triggered by schedule '{event_str}'");
+                info!("task triggered by schedule '{event_str}'");
             }
 
             let result = datastore.garbage_collection(&*worker, worker.upid());
diff --git a/src/server/prune_job.rs b/src/server/prune_job.rs
index 2de34973..83bcd7c3 100644
--- a/src/server/prune_job.rs
+++ b/src/server/prune_job.rs
@@ -1,8 +1,7 @@
 use std::sync::Arc;
 
 use anyhow::Error;
-
-use proxmox_sys::{task_log, task_warn};
+use tracing::{info, warn};
 
 use pbs_api_types::{
     print_store_and_ns, Authid, KeepOptions, Operation, PruneJobOptions, MAX_NAMESPACE_DEPTH,
@@ -16,7 +15,6 @@ use crate::backup::ListAccessibleBackupGroups;
 use crate::server::jobstate::Job;
 
 pub fn prune_datastore(
-    worker: Arc<WorkerTask>,
     auth_id: Authid,
     prune_options: PruneJobOptions,
     datastore: Arc<DataStore>,
@@ -31,19 +29,19 @@ pub fn prune_datastore(
     };
     let ns = prune_options.ns.clone().unwrap_or_default();
     let store_ns = print_store_and_ns(store, &ns);
-    task_log!(worker, "Starting datastore prune on {store_ns}, {depth}");
+    info!("Starting datastore prune on {store_ns}, {depth}");
 
     if dry_run {
-        task_log!(worker, "(dry test run)");
+        info!("(dry test run)");
     }
 
     let keep_all = !prune_options.keeps_something();
 
     if keep_all {
-        task_log!(worker, "No prune selection - keeping all files.");
+        info!("No prune selection - keeping all files.");
     } else {
         let rendered_options = cli_prune_options_string(&prune_options);
-        task_log!(worker, "retention options: {rendered_options}");
+        info!("retention options: {rendered_options}");
     }
 
     for group in ListAccessibleBackupGroups::new_with_privs(
@@ -61,8 +59,7 @@ pub fn prune_datastore(
         let mut prune_info = compute_prune_info(list, &prune_options.keep)?;
         prune_info.reverse(); // delete older snapshots first
 
-        task_log!(
-            worker,
+        info!(
             "Pruning group {ns}:\"{}/{}\"",
             group.backup_type(),
             group.backup_id()
@@ -70,8 +67,7 @@ pub fn prune_datastore(
 
         for (info, mark) in prune_info {
             let keep = keep_all || mark.keep();
-            task_log!(
-                worker,
+            info!(
                 "{}{} {}/{}/{}",
                 if dry_run { "would " } else { "" },
                 mark,
@@ -82,7 +78,7 @@ pub fn prune_datastore(
             if !keep && !dry_run {
                 if let Err(err) = datastore.remove_backup_dir(ns, info.backup_dir.as_ref(), false) {
                     let path = info.backup_dir.relative_path();
-                    task_warn!(worker, "failed to remove dir {path:?}: {err}");
+                    warn!("failed to remove dir {path:?}: {err}");
                 }
             }
         }
@@ -150,13 +146,13 @@ pub fn do_prune_job(
         move |worker| {
             job.start(&worker.upid().to_string())?;
 
-            task_log!(worker, "prune job '{}'", job.jobname());
+            info!("prune job '{}'", job.jobname());
 
             if let Some(event_str) = schedule {
-                task_log!(worker, "task triggered by schedule '{event_str}'");
+                info!("task triggered by schedule '{event_str}'");
             }
 
-            let result = prune_datastore(worker.clone(), auth_id, prune_options, datastore, false);
+            let result = prune_datastore(auth_id, prune_options, datastore, false);
 
             let status = worker.create_state(&result);
 
diff --git a/src/server/pull.rs b/src/server/pull.rs
index 14744e9c..f5d2b837 100644
--- a/src/server/pull.rs
+++ b/src/server/pull.rs
@@ -10,10 +10,9 @@ use std::time::{Duration, SystemTime};
 use anyhow::{bail, format_err, Error};
 use http::StatusCode;
 use proxmox_human_byte::HumanByte;
-use proxmox_rest_server::WorkerTask;
 use proxmox_router::HttpError;
-use proxmox_sys::{task_log, task_warn};
 use serde_json::json;
+use tracing::{info, warn};
 
 use pbs_api_types::{
     print_store_and_ns, Authid, BackupDir, BackupGroup, BackupNamespace, CryptMode, GroupFilter,
@@ -122,7 +121,6 @@ trait PullSource: Send + Sync {
     async fn list_namespaces(
         &self,
         max_depth: &mut Option<usize>,
-        worker: &WorkerTask,
     ) -> Result<Vec<BackupNamespace>, Error>;
 
     /// Lists groups within a specific namespace from the source.
@@ -137,7 +135,6 @@ trait PullSource: Send + Sync {
         &self,
         namespace: &BackupNamespace,
         group: &BackupGroup,
-        worker: &WorkerTask,
     ) -> Result<Vec<BackupDir>, Error>;
     fn get_ns(&self) -> BackupNamespace;
     fn get_store(&self) -> &str;
@@ -155,7 +152,6 @@ impl PullSource for RemoteSource {
     async fn list_namespaces(
         &self,
         max_depth: &mut Option<usize>,
-        worker: &WorkerTask,
     ) -> Result<Vec<BackupNamespace>, Error> {
         if self.ns.is_root() && max_depth.map_or(false, |depth| depth == 0) {
             return Ok(vec![self.ns.clone()]);
@@ -178,8 +174,8 @@ impl PullSource for RemoteSource {
                 Some(HttpError { code, message }) => match code {
                     &StatusCode::NOT_FOUND => {
                         if self.ns.is_root() && max_depth.is_none() {
-                            task_warn!(worker, "Could not query remote for namespaces (404) -> temporarily switching to backwards-compat mode");
-                            task_warn!(worker, "Either make backwards-compat mode explicit (max-depth == 0) or upgrade remote system.");
+                            warn!("Could not query remote for namespaces (404) -> temporarily switching to backwards-compat mode");
+                            warn!("Either make backwards-compat mode explicit (max-depth == 0) or upgrade remote system.");
                             max_depth.replace(0);
                         } else {
                             bail!("Remote namespace set/recursive sync requested, but remote does not support namespaces.")
@@ -238,7 +234,6 @@ impl PullSource for RemoteSource {
         &self,
         namespace: &BackupNamespace,
         group: &BackupGroup,
-        worker: &WorkerTask,
     ) -> Result<Vec<BackupDir>, Error> {
         let path = format!("api2/json/admin/datastore/{}/snapshots", self.repo.store());
 
@@ -261,11 +256,7 @@ impl PullSource for RemoteSource {
                 let snapshot = item.backup;
                 // in-progress backups can't be synced
                 if item.size.is_none() {
-                    task_log!(
-                        worker,
-                        "skipping snapshot {} - in-progress backup",
-                        snapshot
-                    );
+                    info!("skipping snapshot {} - in-progress backup", snapshot);
                     return None;
                 }
 
@@ -301,7 +292,6 @@ impl PullSource for LocalSource {
     async fn list_namespaces(
         &self,
         max_depth: &mut Option<usize>,
-        _worker: &WorkerTask,
     ) -> Result<Vec<BackupNamespace>, Error> {
         ListNamespacesRecursive::new_max_depth(
             self.store.clone(),
@@ -333,7 +323,6 @@ impl PullSource for LocalSource {
         &self,
         namespace: &BackupNamespace,
         group: &BackupGroup,
-        _worker: &WorkerTask,
     ) -> Result<Vec<BackupDir>, Error> {
         Ok(self
             .store
@@ -381,19 +370,10 @@ trait PullReader: Send + Sync {
     /// Asynchronously loads a file from the source into a local file.
     /// `filename` is the name of the file to load from the source.
     /// `into` is the path of the local file to load the source file into.
-    async fn load_file_into(
-        &self,
-        filename: &str,
-        into: &Path,
-        worker: &WorkerTask,
-    ) -> Result<Option<DataBlob>, Error>;
+    async fn load_file_into(&self, filename: &str, into: &Path) -> Result<Option<DataBlob>, Error>;
 
     /// Tries to download the client log from the source and save it into a local file.
-    async fn try_download_client_log(
-        &self,
-        to_path: &Path,
-        worker: &WorkerTask,
-    ) -> Result<(), Error>;
+    async fn try_download_client_log(&self, to_path: &Path) -> Result<(), Error>;
 
     fn skip_chunk_sync(&self, target_store_name: &str) -> bool;
 }
@@ -409,12 +389,7 @@ impl PullReader for RemoteReader {
         ))
     }
 
-    async fn load_file_into(
-        &self,
-        filename: &str,
-        into: &Path,
-        worker: &WorkerTask,
-    ) -> Result<Option<DataBlob>, Error> {
+    async fn load_file_into(&self, filename: &str, into: &Path) -> Result<Option<DataBlob>, Error> {
         let mut tmp_file = std::fs::OpenOptions::new()
             .write(true)
             .create(true)
@@ -426,8 +401,7 @@ impl PullReader for RemoteReader {
             match err.downcast_ref::<HttpError>() {
                 Some(HttpError { code, message }) => match *code {
                     StatusCode::NOT_FOUND => {
-                        task_log!(
-                            worker,
+                        info!(
                             "skipping snapshot {} - vanished since start of sync",
                             &self.dir,
                         );
@@ -446,11 +420,7 @@ impl PullReader for RemoteReader {
         Ok(DataBlob::load_from_reader(&mut tmp_file).ok())
     }
 
-    async fn try_download_client_log(
-        &self,
-        to_path: &Path,
-        worker: &WorkerTask,
-    ) -> Result<(), Error> {
+    async fn try_download_client_log(&self, to_path: &Path) -> Result<(), Error> {
         let mut tmp_path = to_path.to_owned();
         tmp_path.set_extension("tmp");
 
@@ -469,7 +439,7 @@ impl PullReader for RemoteReader {
             if let Err(err) = std::fs::rename(&tmp_path, to_path) {
                 bail!("Atomic rename file {:?} failed - {}", to_path, err);
             }
-            task_log!(worker, "got backup log file {:?}", CLIENT_LOG_BLOB_NAME);
+            info!("got backup log file {:?}", CLIENT_LOG_BLOB_NAME);
         }
 
         Ok(())
@@ -490,12 +460,7 @@ impl PullReader for LocalReader {
         ))
     }
 
-    async fn load_file_into(
-        &self,
-        filename: &str,
-        into: &Path,
-        _worker: &WorkerTask,
-    ) -> Result<Option<DataBlob>, Error> {
+    async fn load_file_into(&self, filename: &str, into: &Path) -> Result<Option<DataBlob>, Error> {
         let mut tmp_file = std::fs::OpenOptions::new()
             .write(true)
             .create(true)
@@ -509,11 +474,7 @@ impl PullReader for LocalReader {
         Ok(DataBlob::load_from_reader(&mut tmp_file).ok())
     }
 
-    async fn try_download_client_log(
-        &self,
-        _to_path: &Path,
-        _worker: &WorkerTask,
-    ) -> Result<(), Error> {
+    async fn try_download_client_log(&self, _to_path: &Path) -> Result<(), Error> {
         Ok(())
     }
 
@@ -603,7 +564,6 @@ impl PullParameters {
 }
 
 async fn pull_index_chunks<I: IndexFile>(
-    worker: &WorkerTask,
     chunk_reader: Arc<dyn AsyncReadChunk>,
     target: Arc<DataStore>,
     index: I,
@@ -658,10 +618,10 @@ async fn pull_index_chunks<I: IndexFile>(
                     target.cond_touch_chunk(&info.digest, false)
                 })?;
                 if chunk_exists {
-                    //task_log!(worker, "chunk {} exists {}", pos, hex::encode(digest));
+                    //info!("chunk {} exists {}", pos, hex::encode(digest));
                     return Ok::<_, Error>(());
                 }
-                //task_log!(worker, "sync {} chunk {}", pos, hex::encode(digest));
+                //info!("sync {} chunk {}", pos, hex::encode(digest));
                 let chunk = chunk_reader.read_raw_chunk(&info.digest).await?;
                 let raw_size = chunk.raw_size() as usize;
 
@@ -689,8 +649,7 @@ async fn pull_index_chunks<I: IndexFile>(
     let bytes = bytes.load(Ordering::SeqCst);
     let chunk_count = chunk_count.load(Ordering::SeqCst);
 
-    task_log!(
-        worker,
+    info!(
         "downloaded {} ({}/s)",
         HumanByte::from(bytes),
         HumanByte::new_binary(bytes as f64 / elapsed.as_secs_f64()),
@@ -730,7 +689,6 @@ fn verify_archive(info: &FileInfo, csum: &[u8; 32], size: u64) -> Result<(), Err
 /// - if archive is an index, pull referenced chunks
 /// - Rename tmp file into real path
 async fn pull_single_archive<'a>(
-    worker: &'a WorkerTask,
     reader: Arc<dyn PullReader + 'a>,
     snapshot: &'a pbs_datastore::BackupDir,
     archive_info: &'a FileInfo,
@@ -745,11 +703,9 @@ async fn pull_single_archive<'a>(
 
     let mut pull_stats = PullStats::default();
 
-    task_log!(worker, "sync archive {}", archive_name);
+    info!("sync archive {}", archive_name);
 
-    reader
-        .load_file_into(archive_name, &tmp_path, worker)
-        .await?;
+    reader.load_file_into(archive_name, &tmp_path).await?;
 
     let mut tmpfile = std::fs::OpenOptions::new().read(true).open(&tmp_path)?;
 
@@ -762,10 +718,9 @@ async fn pull_single_archive<'a>(
             verify_archive(archive_info, &csum, size)?;
 
             if reader.skip_chunk_sync(snapshot.datastore().name()) {
-                task_log!(worker, "skipping chunk sync for same datastore");
+                info!("skipping chunk sync for same datastore");
             } else {
                 let stats = pull_index_chunks(
-                    worker,
                     reader.chunk_reader(archive_info.crypt_mode),
                     snapshot.datastore().clone(),
                     index,
@@ -783,10 +738,9 @@ async fn pull_single_archive<'a>(
             verify_archive(archive_info, &csum, size)?;
 
             if reader.skip_chunk_sync(snapshot.datastore().name()) {
-                task_log!(worker, "skipping chunk sync for same datastore");
+                info!("skipping chunk sync for same datastore");
             } else {
                 let stats = pull_index_chunks(
-                    worker,
                     reader.chunk_reader(archive_info.crypt_mode),
                     snapshot.datastore().clone(),
                     index,
@@ -818,7 +772,6 @@ async fn pull_single_archive<'a>(
 /// -- if not, pull it from the remote
 /// - Download log if not already existing
 async fn pull_snapshot<'a>(
-    worker: &'a WorkerTask,
     reader: Arc<dyn PullReader + 'a>,
     snapshot: &'a pbs_datastore::BackupDir,
     downloaded_chunks: Arc<Mutex<HashSet<[u8; 32]>>>,
@@ -834,7 +787,7 @@ async fn pull_snapshot<'a>(
     tmp_manifest_name.set_extension("tmp");
     let tmp_manifest_blob;
     if let Some(data) = reader
-        .load_file_into(MANIFEST_BLOB_NAME, &tmp_manifest_name, worker)
+        .load_file_into(MANIFEST_BLOB_NAME, &tmp_manifest_name)
         .await?
     {
         tmp_manifest_blob = data;
@@ -857,11 +810,9 @@ async fn pull_snapshot<'a>(
 
         if manifest_blob.raw_data() == tmp_manifest_blob.raw_data() {
             if !client_log_name.exists() {
-                reader
-                    .try_download_client_log(&client_log_name, worker)
-                    .await?;
+                reader.try_download_client_log(&client_log_name).await?;
             };
-            task_log!(worker, "no data changes");
+            info!("no data changes");
             let _ = std::fs::remove_file(&tmp_manifest_name);
             return Ok(pull_stats); // nothing changed
         }
@@ -881,7 +832,7 @@ async fn pull_snapshot<'a>(
                     match manifest.verify_file(&item.filename, &csum, size) {
                         Ok(_) => continue,
                         Err(err) => {
-                            task_log!(worker, "detected changed file {:?} - {}", path, err);
+                            info!("detected changed file {:?} - {}", path, err);
                         }
                     }
                 }
@@ -891,7 +842,7 @@ async fn pull_snapshot<'a>(
                     match manifest.verify_file(&item.filename, &csum, size) {
                         Ok(_) => continue,
                         Err(err) => {
-                            task_log!(worker, "detected changed file {:?} - {}", path, err);
+                            info!("detected changed file {:?} - {}", path, err);
                         }
                     }
                 }
@@ -901,21 +852,15 @@ async fn pull_snapshot<'a>(
                     match manifest.verify_file(&item.filename, &csum, size) {
                         Ok(_) => continue,
                         Err(err) => {
-                            task_log!(worker, "detected changed file {:?} - {}", path, err);
+                            info!("detected changed file {:?} - {}", path, err);
                         }
                     }
                 }
             }
         }
 
-        let stats = pull_single_archive(
-            worker,
-            reader.clone(),
-            snapshot,
-            item,
-            downloaded_chunks.clone(),
-        )
-        .await?;
+        let stats =
+            pull_single_archive(reader.clone(), snapshot, item, downloaded_chunks.clone()).await?;
         pull_stats.add(stats);
     }
 
@@ -924,9 +869,7 @@ async fn pull_snapshot<'a>(
     }
 
     if !client_log_name.exists() {
-        reader
-            .try_download_client_log(&client_log_name, worker)
-            .await?;
+        reader.try_download_client_log(&client_log_name).await?;
     };
     snapshot
         .cleanup_unreferenced_files(&manifest)
@@ -940,7 +883,6 @@ async fn pull_snapshot<'a>(
 /// The `reader` is configured to read from the source backup directory, while the
 /// `snapshot` is pointing to the local datastore and target namespace.
 async fn pull_snapshot_from<'a>(
-    worker: &'a WorkerTask,
     reader: Arc<dyn PullReader + 'a>,
     snapshot: &'a pbs_datastore::BackupDir,
     downloaded_chunks: Arc<Mutex<HashSet<[u8; 32]>>>,
@@ -950,27 +892,27 @@ async fn pull_snapshot_from<'a>(
         .create_locked_backup_dir(snapshot.backup_ns(), snapshot.as_ref())?;
 
     let pull_stats = if is_new {
-        task_log!(worker, "sync snapshot {}", snapshot.dir());
+        info!("sync snapshot {}", snapshot.dir());
 
-        match pull_snapshot(worker, reader, snapshot, downloaded_chunks).await {
+        match pull_snapshot(reader, snapshot, downloaded_chunks).await {
             Err(err) => {
                 if let Err(cleanup_err) = snapshot.datastore().remove_backup_dir(
                     snapshot.backup_ns(),
                     snapshot.as_ref(),
                     true,
                 ) {
-                    task_log!(worker, "cleanup error - {}", cleanup_err);
+                    info!("cleanup error - {}", cleanup_err);
                 }
                 return Err(err);
             }
             Ok(pull_stats) => {
-                task_log!(worker, "sync snapshot {} done", snapshot.dir());
+                info!("sync snapshot {} done", snapshot.dir());
                 pull_stats
             }
         }
     } else {
-        task_log!(worker, "re-sync snapshot {}", snapshot.dir());
-        pull_snapshot(worker, reader, snapshot, downloaded_chunks).await?
+        info!("re-sync snapshot {}", snapshot.dir());
+        pull_snapshot(reader, snapshot, downloaded_chunks).await?
     };
 
     Ok(pull_stats)
@@ -1073,7 +1015,6 @@ impl std::fmt::Display for SkipInfo {
 /// - remote snapshot access is checked by remote (twice: query and opening the backup reader)
 /// - local group owner is already checked by pull_store
 async fn pull_group(
-    worker: &WorkerTask,
     params: &PullParameters,
     source_namespace: &BackupNamespace,
     group: &BackupGroup,
@@ -1084,7 +1025,7 @@ async fn pull_group(
 
     let mut raw_list: Vec<BackupDir> = params
         .source
-        .list_backup_dirs(source_namespace, group, worker)
+        .list_backup_dirs(source_namespace, group)
         .await?;
     raw_list.sort_unstable_by(|a, b| a.time.cmp(&b.time));
 
@@ -1113,7 +1054,7 @@ async fn pull_group(
                 already_synced_skip_info.update(dir.time);
                 return false;
             } else if already_synced_skip_info.count > 0 {
-                task_log!(worker, "{}", already_synced_skip_info);
+                info!("{}", already_synced_skip_info);
                 already_synced_skip_info.reset();
                 return true;
             }
@@ -1122,7 +1063,7 @@ async fn pull_group(
                 transfer_last_skip_info.update(dir.time);
                 return false;
             } else if transfer_last_skip_info.count > 0 {
-                task_log!(worker, "{}", transfer_last_skip_info);
+                info!("{}", transfer_last_skip_info);
                 transfer_last_skip_info.reset();
             }
             true
@@ -1147,11 +1088,10 @@ async fn pull_group(
             .source
             .reader(source_namespace, &from_snapshot)
             .await?;
-        let result =
-            pull_snapshot_from(worker, reader, &to_snapshot, downloaded_chunks.clone()).await;
+        let result = pull_snapshot_from(reader, &to_snapshot, downloaded_chunks.clone()).await;
 
         progress.done_snapshots = pos as u64 + 1;
-        task_log!(worker, "percentage done: {}", progress);
+        info!("percentage done: {}", progress);
 
         let stats = result?; // stop on error
         pull_stats.add(stats);
@@ -1169,14 +1109,13 @@ async fn pull_group(
                 continue;
             }
             if snapshot.is_protected() {
-                task_log!(
-                    worker,
+                info!(
                     "don't delete vanished snapshot {} (protected)",
                     snapshot.dir()
                 );
                 continue;
             }
-            task_log!(worker, "delete vanished snapshot {}", snapshot.dir());
+            info!("delete vanished snapshot {}", snapshot.dir());
             params
                 .target
                 .store
@@ -1235,7 +1174,6 @@ fn check_and_remove_ns(params: &PullParameters, local_ns: &BackupNamespace) -> R
 }
 
 fn check_and_remove_vanished_ns(
-    worker: &WorkerTask,
     params: &PullParameters,
     synced_ns: HashSet<BackupNamespace>,
 ) -> Result<(bool, RemovedVanishedStats), Error> {
@@ -1276,16 +1214,15 @@ fn check_and_remove_vanished_ns(
         }
         match check_and_remove_ns(params, &local_ns) {
             Ok(true) => {
-                task_log!(worker, "Removed namespace {local_ns}");
+                info!("Removed namespace {local_ns}");
                 removed_stats.namespaces += 1;
             }
-            Ok(false) => task_log!(
-                worker,
+            Ok(false) => info!(
                 "Did not remove namespace {} - protected snapshots remain",
                 local_ns
             ),
             Err(err) => {
-                task_log!(worker, "Failed to remove namespace {} - {}", local_ns, err);
+                info!("Failed to remove namespace {} - {}", local_ns, err);
                 errors = true;
             }
         }
@@ -1311,10 +1248,7 @@ fn check_and_remove_vanished_ns(
 /// - remote namespaces are filtered by remote
 /// - creation and removal of sub-NS checked here
 /// - access to sub-NS checked here
-pub(crate) async fn pull_store(
-    worker: &WorkerTask,
-    mut params: PullParameters,
-) -> Result<PullStats, Error> {
+pub(crate) async fn pull_store(mut params: PullParameters) -> Result<PullStats, Error> {
     // explicit create shared lock to prevent GC on newly created chunks
     let _shared_store_lock = params.target.store.try_shared_chunk_store_lock()?;
     let mut errors = false;
@@ -1323,10 +1257,7 @@ pub(crate) async fn pull_store(
     let mut namespaces = if params.source.get_ns().is_root() && old_max_depth == Some(0) {
         vec![params.source.get_ns()] // backwards compat - don't query remote namespaces!
     } else {
-        params
-            .source
-            .list_namespaces(&mut params.max_depth, worker)
-            .await?
+        params.source.list_namespaces(&mut params.max_depth).await?
     };
 
     let ns_layers_to_be_pulled = namespaces
@@ -1358,33 +1289,28 @@ pub(crate) async fn pull_store(
         let target_ns = namespace.map_prefix(&params.source.get_ns(), &params.target.ns)?;
         let target_store_ns_str = print_store_and_ns(params.target.store.name(), &target_ns);
 
-        task_log!(worker, "----");
-        task_log!(
-            worker,
+        info!("----");
+        info!(
             "Syncing {} into {}",
-            source_store_ns_str,
-            target_store_ns_str
+            source_store_ns_str, target_store_ns_str
         );
 
         synced_ns.insert(target_ns.clone());
 
         match check_and_create_ns(&params, &target_ns) {
-            Ok(true) => task_log!(worker, "Created namespace {}", target_ns),
+            Ok(true) => info!("Created namespace {}", target_ns),
             Ok(false) => {}
             Err(err) => {
-                task_log!(
-                    worker,
+                info!(
                     "Cannot sync {} into {} - {}",
-                    source_store_ns_str,
-                    target_store_ns_str,
-                    err,
+                    source_store_ns_str, target_store_ns_str, err,
                 );
                 errors = true;
                 continue;
             }
         }
 
-        match pull_ns(worker, &namespace, &mut params).await {
+        match pull_ns(&namespace, &mut params).await {
             Ok((ns_progress, ns_pull_stats, ns_errors)) => {
                 errors |= ns_errors;
 
@@ -1393,29 +1319,24 @@ pub(crate) async fn pull_store(
                 if params.max_depth != Some(0) {
                     groups += ns_progress.done_groups;
                     snapshots += ns_progress.done_snapshots;
-                    task_log!(
-                        worker,
+                    info!(
                         "Finished syncing namespace {}, current progress: {} groups, {} snapshots",
-                        namespace,
-                        groups,
-                        snapshots,
+                        namespace, groups, snapshots,
                     );
                 }
             }
             Err(err) => {
                 errors = true;
-                task_log!(
-                    worker,
+                info!(
                     "Encountered errors while syncing namespace {} - {}",
-                    &namespace,
-                    err,
+                    &namespace, err,
                 );
             }
         };
     }
 
     if params.remove_vanished {
-        let (has_errors, stats) = check_and_remove_vanished_ns(worker, &params, synced_ns)?;
+        let (has_errors, stats) = check_and_remove_vanished_ns(&params, synced_ns)?;
         errors |= has_errors;
         pull_stats.add(PullStats::from(stats));
     }
@@ -1440,7 +1361,6 @@ pub(crate) async fn pull_store(
 /// - remote namespaces are filtered by remote
 /// - owner check for vanished groups done here
 pub(crate) async fn pull_ns(
-    worker: &WorkerTask,
     namespace: &BackupNamespace,
     params: &mut PullParameters,
 ) -> Result<(StoreProgress, PullStats, bool), Error> {
@@ -1460,8 +1380,7 @@ pub(crate) async fn pull_ns(
         .into_iter()
         .filter(|group| group.apply_filters(&params.group_filter))
         .collect();
-    task_log!(
-        worker,
+    info!(
         "found {} groups to sync (out of {} total)",
         list.len(),
         unfiltered_count
@@ -1492,15 +1411,10 @@ pub(crate) async fn pull_ns(
             {
                 Ok(result) => result,
                 Err(err) => {
-                    task_log!(
-                        worker,
-                        "sync group {} failed - group lock failed: {}",
-                        &group,
-                        err
-                    );
+                    info!("sync group {} failed - group lock failed: {}", &group, err);
                     errors = true;
                     // do not stop here, instead continue
-                    task_log!(worker, "create_locked_backup_group failed");
+                    info!("create_locked_backup_group failed");
                     continue;
                 }
             };
@@ -1508,19 +1422,16 @@ pub(crate) async fn pull_ns(
         // permission check
         if params.owner != owner {
             // only the owner is allowed to create additional snapshots
-            task_log!(
-                worker,
+            info!(
                 "sync group {} failed - owner check failed ({} != {})",
-                &group,
-                params.owner,
-                owner
+                &group, params.owner, owner
             );
             errors = true; // do not stop here, instead continue
         } else {
-            match pull_group(worker, params, namespace, &group, &mut progress).await {
+            match pull_group(params, namespace, &group, &mut progress).await {
                 Ok(stats) => pull_stats.add(stats),
                 Err(err) => {
-                    task_log!(worker, "sync group {} failed - {}", &group, err,);
+                    info!("sync group {} failed - {}", &group, err,);
                     errors = true; // do not stop here, instead continue
                 }
             }
@@ -1542,7 +1453,7 @@ pub(crate) async fn pull_ns(
                 if !local_group.apply_filters(&params.group_filter) {
                     continue;
                 }
-                task_log!(worker, "delete vanished group '{local_group}'",);
+                info!("delete vanished group '{local_group}'",);
                 let delete_stats_result = params
                     .target
                     .store
@@ -1551,10 +1462,7 @@ pub(crate) async fn pull_ns(
                 match delete_stats_result {
                     Ok(stats) => {
                         if !stats.all_removed() {
-                            task_log!(
-                                worker,
-                                "kept some protected snapshots of group '{local_group}'",
-                            );
+                            info!("kept some protected snapshots of group '{local_group}'",);
                             pull_stats.add(PullStats::from(RemovedVanishedStats {
                                 snapshots: stats.removed_snapshots(),
                                 groups: 0,
@@ -1569,7 +1477,7 @@ pub(crate) async fn pull_ns(
                         }
                     }
                     Err(err) => {
-                        task_log!(worker, "{}", err);
+                        info!("{}", err);
                         errors = true;
                     }
                 }
@@ -1577,7 +1485,7 @@ pub(crate) async fn pull_ns(
             Ok(())
         });
         if let Err(err) = result {
-            task_log!(worker, "error during cleanup: {}", err);
+            info!("error during cleanup: {}", err);
             errors = true;
         };
     }
diff --git a/src/server/realm_sync_job.rs b/src/server/realm_sync_job.rs
index 972e9a6b..cd9ffc2c 100644
--- a/src/server/realm_sync_job.rs
+++ b/src/server/realm_sync_job.rs
@@ -1,13 +1,14 @@
 use anyhow::{bail, format_err, Context, Error};
+use tracing::{info, warn};
+
 use pbs_config::{acl::AclTree, token_shadow, BackupLockGuard};
 use proxmox_lang::try_block;
 use proxmox_ldap::{Config, Connection, SearchParameters, SearchResult};
 use proxmox_rest_server::WorkerTask;
 use proxmox_schema::{ApiType, Schema};
 use proxmox_section_config::SectionConfigData;
-use proxmox_sys::{task_log, task_warn};
 
-use std::{collections::HashSet, sync::Arc};
+use std::collections::HashSet;
 
 use pbs_api_types::{
     ApiToken, Authid, LdapRealmConfig, Realm, RemoveVanished, SyncAttributes as LdapSyncAttributes,
@@ -38,7 +39,7 @@ pub fn do_realm_sync_job(
         move |worker| {
             job.start(&worker.upid().to_string()).unwrap();
 
-            task_log!(worker, "starting realm sync for {}", realm.as_str());
+            info!("starting realm sync for {}", realm.as_str());
 
             let override_settings = GeneralSyncSettingsOverride {
                 remove_vanished,
@@ -46,7 +47,7 @@ pub fn do_realm_sync_job(
             };
 
             async move {
-                let sync_job = LdapRealmSyncJob::new(worker, realm, &override_settings, dry_run)?;
+                let sync_job = LdapRealmSyncJob::new(realm, &override_settings, dry_run)?;
                 sync_job.sync().await
             }
         },
@@ -57,7 +58,6 @@ pub fn do_realm_sync_job(
 
 /// Implementation for syncing LDAP realms
 struct LdapRealmSyncJob {
-    worker: Arc<WorkerTask>,
     realm: Realm,
     general_sync_settings: GeneralSyncSettings,
     ldap_sync_settings: LdapSyncSettings,
@@ -68,7 +68,6 @@ struct LdapRealmSyncJob {
 impl LdapRealmSyncJob {
     /// Create new LdapRealmSyncJob
     fn new(
-        worker: Arc<WorkerTask>,
         realm: Realm,
         override_settings: &GeneralSyncSettingsOverride,
         dry_run: bool,
@@ -93,7 +92,6 @@ impl LdapRealmSyncJob {
         let ldap_config = auth::LdapAuthenticator::api_type_to_config(&config)?;
 
         Ok(Self {
-            worker,
             realm,
             general_sync_settings: sync_settings,
             ldap_sync_settings: sync_attributes,
@@ -105,10 +103,7 @@ impl LdapRealmSyncJob {
     /// Perform realm synchronization
     async fn sync(&self) -> Result<(), Error> {
         if self.dry_run {
-            task_log!(
-                self.worker,
-                "this is a DRY RUN - changes will not be persisted"
-            );
+            info!("this is a DRY RUN - changes will not be persisted");
         }
 
         let ldap = Connection::new(self.ldap_config.clone());
@@ -190,7 +185,7 @@ impl LdapRealmSyncJob {
                 anyhow::Ok(())
             });
             if let Err(e) = result {
-                task_log!(self.worker, "could not create/update user: {e}");
+                info!("could not create/update user: {e}");
             }
         }
 
@@ -209,18 +204,10 @@ impl LdapRealmSyncJob {
 
         if let Some(existing_user) = existing_user {
             if existing_user != new_or_updated_user {
-                task_log!(
-                    self.worker,
-                    "updating user {}",
-                    new_or_updated_user.userid.as_str()
-                );
+                info!("updating user {}", new_or_updated_user.userid.as_str());
             }
         } else {
-            task_log!(
-                self.worker,
-                "creating user {}",
-                new_or_updated_user.userid.as_str()
-            );
+            info!("creating user {}", new_or_updated_user.userid.as_str());
         }
 
         user_config.set_data(
@@ -242,10 +229,7 @@ impl LdapRealmSyncJob {
             let schema = schema.unwrap_string_schema();
 
             if let Err(e) = schema.check_constraints(value) {
-                task_warn!(
-                    self.worker,
-                    "{userid}: ignoring attribute `{attribute}`: {e}"
-                );
+                warn!("{userid}: ignoring attribute `{attribute}`: {e}");
 
                 None
             } else {
@@ -324,7 +308,7 @@ impl LdapRealmSyncJob {
         to_delete: &[Userid],
     ) -> Result<(), Error> {
         for userid in to_delete {
-            task_log!(self.worker, "deleting user {}", userid.as_str());
+            info!("deleting user {}", userid.as_str());
 
             // Delete the user
             user_config.sections.remove(userid.as_str());
@@ -351,7 +335,7 @@ impl LdapRealmSyncJob {
 
                     if !self.dry_run {
                         if let Err(e) = token_shadow::delete_secret(&tokenid) {
-                            task_warn!(self.worker, "could not delete token for user {userid}: {e}",)
+                            warn!("could not delete token for user {userid}: {e}",)
                         }
                     }
 
diff --git a/src/server/verify_job.rs b/src/server/verify_job.rs
index 8bf2a0c9..94fd0279 100644
--- a/src/server/verify_job.rs
+++ b/src/server/verify_job.rs
@@ -1,9 +1,9 @@
 use anyhow::{format_err, Error};
+use tracing::info;
 
 use pbs_api_types::{Authid, Operation, VerificationJobConfig};
 use pbs_datastore::DataStore;
 use proxmox_rest_server::WorkerTask;
-use proxmox_sys::task_log;
 
 use crate::{
     backup::{verify_all_backups, verify_filter},
@@ -36,9 +36,9 @@ pub fn do_verification_job(
         move |worker| {
             job.start(&worker.upid().to_string())?;
 
-            task_log!(worker, "Starting datastore verify job '{}'", job_id);
+            info!("Starting datastore verify job '{}'", job_id);
             if let Some(event_str) = schedule {
-                task_log!(worker, "task triggered by schedule '{}'", event_str);
+                info!("task triggered by schedule '{}'", event_str);
             }
 
             let ns = match verification_job.ns {
@@ -60,9 +60,9 @@ pub fn do_verification_job(
             let job_result = match result {
                 Ok(ref failed_dirs) if failed_dirs.is_empty() => Ok(()),
                 Ok(ref failed_dirs) => {
-                    task_log!(worker, "Failed to verify the following snapshots/groups:");
+                    info!("Failed to verify the following snapshots/groups:");
                     for dir in failed_dirs {
-                        task_log!(worker, "\t{}", dir);
+                        info!("\t{}", dir);
                     }
 
                     Err(format_err!(
diff --git a/src/tape/drive/mod.rs b/src/tape/drive/mod.rs
index 8607d64b..383f710b 100644
--- a/src/tape/drive/mod.rs
+++ b/src/tape/drive/mod.rs
@@ -12,6 +12,7 @@ use nix::fcntl::OFlag;
 use nix::sys::stat::Mode;
 use serde::Deserialize;
 use serde_json::Value;
+use tracing::info;
 
 use proxmox_sys::fs::{
     atomic_open_or_create_file, file_read_optional_string, lock_file, replace_file, CreateOptions,
@@ -19,7 +20,7 @@ use proxmox_sys::fs::{
 
 use proxmox_io::ReadExt;
 use proxmox_section_config::SectionConfigData;
-use proxmox_sys::{task_log, WorkerTaskContext};
+use proxmox_sys::WorkerTaskContext;
 use proxmox_uuid::Uuid;
 
 use pbs_api_types::{Fingerprint, LtoTapeDrive, VirtualTapeDrive};
@@ -372,11 +373,9 @@ pub fn request_and_load_media(
 ) -> Result<(Box<dyn TapeDriver>, MediaId), Error> {
     let check_label = |handle: &mut dyn TapeDriver, uuid: &proxmox_uuid::Uuid| {
         if let Ok((Some(media_id), _)) = handle.read_label() {
-            task_log!(
-                worker,
+            info!(
                 "found media label {} ({})",
-                media_id.label.label_text,
-                media_id.label.uuid,
+                media_id.label.label_text, media_id.label.uuid,
             );
 
             if media_id.label.uuid == *uuid {
@@ -414,19 +413,16 @@ pub fn request_and_load_media(
                     let update_and_log_request_error =
                         |old: &mut TapeRequestError, new: TapeRequestError| -> Result<(), Error> {
                             if new != *old {
-                                task_log!(worker, "{}", new);
+                                info!("{}", new);
                                 let (device_type, device) = if let Some(changer) = changer {
                                     ("changer", changer.as_str())
                                 } else {
                                     ("drive", drive)
                                 };
 
-                                task_log!(
-                                    worker,
+                                info!(
                                     "Please insert media '{}' into {} '{}'",
-                                    label_text,
-                                    device_type,
-                                    device
+                                    label_text, device_type, device
                                 );
                                 if let Some(to) = notify_email {
                                     send_load_media_email(
@@ -452,18 +448,11 @@ pub fn request_and_load_media(
                                 std::thread::sleep(std::time::Duration::from_millis(100));
                             }
                         } else if drive_config.changer.is_none() {
-                            task_log!(
-                                worker,
-                                "Checking for media '{}' in drive '{}'",
-                                label_text,
-                                drive
-                            );
+                            info!("Checking for media '{}' in drive '{}'", label_text, drive);
                         } else {
-                            task_log!(
-                                worker,
+                            info!(
                                 "trying to load media '{}' into drive '{}'",
-                                label_text,
-                                drive
+                                label_text, drive
                             );
                         }
 
@@ -491,8 +480,7 @@ pub fn request_and_load_media(
 
                         let request_error = match handle.read_label() {
                             Ok((Some(media_id), _)) if media_id.label.uuid == label.uuid => {
-                                task_log!(
-                                    worker,
+                                info!(
                                     "found media label {} ({})",
                                     media_id.label.label_text,
                                     media_id.label.uuid.to_string(),
diff --git a/src/tape/pool_writer/mod.rs b/src/tape/pool_writer/mod.rs
index a6ba4a1d..c83709bb 100644
--- a/src/tape/pool_writer/mod.rs
+++ b/src/tape/pool_writer/mod.rs
@@ -11,8 +11,8 @@ use std::sync::{Arc, Mutex};
 use std::time::SystemTime;
 
 use anyhow::{bail, Error};
+use tracing::{info, warn};
 
-use proxmox_sys::{task_log, task_warn};
 use proxmox_uuid::Uuid;
 
 use pbs_datastore::{DataStore, SnapshotReader};
@@ -61,7 +61,6 @@ impl PoolWriter {
     pub fn new(
         mut pool: MediaPool,
         drive_name: &str,
-        worker: &WorkerTask,
         notify_email: Option<String>,
         force_media_set: bool,
         ns_magic: bool,
@@ -70,11 +69,11 @@ impl PoolWriter {
 
         let new_media_set_reason = pool.start_write_session(current_time, force_media_set)?;
         if let Some(reason) = new_media_set_reason {
-            task_log!(worker, "starting new media set - reason: {}", reason,);
+            info!("starting new media set - reason: {}", reason,);
         }
 
         let media_set_uuid = pool.current_media_set().uuid();
-        task_log!(worker, "media set uuid: {}", media_set_uuid);
+        info!("media set uuid: {}", media_set_uuid);
 
         let mut catalog_set = CatalogSet::new();
 
@@ -129,7 +128,7 @@ impl PoolWriter {
     }
 
     /// Eject media and drop PoolWriterState (close drive)
-    pub fn eject_media(&mut self, worker: &WorkerTask) -> Result<(), Error> {
+    pub fn eject_media(&mut self) -> Result<(), Error> {
         let mut status = match self.status.take() {
             Some(status) => status,
             None => return Ok(()), // no media loaded
@@ -138,13 +137,13 @@ impl PoolWriter {
         let (drive_config, _digest) = pbs_config::drive::config()?;
 
         if let Some((mut changer, _)) = media_changer(&drive_config, &self.drive_name)? {
-            task_log!(worker, "eject media");
+            info!("eject media");
             status.drive.eject_media()?; // rewind and eject early, so that unload_media is faster
             drop(status); // close drive
-            task_log!(worker, "unload media");
+            info!("unload media");
             changer.unload_media(None)?; //eject and unload
         } else {
-            task_log!(worker, "standalone drive - ejecting media");
+            info!("standalone drive - ejecting media");
             status.drive.eject_media()?;
         }
 
@@ -152,14 +151,14 @@ impl PoolWriter {
     }
 
     /// Export current media set and drop PoolWriterState (close drive)
-    pub fn export_media_set(&mut self, worker: &WorkerTask) -> Result<(), Error> {
+    pub fn export_media_set(&mut self) -> Result<(), Error> {
         let mut status = self.status.take();
 
         let (drive_config, _digest) = pbs_config::drive::config()?;
 
         if let Some((mut changer, _)) = media_changer(&drive_config, &self.drive_name)? {
             if let Some(ref mut status) = status {
-                task_log!(worker, "rewind media");
+                info!("rewind media");
                 // rewind first so that the unload command later does not run into a timeout
                 status.drive.rewind()?;
             }
@@ -169,25 +168,19 @@ impl PoolWriter {
                 let media = self.pool.lookup_media(media_uuid)?;
                 let label_text = media.label_text();
                 if let Some(slot) = changer.export_media(label_text)? {
-                    task_log!(
-                        worker,
+                    info!(
                         "exported media '{}' to import/export slot {}",
-                        label_text,
-                        slot
+                        label_text, slot
                     );
                 } else {
-                    task_warn!(
-                        worker,
+                    warn!(
                         "export failed - media '{}' is not online or in different drive",
                         label_text
                     );
                 }
             }
         } else if let Some(mut status) = status {
-            task_log!(
-                worker,
-                "standalone drive - ejecting media instead of export"
-            );
+            info!("standalone drive - ejecting media instead of export");
             status.drive.eject_media()?;
         }
 
@@ -228,15 +221,11 @@ impl PoolWriter {
             return Ok(media_uuid);
         }
 
-        task_log!(
-            worker,
-            "allocated new writable media '{}'",
-            media.label_text()
-        );
+        info!("allocated new writable media '{}'", media.label_text());
 
         if let Some(PoolWriterState { mut drive, .. }) = self.status.take() {
             if last_media_uuid.is_some() {
-                task_log!(worker, "eject current media");
+                info!("eject current media");
                 drive.eject_media()?;
             }
         }
@@ -254,7 +243,7 @@ impl PoolWriter {
         // test for critical tape alert flags
         if let Ok(alert_flags) = drive.tape_alert_flags() {
             if !alert_flags.is_empty() {
-                task_log!(worker, "TapeAlertFlags: {:?}", alert_flags);
+                info!("TapeAlertFlags: {:?}", alert_flags);
                 if tape_alert_flags_critical(alert_flags) {
                     self.pool.set_media_status_damaged(&media_uuid)?;
                     bail!(
@@ -265,20 +254,15 @@ impl PoolWriter {
             }
         }
 
-        let (catalog, is_new_media) = update_media_set_label(
-            worker,
-            drive.as_mut(),
-            old_media_id.media_set_label,
-            media.id(),
-        )?;
+        let (catalog, is_new_media) =
+            update_media_set_label(drive.as_mut(), old_media_id.media_set_label, media.id())?;
 
         self.catalog_set.lock().unwrap().append_catalog(catalog)?;
 
         let media_set = media.media_set_label().unwrap();
 
         if is_new_media && media_set.seq_nr >= MEDIA_SET_SEQ_NR_WARN_LIMIT {
-            task_warn!(
-                worker,
+            warn!(
                 "large media-set detected ({}), consider using a different allocation policy",
                 media_set.seq_nr
             );
@@ -295,7 +279,7 @@ impl PoolWriter {
 
         if is_new_media {
             // add catalogs from previous media
-            self.append_media_set_catalogs(worker)?;
+            self.append_media_set_catalogs()?;
         }
 
         self.used_tapes.insert(media_uuid.clone());
@@ -315,12 +299,12 @@ impl PoolWriter {
     // Check it tape is loaded, then move to EOM (if not already there)
     //
     // Returns the tape position at EOM.
-    fn prepare_tape_write(status: &mut PoolWriterState, worker: &WorkerTask) -> Result<u64, Error> {
+    fn prepare_tape_write(status: &mut PoolWriterState) -> Result<u64, Error> {
         if !status.at_eom {
-            task_log!(worker, "moving to end of media");
+            info!("moving to end of media");
             status.drive.move_to_eom(true)?;
             status.at_eom = true;
-            task_log!(worker, "arrived at end of media");
+            info!("arrived at end of media");
         }
 
         let current_file_number = status.drive.current_file_number()?;
@@ -341,7 +325,7 @@ impl PoolWriter {
     /// on the media (return value 'Ok(false, _)'). In that case, the
     /// archive is marked incomplete. The caller should mark the media
     /// as full and try again using another media.
-    pub fn append_catalog_archive(&mut self, worker: &WorkerTask) -> Result<bool, Error> {
+    pub fn append_catalog_archive(&mut self) -> Result<bool, Error> {
         let catalog_magic = self.catalog_version();
 
         let status = match self.status {
@@ -349,7 +333,7 @@ impl PoolWriter {
             None => bail!("PoolWriter - no media loaded"),
         };
 
-        Self::prepare_tape_write(status, worker)?;
+        Self::prepare_tape_write(status)?;
 
         let catalog_set = self.catalog_set.lock().unwrap();
 
@@ -392,7 +376,7 @@ impl PoolWriter {
     }
 
     // Append catalogs for all previous media in set (without last)
-    fn append_media_set_catalogs(&mut self, worker: &WorkerTask) -> Result<(), Error> {
+    fn append_media_set_catalogs(&mut self) -> Result<(), Error> {
         let media_set = self.pool.current_media_set();
 
         let mut media_list = media_set.media_list();
@@ -408,7 +392,7 @@ impl PoolWriter {
             None => bail!("PoolWriter - no media loaded"),
         };
 
-        Self::prepare_tape_write(status, worker)?;
+        Self::prepare_tape_write(status)?;
 
         for (seq_nr, uuid) in media_list.iter().enumerate() {
             let uuid = match uuid {
@@ -420,7 +404,7 @@ impl PoolWriter {
 
             let mut file = Self::open_catalog_file(uuid)?;
 
-            task_log!(worker, "write catalog for previous media: {}", uuid);
+            info!("write catalog for previous media: {}", uuid);
 
             if tape_write_catalog(
                 writer.as_mut(),
@@ -451,7 +435,6 @@ impl PoolWriter {
     /// media.
     pub fn append_snapshot_archive(
         &mut self,
-        worker: &WorkerTask,
         snapshot_reader: &SnapshotReader,
     ) -> Result<(bool, usize), Error> {
         let status = match self.status {
@@ -459,7 +442,7 @@ impl PoolWriter {
             None => bail!("PoolWriter - no media loaded"),
         };
 
-        let current_file_number = Self::prepare_tape_write(status, worker)?;
+        let current_file_number = Self::prepare_tape_write(status)?;
 
         let (done, bytes_written) = {
             let mut writer: Box<dyn TapeWrite> = status.drive.write_file()?;
@@ -505,7 +488,7 @@ impl PoolWriter {
             None => bail!("PoolWriter - no media loaded"),
         };
 
-        let current_file_number = Self::prepare_tape_write(status, worker)?;
+        let current_file_number = Self::prepare_tape_write(status)?;
 
         let writer = status.drive.write_file()?;
 
@@ -517,8 +500,7 @@ impl PoolWriter {
         status.bytes_written += bytes_written;
 
         let elapsed = start_time.elapsed()?.as_secs_f64();
-        task_log!(
-            worker,
+        info!(
             "wrote {} chunks ({:.2} MB at {:.2} MB/s)",
             saved_chunks.len(),
             bytes_written as f64 / 1_000_000.0,
@@ -598,7 +580,7 @@ fn write_chunk_archive<'a>(
         }
 
         if writer.bytes_written() > max_size {
-            //task_log!(worker, "Chunk Archive max size reached, closing archive");
+            //info!("Chunk Archive max size reached, closing archive");
             break;
         }
     }
@@ -612,7 +594,6 @@ fn write_chunk_archive<'a>(
 // set label does not match the expected media set, overwrite the
 // media set label.
 fn update_media_set_label(
-    worker: &WorkerTask,
     drive: &mut dyn TapeDriver,
     old_set: Option<MediaSetLabel>,
     media_id: &MediaId,
@@ -641,7 +622,7 @@ fn update_media_set_label(
 
     let new_media = match old_set {
         None => {
-            task_log!(worker, "writing new media set label");
+            info!("writing new media set label");
             drive.write_media_set_label(new_set, key_config.as_ref())?;
             media_catalog = MediaCatalog::overwrite(TAPE_STATUS_DIR, media_id, false)?;
             true
@@ -665,8 +646,7 @@ fn update_media_set_label(
 
                 false
             } else {
-                task_log!(
-                    worker,
+                info!(
                     "writing new media set label (overwrite '{}/{}')",
                     media_set_label.uuid.to_string(),
                     media_set_label.seq_nr,
diff --git a/src/tools/disks/mod.rs b/src/tools/disks/mod.rs
index 94f89e0a..f916416f 100644
--- a/src/tools/disks/mod.rs
+++ b/src/tools/disks/mod.rs
@@ -16,14 +16,13 @@ use ::serde::{Deserialize, Serialize};
 
 use proxmox_lang::error::io_err_other;
 use proxmox_lang::{io_bail, io_format_err};
-use proxmox_rest_server::WorkerTask;
 use proxmox_schema::api;
 use proxmox_sys::linux::procfs::{mountinfo::Device, MountInfo};
-use proxmox_sys::task_log;
 
 use pbs_api_types::{BLOCKDEVICE_DISK_AND_PARTITION_NAME_REGEX, BLOCKDEVICE_NAME_REGEX};
 
 mod zfs;
+use tracing::info;
 pub use zfs::*;
 mod zpool_status;
 pub use zpool_status::*;
@@ -1116,7 +1115,7 @@ pub fn inititialize_gpt_disk(disk: &Disk, uuid: Option<&str>) -> Result<(), Erro
 
 /// Wipes all labels and the first 200 MiB of a disk/partition (or the whole if it is smaller).
 /// If called with a partition, also sets the partition type to 0x83 'Linux filesystem'.
-pub fn wipe_blockdev(disk: &Disk, worker: Arc<WorkerTask>) -> Result<(), Error> {
+pub fn wipe_blockdev(disk: &Disk) -> Result<(), Error> {
     let disk_path = match disk.device_path() {
         Some(path) => path,
         None => bail!("disk {:?} has no node in /dev", disk.syspath()),
@@ -1137,13 +1136,13 @@ pub fn wipe_blockdev(disk: &Disk, worker: Arc<WorkerTask>) -> Result<(), Error>
 
     to_wipe.push(disk_path.to_path_buf());
 
-    task_log!(worker, "Wiping block device {}", disk_path.display());
+    info!("Wiping block device {}", disk_path.display());
 
     let mut wipefs_command = std::process::Command::new("wipefs");
     wipefs_command.arg("--all").args(&to_wipe);
 
     let wipefs_output = proxmox_sys::command::run_command(wipefs_command, None)?;
-    task_log!(worker, "wipefs output: {}", wipefs_output);
+    info!("wipefs output: {}", wipefs_output);
 
     let size = disk.size().map(|size| size / 1024 / 1024)?;
     let count = size.min(200);
@@ -1163,21 +1162,17 @@ pub fn wipe_blockdev(disk: &Disk, worker: Arc<WorkerTask>) -> Result<(), Error>
     dd_command.args(args);
 
     let dd_output = proxmox_sys::command::run_command(dd_command, None)?;
-    task_log!(worker, "dd output: {}", dd_output);
+    info!("dd output: {}", dd_output);
 
     if is_partition {
         // set the partition type to 0x83 'Linux filesystem'
-        change_parttype(disk, "8300", worker)?;
+        change_parttype(disk, "8300")?;
     }
 
     Ok(())
 }
 
-pub fn change_parttype(
-    part_disk: &Disk,
-    part_type: &str,
-    worker: Arc<WorkerTask>,
-) -> Result<(), Error> {
+pub fn change_parttype(part_disk: &Disk, part_type: &str) -> Result<(), Error> {
     let part_path = match part_disk.device_path() {
         Some(path) => path,
         None => bail!("disk {:?} has no node in /dev", part_disk.syspath()),
@@ -1199,7 +1194,7 @@ pub fn change_parttype(
         };
         sgdisk_command.arg(part_disk_parent_path);
         let sgdisk_output = proxmox_sys::command::run_command(sgdisk_command, None)?;
-        task_log!(worker, "sgdisk output: {}", sgdisk_output);
+        info!("sgdisk output: {}", sgdisk_output);
     }
     Ok(())
 }
diff --git a/tests/worker-task-abort.rs b/tests/worker-task-abort.rs
index eda86f01..80243dbb 100644
--- a/tests/worker-task-abort.rs
+++ b/tests/worker-task-abort.rs
@@ -7,24 +7,25 @@ extern crate tokio;
 
 use proxmox_lang::try_block;
 use proxmox_sys::fs::CreateOptions;
-use proxmox_sys::{task_log, WorkerTaskContext};
+use proxmox_sys::WorkerTaskContext;
 
 use pbs_api_types::{Authid, UPID};
 
 use proxmox_rest_server::{CommandSocket, WorkerTask};
+use tracing::info;
 
 fn garbage_collection(worker: &WorkerTask) -> Result<(), Error> {
-    task_log!(worker, "start garbage collection");
+    info!("start garbage collection");
 
     for i in 0..50 {
         worker.check_abort()?;
 
-        task_log!(worker, "progress {}", i);
+        info!("progress {}", i);
 
         std::thread::sleep(std::time::Duration::from_millis(10));
     }
 
-    task_log!(worker, "end garbage collection");
+    info!("end garbage collection");
 
     Ok(())
 }
-- 
2.43.0





^ permalink raw reply	[flat|nested] 5+ messages in thread

* [pbs-devel] [PATCH proxmox-backup v2 2/3] removed task_log! macro and moved to tracing in api
  2024-04-10 11:48 [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
  2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 1/3] removed task_log! macro and moved to tracing Gabriel Goller
@ 2024-04-10 11:48 ` Gabriel Goller
  2024-04-10 11:49 ` [pbs-devel] [PATCH proxmox v2 3/3] proxmox-log: added tracing infra Gabriel Goller
  2024-04-10 14:17 ` [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
  3 siblings, 0 replies; 5+ messages in thread
From: Gabriel Goller @ 2024-04-10 11:48 UTC (permalink / raw)
  To: pbs-devel

Imported `proxmox-log` and substituted all `task_log!`
(and task_warn!, task_error!) invocations with tracing calls (info!,
warn!, etc..). Removed worker references where it isn't necessary
anymore.

Signed-off-by: Gabriel Goller <g.goller@proxmox.com>
---
 src/api2/admin/datastore.rs      |  26 ++--
 src/api2/config/acme.rs          |  20 +--
 src/api2/config/datastore.rs     |  16 +-
 src/api2/config/prune.rs         |  14 +-
 src/api2/node/apt.rs             |  13 +-
 src/api2/node/certificates.rs    |  64 ++++----
 src/api2/node/disks/directory.rs |  13 +-
 src/api2/node/disks/mod.rs       |  12 +-
 src/api2/node/disks/zfs.rs       |  30 ++--
 src/api2/node/mod.rs             |  11 +-
 src/api2/pull.rs                 |  33 ++--
 src/api2/tape/backup.rs          |  72 ++++-----
 src/api2/tape/drive.rs           | 146 +++++++-----------
 src/api2/tape/restore.rs         | 254 ++++++++++---------------------
 14 files changed, 264 insertions(+), 460 deletions(-)

diff --git a/src/api2/admin/datastore.rs b/src/api2/admin/datastore.rs
index 35628c59..2757da6e 100644
--- a/src/api2/admin/datastore.rs
+++ b/src/api2/admin/datastore.rs
@@ -13,6 +13,7 @@ use hyper::{header, Body, Response, StatusCode};
 use serde::Deserialize;
 use serde_json::{json, Value};
 use tokio_stream::wrappers::ReceiverStream;
+use tracing::{info, warn};
 
 use proxmox_async::blocking::WrappedReaderStream;
 use proxmox_async::{io::AsyncChannelWriter, stream::AsyncReaderStream};
@@ -26,7 +27,6 @@ use proxmox_sortable_macro::sortable;
 use proxmox_sys::fs::{
     file_read_firstline, file_read_optional_string, replace_file, CreateOptions,
 };
-use proxmox_sys::{task_log, task_warn};
 
 use pxar::accessor::aio::Accessor;
 use pxar::EntryKind;
@@ -908,9 +908,9 @@ pub fn verify(
                 )?
             };
             if !failed_dirs.is_empty() {
-                task_log!(worker, "Failed to verify the following snapshots/groups:");
+                info!("Failed to verify the following snapshots/groups:");
                 for dir in failed_dirs {
-                    task_log!(worker, "\t{}", dir);
+                    info!("\t{}", dir);
                 }
                 bail!("verification failed - please check the log for details");
             }
@@ -1030,9 +1030,9 @@ pub fn prune(
         return Ok(json!(prune_result));
     }
 
-    let prune_group = move |worker: Arc<WorkerTask>| {
+    let prune_group = move |_worker: Arc<WorkerTask>| {
         if keep_all {
-            task_log!(worker, "No prune selection - keeping all files.");
+            info!("No prune selection - keeping all files.");
         } else {
             let mut opts = Vec::new();
             if !ns.is_root() {
@@ -1040,9 +1040,8 @@ pub fn prune(
             }
             crate::server::cli_keep_options(&mut opts, &keep_options);
 
-            task_log!(worker, "retention options: {}", opts.join(" "));
-            task_log!(
-                worker,
+            info!("retention options: {}", opts.join(" "));
+            info!(
                 "Starting prune on {} group \"{}\"",
                 print_store_and_ns(&store, &ns),
                 group.group(),
@@ -1059,7 +1058,7 @@ pub fn prune(
 
             let msg = format!("{}/{}/{timestamp} {mark}", group.ty, group.id);
 
-            task_log!(worker, "{msg}");
+            info!("{msg}");
 
             prune_result.push(PruneResult {
                 backup_type: group.ty,
@@ -1072,8 +1071,7 @@ pub fn prune(
 
             if !keep {
                 if let Err(err) = backup_dir.destroy(false) {
-                    task_warn!(
-                        worker,
+                    warn!(
                         "failed to remove dir {:?}: {}",
                         backup_dir.relative_path(),
                         err,
@@ -1097,7 +1095,7 @@ pub fn prune(
         )?;
         Ok(json!(upid))
     } else {
-        let worker = WorkerTask::new("prune", Some(worker_id), auth_id.to_string(), true)?;
+        let (worker, _) = WorkerTask::new("prune", Some(worker_id), auth_id.to_string(), true)?;
         let result = prune_group(worker.clone());
         worker.log_result(&Ok(()));
         Ok(json!(result))
@@ -1160,9 +1158,7 @@ pub fn prune_datastore(
         Some(worker_id),
         auth_id.to_string(),
         to_stdout,
-        move |worker| {
-            crate::server::prune_datastore(worker, auth_id, prune_options, datastore, dry_run)
-        },
+        move |_worker| crate::server::prune_datastore(auth_id, prune_options, datastore, dry_run),
     )?;
 
     Ok(upid_str)
diff --git a/src/api2/config/acme.rs b/src/api2/config/acme.rs
index 4fa276f6..f22ee2ae 100644
--- a/src/api2/config/acme.rs
+++ b/src/api2/config/acme.rs
@@ -9,12 +9,12 @@ use hex::FromHex;
 use lazy_static::lazy_static;
 use serde::{Deserialize, Serialize};
 use serde_json::{json, Value};
+use tracing::{info, warn};
 
 use proxmox_router::{
     http_bail, list_subdirs_api_method, Permission, Router, RpcEnvironment, SubdirMap,
 };
 use proxmox_schema::{api, param_bail};
-use proxmox_sys::{task_log, task_warn};
 
 use proxmox_acme::account::AccountData as AcmeAccountData;
 use proxmox_acme::Account;
@@ -240,10 +240,10 @@ fn register_account(
         Some(name.to_string()),
         auth_id.to_string(),
         true,
-        move |worker| async move {
+        move |_worker| async move {
             let mut client = AcmeClient::new(directory);
 
-            task_log!(worker, "Registering ACME account '{}'...", &name);
+            info!("Registering ACME account '{}'...", &name);
 
             let account = do_register_account(
                 &mut client,
@@ -255,11 +255,7 @@ fn register_account(
             )
             .await?;
 
-            task_log!(
-                worker,
-                "Registration successful, account URL: {}",
-                account.location
-            );
+            info!("Registration successful, account URL: {}", account.location);
 
             Ok(())
         },
@@ -354,7 +350,7 @@ pub fn deactivate_account(
         Some(name.to_string()),
         auth_id.to_string(),
         true,
-        move |worker| async move {
+        move |_worker| async move {
             match AcmeClient::load(&name)
                 .await?
                 .update_account(&json!({"status": "deactivated"}))
@@ -363,11 +359,9 @@ pub fn deactivate_account(
                 Ok(_account) => (),
                 Err(err) if !force => return Err(err),
                 Err(err) => {
-                    task_warn!(
-                        worker,
+                    warn!(
                         "error deactivating account {}, proceedeing anyway - {}",
-                        name,
-                        err,
+                        name, err,
                     );
                 }
             }
diff --git a/src/api2/config/datastore.rs b/src/api2/config/datastore.rs
index 3081e1f4..b070df0e 100644
--- a/src/api2/config/datastore.rs
+++ b/src/api2/config/datastore.rs
@@ -4,11 +4,11 @@ use ::serde::{Deserialize, Serialize};
 use anyhow::Error;
 use hex::FromHex;
 use serde_json::Value;
+use tracing::warn;
 
 use proxmox_router::{http_bail, Permission, Router, RpcEnvironment, RpcEnvironmentType};
 use proxmox_schema::{api, param_bail, ApiType};
 use proxmox_section_config::SectionConfigData;
-use proxmox_sys::{task_warn, WorkerTaskContext};
 use proxmox_uuid::Uuid;
 
 use pbs_api_types::{
@@ -70,7 +70,6 @@ pub(crate) fn do_create_datastore(
     _lock: BackupLockGuard,
     mut config: SectionConfigData,
     datastore: DataStoreConfig,
-    worker: Option<&dyn WorkerTaskContext>,
 ) -> Result<(), Error> {
     let path: PathBuf = datastore.path.clone().into();
 
@@ -84,7 +83,6 @@ pub(crate) fn do_create_datastore(
         path,
         backup_user.uid,
         backup_user.gid,
-        worker,
         tuning.sync_level.unwrap_or_default(),
     )?;
 
@@ -155,11 +153,11 @@ pub fn create_datastore(
         Some(config.name.to_string()),
         auth_id.to_string(),
         to_stdout,
-        move |worker| {
-            do_create_datastore(lock, section_config, config, Some(&worker))?;
+        move |_worker| {
+            do_create_datastore(lock, section_config, config)?;
 
             if let Some(prune_job_config) = prune_job_config {
-                do_create_prune_job(prune_job_config, Some(&worker))
+                do_create_prune_job(prune_job_config)
             } else {
                 Ok(())
             }
@@ -512,8 +510,8 @@ pub async fn delete_datastore(
         Some(name.clone()),
         auth_id.to_string(),
         to_stdout,
-        move |worker| {
-            pbs_datastore::DataStore::destroy(&name, destroy_data, &worker)?;
+        move |_worker| {
+            pbs_datastore::DataStore::destroy(&name, destroy_data)?;
 
             // ignore errors
             let _ = jobstate::remove_state_file("prune", &name);
@@ -522,7 +520,7 @@ pub async fn delete_datastore(
             if let Err(err) =
                 proxmox_async::runtime::block_on(crate::server::notify_datastore_removed())
             {
-                task_warn!(worker, "failed to notify after datastore removal: {err}");
+                warn!("failed to notify after datastore removal: {err}");
             }
 
             Ok(())
diff --git a/src/api2/config/prune.rs b/src/api2/config/prune.rs
index 4f7ce39c..4f3d94af 100644
--- a/src/api2/config/prune.rs
+++ b/src/api2/config/prune.rs
@@ -1,7 +1,5 @@
 use anyhow::Error;
 use hex::FromHex;
-use proxmox_sys::task_log;
-use proxmox_sys::WorkerTaskContext;
 use serde::{Deserialize, Serialize};
 use serde_json::Value;
 
@@ -15,6 +13,7 @@ use pbs_api_types::{
 use pbs_config::prune;
 
 use pbs_config::CachedUserInfo;
+use tracing::info;
 
 #[api(
     input: {
@@ -58,10 +57,7 @@ pub fn list_prune_jobs(
     Ok(list)
 }
 
-pub fn do_create_prune_job(
-    config: PruneJobConfig,
-    worker: Option<&dyn WorkerTaskContext>,
-) -> Result<(), Error> {
+pub fn do_create_prune_job(config: PruneJobConfig) -> Result<(), Error> {
     let _lock = prune::lock_config()?;
 
     let (mut section_config, _digest) = prune::config()?;
@@ -76,9 +72,7 @@ pub fn do_create_prune_job(
 
     crate::server::jobstate::create_state_file("prunejob", &config.id)?;
 
-    if let Some(worker) = worker {
-        task_log!(worker, "Prune job created: {}", config.id);
-    }
+    info!("Prune job created: {}", config.id);
 
     Ok(())
 }
@@ -108,7 +102,7 @@ pub fn create_prune_job(
 
     user_info.check_privs(&auth_id, &config.acl_path(), PRIV_DATASTORE_MODIFY, true)?;
 
-    do_create_prune_job(config, None)
+    do_create_prune_job(config)
 }
 
 #[api(
diff --git a/src/api2/node/apt.rs b/src/api2/node/apt.rs
index 9c0d9ecc..38af0452 100644
--- a/src/api2/node/apt.rs
+++ b/src/api2/node/apt.rs
@@ -1,6 +1,7 @@
 use anyhow::{bail, format_err, Error};
 use serde_json::{json, Value};
 use std::os::unix::prelude::OsStrExt;
+use tracing::{info, warn};
 
 use proxmox_router::{
     list_subdirs_api_method, Permission, Router, RpcEnvironment, RpcEnvironmentType, SubdirMap,
@@ -83,9 +84,9 @@ fn read_and_update_proxy_config() -> Result<Option<ProxyConfig>, Error> {
     Ok(proxy_config)
 }
 
-fn do_apt_update(worker: &WorkerTask, quiet: bool) -> Result<(), Error> {
+fn do_apt_update(quiet: bool) -> Result<(), Error> {
     if !quiet {
-        worker.log_message("starting apt-get update")
+        info!("starting apt-get update");
     }
 
     read_and_update_proxy_config()?;
@@ -99,7 +100,7 @@ fn do_apt_update(worker: &WorkerTask, quiet: bool) -> Result<(), Error> {
         .map_err(|err| format_err!("failed to execute {:?} - {}", command, err))?;
 
     if !quiet {
-        worker.log_message(String::from_utf8(output.stdout)?);
+        info!("{}", String::from_utf8(output.stdout)?);
     }
 
     // TODO: improve run_command to allow outputting both, stderr and stdout
@@ -114,7 +115,7 @@ fn do_apt_update(worker: &WorkerTask, quiet: bool) -> Result<(), Error> {
                     }
                 })
                 .unwrap_or_else(|_| String::from("non utf8 error message (suppressed)"));
-            worker.log_warning(msg);
+            warn!(msg);
         } else {
             bail!("terminated by signal");
         }
@@ -160,8 +161,8 @@ pub fn apt_update_database(
     let auth_id = rpcenv.get_auth_id().unwrap();
     let to_stdout = rpcenv.env_type() == RpcEnvironmentType::CLI;
 
-    let upid_str = WorkerTask::new_thread("aptupdate", None, auth_id, to_stdout, move |worker| {
-        do_apt_update(&worker, quiet)?;
+    let upid_str = WorkerTask::new_thread("aptupdate", None, auth_id, to_stdout, move |_worker| {
+        do_apt_update(quiet)?;
 
         let mut cache = apt::update_cache()?;
 
diff --git a/src/api2/node/certificates.rs b/src/api2/node/certificates.rs
index 6dfcd0c0..e4fbc8ac 100644
--- a/src/api2/node/certificates.rs
+++ b/src/api2/node/certificates.rs
@@ -5,16 +5,17 @@ use anyhow::{bail, format_err, Error};
 use openssl::pkey::PKey;
 use openssl::x509::X509;
 use serde::{Deserialize, Serialize};
+use tracing::info;
 
 use proxmox_router::list_subdirs_api_method;
 use proxmox_router::SubdirMap;
 use proxmox_router::{Permission, Router, RpcEnvironment};
 use proxmox_schema::api;
-use proxmox_sys::{task_log, task_warn};
 
 use pbs_api_types::{NODE_SCHEMA, PRIV_SYS_MODIFY};
 use pbs_buildcfg::configdir;
 use pbs_tools::cert;
+use tracing::warn;
 
 use crate::acme::AcmeClient;
 use crate::api2::types::AcmeDomain;
@@ -301,10 +302,7 @@ async fn order_certificate(
     };
 
     if domains.is_empty() {
-        task_log!(
-            worker,
-            "No domains configured to be ordered from an ACME server."
-        );
+        info!("No domains configured to be ordered from an ACME server.");
         return Ok(None);
     }
 
@@ -312,11 +310,11 @@ async fn order_certificate(
 
     let mut acme = node_config.acme_client().await?;
 
-    task_log!(worker, "Placing ACME order");
+    info!("Placing ACME order");
     let order = acme
         .new_order(domains.iter().map(|d| d.domain.to_ascii_lowercase()))
         .await?;
-    task_log!(worker, "Order URL: {}", order.location);
+    info!("Order URL: {}", order.location);
 
     let identifiers: Vec<String> = order
         .data
@@ -328,7 +326,7 @@ async fn order_certificate(
         .collect();
 
     for auth_url in &order.data.authorizations {
-        task_log!(worker, "Getting authorization details from '{}'", auth_url);
+        info!("Getting authorization details from '{}'", auth_url);
         let mut auth = acme.get_authorization(auth_url).await?;
 
         let domain = match &mut auth.identifier {
@@ -336,11 +334,11 @@ async fn order_certificate(
         };
 
         if auth.status == Status::Valid {
-            task_log!(worker, "{} is already validated!", domain);
+            info!("{} is already validated!", domain);
             continue;
         }
 
-        task_log!(worker, "The validation for {} is pending", domain);
+        info!("The validation for {} is pending", domain);
         let domain_config: &AcmeDomain = get_domain_config(&domain)?;
         let plugin_id = domain_config.plugin.as_deref().unwrap_or("standalone");
         let mut plugin_cfg =
@@ -348,31 +346,28 @@ async fn order_certificate(
                 format_err!("plugin '{}' for domain '{}' not found!", plugin_id, domain)
             })?;
 
-        task_log!(worker, "Setting up validation plugin");
+        info!("Setting up validation plugin");
         let validation_url = plugin_cfg
             .setup(&mut acme, &auth, domain_config, Arc::clone(&worker))
             .await?;
 
-        let result = request_validation(&worker, &mut acme, auth_url, validation_url).await;
+        let result = request_validation(&mut acme, auth_url, validation_url).await;
 
         if let Err(err) = plugin_cfg
             .teardown(&mut acme, &auth, domain_config, Arc::clone(&worker))
             .await
         {
-            task_warn!(
-                worker,
+            warn!(
                 "Failed to teardown plugin '{}' for domain '{}' - {}",
-                plugin_id,
-                domain,
-                err
+                plugin_id, domain, err
             );
         }
 
         result?;
     }
 
-    task_log!(worker, "All domains validated");
-    task_log!(worker, "Creating CSR");
+    info!("All domains validated");
+    info!("Creating CSR");
 
     let csr = proxmox_acme::util::Csr::generate(&identifiers, &Default::default())?;
     let mut finalize_error_cnt = 0u8;
@@ -385,7 +380,7 @@ async fn order_certificate(
 
         match order.status {
             Status::Pending => {
-                task_log!(worker, "still pending, trying to finalize anyway");
+                info!("still pending, trying to finalize anyway");
                 let finalize = order
                     .finalize
                     .as_deref()
@@ -400,7 +395,7 @@ async fn order_certificate(
                 tokio::time::sleep(Duration::from_secs(5)).await;
             }
             Status::Ready => {
-                task_log!(worker, "order is ready, finalizing");
+                info!("order is ready, finalizing");
                 let finalize = order
                     .finalize
                     .as_deref()
@@ -409,18 +404,18 @@ async fn order_certificate(
                 tokio::time::sleep(Duration::from_secs(5)).await;
             }
             Status::Processing => {
-                task_log!(worker, "still processing, trying again in 30 seconds");
+                info!("still processing, trying again in 30 seconds");
                 tokio::time::sleep(Duration::from_secs(30)).await;
             }
             Status::Valid => {
-                task_log!(worker, "valid");
+                info!("valid");
                 break;
             }
             other => bail!("order status: {:?}", other),
         }
     }
 
-    task_log!(worker, "Downloading certificate");
+    info!("Downloading certificate");
     let certificate = acme
         .get_certificate(
             order
@@ -437,15 +432,14 @@ async fn order_certificate(
 }
 
 async fn request_validation(
-    worker: &WorkerTask,
     acme: &mut AcmeClient,
     auth_url: &str,
     validation_url: &str,
 ) -> Result<(), Error> {
-    task_log!(worker, "Triggering validation");
+    info!("Triggering validation");
     acme.request_challenge_validation(validation_url).await?;
 
-    task_log!(worker, "Sleeping for 5 seconds");
+    info!("Sleeping for 5 seconds");
     tokio::time::sleep(Duration::from_secs(5)).await;
 
     loop {
@@ -454,10 +448,7 @@ async fn request_validation(
         let auth = acme.get_authorization(auth_url).await?;
         match auth.status {
             Status::Pending => {
-                task_log!(
-                    worker,
-                    "Status is still 'pending', trying again in 10 seconds"
-                );
+                info!("Status is still 'pending', trying again in 10 seconds");
                 tokio::time::sleep(Duration::from_secs(10)).await;
             }
             Status::Valid => return Ok(()),
@@ -582,15 +573,12 @@ pub fn revoke_acme_cert(rpcenv: &mut dyn RpcEnvironment) -> Result<String, Error
         None,
         auth_id,
         true,
-        move |worker| async move {
-            task_log!(worker, "Loading ACME account");
+        move |_worker| async move {
+            info!("Loading ACME account");
             let mut acme = node_config.acme_client().await?;
-            task_log!(worker, "Revoking old certificate");
+            info!("Revoking old certificate");
             acme.revoke_certificate(cert_pem.as_bytes(), None).await?;
-            task_log!(
-                worker,
-                "Deleting certificate and regenerating a self-signed one"
-            );
+            info!("Deleting certificate and regenerating a self-signed one");
             delete_custom_certificate().await?;
             Ok(())
         },
diff --git a/src/api2/node/disks/directory.rs b/src/api2/node/disks/directory.rs
index 9f1112a9..1db573e9 100644
--- a/src/api2/node/disks/directory.rs
+++ b/src/api2/node/disks/directory.rs
@@ -2,11 +2,11 @@ use ::serde::{Deserialize, Serialize};
 use anyhow::{bail, Error};
 use serde_json::json;
 use std::os::linux::fs::MetadataExt;
+use tracing::info;
 
 use proxmox_router::{Permission, Router, RpcEnvironment, RpcEnvironmentType};
 use proxmox_schema::api;
 use proxmox_section_config::SectionConfigData;
-use proxmox_sys::task_log;
 
 use pbs_api_types::{
     DataStoreConfig, BLOCKDEVICE_NAME_SCHEMA, DATASTORE_SCHEMA, NODE_SCHEMA, PRIV_SYS_AUDIT,
@@ -179,8 +179,8 @@ pub fn create_datastore_disk(
         Some(name.clone()),
         auth_id,
         to_stdout,
-        move |worker| {
-            task_log!(worker, "create datastore '{}' on disk {}", name, disk);
+        move |_worker| {
+            info!("create datastore '{}' on disk {}", name, disk);
 
             let add_datastore = add_datastore.unwrap_or(false);
             let filesystem = filesystem.unwrap_or(FileSystemType::Ext4);
@@ -213,12 +213,7 @@ pub fn create_datastore_disk(
                     bail!("datastore '{}' already exists.", datastore.name);
                 }
 
-                crate::api2::config::datastore::do_create_datastore(
-                    lock,
-                    config,
-                    datastore,
-                    Some(&worker),
-                )?;
+                crate::api2::config::datastore::do_create_datastore(lock, config, datastore)?;
             }
 
             Ok(())
diff --git a/src/api2/node/disks/mod.rs b/src/api2/node/disks/mod.rs
index 711dae7b..4ec511aa 100644
--- a/src/api2/node/disks/mod.rs
+++ b/src/api2/node/disks/mod.rs
@@ -6,7 +6,7 @@ use proxmox_router::{
 };
 use proxmox_schema::api;
 use proxmox_sortable_macro::sortable;
-use proxmox_sys::task_log;
+use tracing::info;
 
 use pbs_api_types::{
     BLOCKDEVICE_DISK_AND_PARTITION_NAME_SCHEMA, BLOCKDEVICE_NAME_SCHEMA, NODE_SCHEMA,
@@ -164,8 +164,8 @@ pub fn initialize_disk(
         Some(disk.clone()),
         auth_id,
         to_stdout,
-        move |worker| {
-            task_log!(worker, "initialize disk {}", disk);
+        move |_worker| {
+            info!("initialize disk {}", disk);
 
             let disk_manager = DiskManage::new();
             let disk_info = disk_manager.disk_by_name(&disk)?;
@@ -209,13 +209,13 @@ pub fn wipe_disk(disk: String, rpcenv: &mut dyn RpcEnvironment) -> Result<Value,
         Some(disk.clone()),
         auth_id,
         to_stdout,
-        move |worker| {
-            task_log!(worker, "wipe disk {}", disk);
+        move |_worker| {
+            info!("wipe disk {}", disk);
 
             let disk_manager = DiskManage::new();
             let disk_info = disk_manager.partition_by_name(&disk)?;
 
-            wipe_blockdev(&disk_info, worker)?;
+            wipe_blockdev(&disk_info)?;
 
             Ok(())
         },
diff --git a/src/api2/node/disks/zfs.rs b/src/api2/node/disks/zfs.rs
index 673dc1bf..2447f4aa 100644
--- a/src/api2/node/disks/zfs.rs
+++ b/src/api2/node/disks/zfs.rs
@@ -1,9 +1,9 @@
 use anyhow::{bail, Error};
 use serde_json::{json, Value};
+use tracing::{error, info};
 
 use proxmox_router::{Permission, Router, RpcEnvironment, RpcEnvironmentType};
 use proxmox_schema::api;
-use proxmox_sys::{task_error, task_log};
 
 use pbs_api_types::{
     DataStoreConfig, ZfsCompressionType, ZfsRaidLevel, ZpoolListItem, DATASTORE_SCHEMA,
@@ -228,13 +228,10 @@ pub fn create_zpool(
         Some(name.clone()),
         auth_id,
         to_stdout,
-        move |worker| {
-            task_log!(
-                worker,
+        move |_worker| {
+            info!(
                 "create {:?} zpool '{}' on devices '{}'",
-                raidlevel,
-                name,
-                devices_text
+                raidlevel, name, devices_text
             );
 
             let mut command = std::process::Command::new("zpool");
@@ -275,12 +272,12 @@ pub fn create_zpool(
                 }
             }
 
-            task_log!(worker, "# {:?}", command);
+            info!("# {:?}", command);
 
             match proxmox_sys::command::run_command(command, None) {
-                Ok(output) => task_log!(worker, "{output}"),
+                Ok(output) => info!("{output}"),
                 Err(err) => {
-                    task_error!(worker, "{err}");
+                    error!("{err}");
                     bail!("Error during 'zpool create', see task log for more details");
                 }
             };
@@ -299,11 +296,11 @@ pub fn create_zpool(
                 command.arg(&format!("compression={}", compression));
             }
             command.args(["relatime=on", &name]);
-            task_log!(worker, "# {:?}", command);
+            info!("# {:?}", command);
             match proxmox_sys::command::run_command(command, None) {
-                Ok(output) => task_log!(worker, "{output}"),
+                Ok(output) => info!("{output}"),
                 Err(err) => {
-                    task_error!(worker, "{err}");
+                    error!("{err}");
                     bail!("Error during 'zfs set', see task log for more details");
                 }
             };
@@ -319,12 +316,7 @@ pub fn create_zpool(
                     bail!("datastore '{}' already exists.", datastore.name);
                 }
 
-                crate::api2::config::datastore::do_create_datastore(
-                    lock,
-                    config,
-                    datastore,
-                    Some(&worker),
-                )?;
+                crate::api2::config::datastore::do_create_datastore(lock, config, datastore)?;
             }
 
             Ok(())
diff --git a/src/api2/node/mod.rs b/src/api2/node/mod.rs
index 931143fd..7055a683 100644
--- a/src/api2/node/mod.rs
+++ b/src/api2/node/mod.rs
@@ -25,6 +25,7 @@ use proxmox_sortable_macro::sortable;
 use proxmox_sys::fd::fd_change_cloexec;
 
 use pbs_api_types::{NODE_SCHEMA, PRIV_SYS_CONSOLE};
+use tracing::{info, warn};
 
 use crate::auth::{private_auth_keyring, public_auth_keyring};
 use crate::tools;
@@ -181,20 +182,18 @@ async fn termproxy(cmd: Option<String>, rpcenv: &mut dyn RpcEnvironment) -> Resu
             let stdout = child.stdout.take().expect("no child stdout handle");
             let stderr = child.stderr.take().expect("no child stderr handle");
 
-            let worker_stdout = worker.clone();
             let stdout_fut = async move {
                 let mut reader = BufReader::new(stdout).lines();
                 while let Some(line) = reader.next_line().await? {
-                    worker_stdout.log_message(line);
+                    info!(line);
                 }
                 Ok::<(), Error>(())
             };
 
-            let worker_stderr = worker.clone();
             let stderr_fut = async move {
                 let mut reader = BufReader::new(stderr).lines();
                 while let Some(line) = reader.next_line().await? {
-                    worker_stderr.log_warning(line);
+                    warn!(line);
                 }
                 Ok::<(), Error>(())
             };
@@ -226,9 +225,9 @@ async fn termproxy(cmd: Option<String>, rpcenv: &mut dyn RpcEnvironment) -> Resu
                 }
 
                 if let Err(err) = child.kill().await {
-                    worker.log_warning(format!("error killing termproxy: {}", err));
+                    warn!("error killing termproxy: {}", err);
                 } else if let Err(err) = child.wait().await {
-                    worker.log_warning(format!("error awaiting termproxy: {}", err));
+                    warn!("error awaiting termproxy: {}", err);
                 }
             }
 
diff --git a/src/api2/pull.rs b/src/api2/pull.rs
index 59db3660..06b752e9 100644
--- a/src/api2/pull.rs
+++ b/src/api2/pull.rs
@@ -1,10 +1,10 @@
 //! Sync datastore from remote server
 use anyhow::{bail, format_err, Error};
 use futures::{future::FutureExt, select};
+use tracing::info;
 
 use proxmox_router::{Permission, Router, RpcEnvironment};
 use proxmox_schema::api;
-use proxmox_sys::task_log;
 
 use pbs_api_types::{
     Authid, BackupNamespace, GroupFilter, RateLimitConfig, SyncJobConfig, DATASTORE_SCHEMA,
@@ -130,12 +130,12 @@ pub fn do_sync_job(
             let worker_future = async move {
                 let pull_params = PullParameters::try_from(&sync_job)?;
 
-                task_log!(worker, "Starting datastore sync job '{}'", job_id);
+                info!("Starting datastore sync job '{}'", job_id);
                 if let Some(event_str) = schedule {
-                    task_log!(worker, "task triggered by schedule '{}'", event_str);
+                    info!("task triggered by schedule '{}'", event_str);
                 }
-                task_log!(
-                    worker,
+
+                info!(
                     "sync datastore '{}' from '{}{}'",
                     sync_job.store,
                     sync_job
@@ -145,33 +145,29 @@ pub fn do_sync_job(
                     sync_job.remote_store,
                 );
 
-                let pull_stats = pull_store(&worker, pull_params).await?;
+                let pull_stats = pull_store(pull_params).await?;
 
                 if pull_stats.bytes != 0 {
                     let amount = HumanByte::from(pull_stats.bytes);
                     let rate = HumanByte::new_binary(
                         pull_stats.bytes as f64 / pull_stats.elapsed.as_secs_f64(),
                     );
-                    task_log!(
-                        worker,
+                    info!(
                         "Summary: sync job pulled {amount} in {} chunks (average rate: {rate}/s)",
                         pull_stats.chunk_count,
                     );
                 } else {
-                    task_log!(worker, "Summary: sync job found no new data to pull");
+                    info!("Summary: sync job found no new data to pull");
                 }
 
                 if let Some(removed) = pull_stats.removed {
-                    task_log!(
-                        worker,
+                    info!(
                         "Summary: removed vanished: snapshots: {}, groups: {}, namespaces: {}",
-                        removed.snapshots,
-                        removed.groups,
-                        removed.namespaces,
+                        removed.snapshots, removed.groups, removed.namespaces,
                     );
                 }
 
-                task_log!(worker, "sync job '{}' end", &job_id);
+                info!("sync job '{}' end", &job_id);
 
                 Ok(())
             };
@@ -321,21 +317,20 @@ async fn pull(
         auth_id.to_string(),
         true,
         move |worker| async move {
-            task_log!(
-                worker,
+            info!(
                 "pull datastore '{}' from '{}/{}'",
                 store,
                 remote.as_deref().unwrap_or("-"),
                 remote_store,
             );
 
-            let pull_future = pull_store(&worker, pull_params);
+            let pull_future = pull_store(pull_params);
             (select! {
                 success = pull_future.fuse() => success,
                 abort = worker.abort_future().map(|_| Err(format_err!("pull aborted"))) => abort,
             })?;
 
-            task_log!(worker, "pull datastore '{}' end", store);
+            info!("pull datastore '{}' end", store);
 
             Ok(())
         },
diff --git a/src/api2/tape/backup.rs b/src/api2/tape/backup.rs
index 28d7e720..fae6ee7c 100644
--- a/src/api2/tape/backup.rs
+++ b/src/api2/tape/backup.rs
@@ -2,11 +2,12 @@ use std::sync::{Arc, Mutex};
 
 use anyhow::{bail, format_err, Error};
 use serde_json::Value;
+use tracing::{info, warn};
 
 use proxmox_lang::try_block;
 use proxmox_router::{Permission, Router, RpcEnvironment, RpcEnvironmentType};
 use proxmox_schema::api;
-use proxmox_sys::{task_log, task_warn, WorkerTaskContext};
+use proxmox_sys::WorkerTaskContext;
 
 use pbs_api_types::{
     print_ns_and_snapshot, print_store_and_ns, Authid, MediaPoolConfig, Operation,
@@ -181,7 +182,7 @@ pub fn do_tape_backup_job(
             let job_result = try_block!({
                 if schedule.is_some() {
                     // for scheduled tape backup jobs, we wait indefinitely for the lock
-                    task_log!(worker, "waiting for drive lock...");
+                    info!("waiting for drive lock...");
                     loop {
                         worker.check_abort()?;
                         match lock_tape_device(&drive_config, &setup.drive) {
@@ -196,9 +197,9 @@ pub fn do_tape_backup_job(
                 }
                 set_tape_device_state(&setup.drive, &worker.upid().to_string())?;
 
-                task_log!(worker, "Starting tape backup job '{}'", job_id);
+                info!("Starting tape backup job '{}'", job_id);
                 if let Some(event_str) = schedule {
-                    task_log!(worker, "task triggered by schedule '{}'", event_str);
+                    info!("task triggered by schedule '{}'", event_str);
                 }
 
                 backup_worker(
@@ -392,7 +393,7 @@ fn backup_worker(
 ) -> Result<(), Error> {
     let start = std::time::Instant::now();
 
-    task_log!(worker, "update media online status");
+    info!("update media online status");
     let changer_name = update_media_online_status(&setup.drive)?;
 
     let root_namespace = setup.ns.clone().unwrap_or_default();
@@ -400,8 +401,7 @@ fn backup_worker(
 
     let pool = MediaPool::with_config(TAPE_STATUS_DIR, pool_config, changer_name, false)?;
 
-    let mut pool_writer =
-        PoolWriter::new(pool, &setup.drive, worker, email, force_media_set, ns_magic)?;
+    let mut pool_writer = PoolWriter::new(pool, &setup.drive, email, force_media_set, ns_magic)?;
 
     let mut group_list = Vec::new();
     let namespaces = datastore.recursive_iter_backup_ns_ok(root_namespace, setup.max_depth)?;
@@ -421,8 +421,7 @@ fn backup_worker(
         None => group_list,
     };
 
-    task_log!(
-        worker,
+    info!(
         "found {} groups (out of {} total)",
         group_list.len(),
         group_count_full
@@ -433,10 +432,7 @@ fn backup_worker(
     let latest_only = setup.latest_only.unwrap_or(false);
 
     if latest_only {
-        task_log!(
-            worker,
-            "latest-only: true (only considering latest snapshots)"
-        );
+        info!("latest-only: true (only considering latest snapshots)");
     }
 
     let datastore_name = datastore.name();
@@ -459,8 +455,7 @@ fn backup_worker(
             .collect();
 
         if snapshot_list.is_empty() {
-            task_log!(
-                worker,
+            info!(
                 "{}, group {} was empty",
                 print_store_and_ns(datastore_name, group.backup_ns()),
                 group.group()
@@ -480,7 +475,7 @@ fn backup_worker(
                     info.backup_dir.backup_ns(),
                     info.backup_dir.as_ref(),
                 ) {
-                    task_log!(worker, "skip snapshot {}", rel_path);
+                    info!("skip snapshot {}", rel_path);
                     continue;
                 }
 
@@ -493,7 +488,7 @@ fn backup_worker(
                     SnapshotBackupResult::Ignored => {}
                 }
                 progress.done_snapshots = 1;
-                task_log!(worker, "percentage done: {}", progress);
+                info!("percentage done: {}", progress);
             }
         } else {
             progress.group_snapshots = snapshot_list.len() as u64;
@@ -506,7 +501,7 @@ fn backup_worker(
                     info.backup_dir.backup_ns(),
                     info.backup_dir.as_ref(),
                 ) {
-                    task_log!(worker, "skip snapshot {}", rel_path);
+                    info!("skip snapshot {}", rel_path);
                     continue;
                 }
 
@@ -519,7 +514,7 @@ fn backup_worker(
                     SnapshotBackupResult::Ignored => {}
                 }
                 progress.done_snapshots = snapshot_number as u64 + 1;
-                task_log!(worker, "percentage done: {}", progress);
+                info!("percentage done: {}", progress);
             }
         }
     }
@@ -527,18 +522,15 @@ fn backup_worker(
     pool_writer.commit()?;
 
     if need_catalog {
-        task_log!(worker, "append media catalog");
+        info!("append media catalog");
 
         let uuid = pool_writer.load_writable_media(worker)?;
-        let done = pool_writer.append_catalog_archive(worker)?;
+        let done = pool_writer.append_catalog_archive()?;
         if !done {
-            task_log!(
-                worker,
-                "catalog does not fit on tape, writing to next volume"
-            );
+            info!("catalog does not fit on tape, writing to next volume");
             pool_writer.set_media_status_full(&uuid)?;
             pool_writer.load_writable_media(worker)?;
-            let done = pool_writer.append_catalog_archive(worker)?;
+            let done = pool_writer.append_catalog_archive()?;
             if !done {
                 bail!("write_catalog_archive failed on second media");
             }
@@ -546,9 +538,9 @@ fn backup_worker(
     }
 
     if setup.export_media_set.unwrap_or(false) {
-        pool_writer.export_media_set(worker)?;
+        pool_writer.export_media_set()?;
     } else if setup.eject_media.unwrap_or(false) {
-        pool_writer.eject_media(worker)?;
+        pool_writer.eject_media()?;
     }
 
     if errors {
@@ -558,7 +550,7 @@ fn backup_worker(
     summary.used_tapes = match pool_writer.get_used_media_labels() {
         Ok(tapes) => Some(tapes),
         Err(err) => {
-            task_warn!(worker, "could not collect list of used tapes: {err}");
+            warn!("could not collect list of used tapes: {err}");
             None
         }
     };
@@ -592,7 +584,7 @@ fn backup_snapshot(
     snapshot: BackupDir,
 ) -> Result<SnapshotBackupResult, Error> {
     let snapshot_path = snapshot.relative_path();
-    task_log!(worker, "backup snapshot {:?}", snapshot_path);
+    info!("backup snapshot {:?}", snapshot_path);
 
     let snapshot_reader = match snapshot.locked_reader() {
         Ok(reader) => reader,
@@ -600,15 +592,10 @@ fn backup_snapshot(
             if !snapshot.full_path().exists() {
                 // we got an error and the dir does not exist,
                 // it probably just vanished, so continue
-                task_log!(worker, "snapshot {:?} vanished, skipping", snapshot_path);
+                info!("snapshot {:?} vanished, skipping", snapshot_path);
                 return Ok(SnapshotBackupResult::Ignored);
             }
-            task_warn!(
-                worker,
-                "failed opening snapshot {:?}: {}",
-                snapshot_path,
-                err
-            );
+            warn!("failed opening snapshot {:?}: {}", snapshot_path, err);
             return Ok(SnapshotBackupResult::Error);
         }
     };
@@ -654,7 +641,7 @@ fn backup_snapshot(
 
     let snapshot_reader = snapshot_reader.lock().unwrap();
 
-    let (done, _bytes) = pool_writer.append_snapshot_archive(worker, &snapshot_reader)?;
+    let (done, _bytes) = pool_writer.append_snapshot_archive(&snapshot_reader)?;
 
     if !done {
         // does not fit on tape, so we try on next volume
@@ -663,19 +650,14 @@ fn backup_snapshot(
         worker.check_abort()?;
 
         pool_writer.load_writable_media(worker)?;
-        let (done, _bytes) = pool_writer.append_snapshot_archive(worker, &snapshot_reader)?;
+        let (done, _bytes) = pool_writer.append_snapshot_archive(&snapshot_reader)?;
 
         if !done {
             bail!("write_snapshot_archive failed on second media");
         }
     }
 
-    task_log!(
-        worker,
-        "end backup {}:{:?}",
-        datastore.name(),
-        snapshot_path
-    );
+    info!("end backup {}:{:?}", datastore.name(), snapshot_path);
 
     Ok(SnapshotBackupResult::Success)
 }
diff --git a/src/api2/tape/drive.rs b/src/api2/tape/drive.rs
index 5a5d39d9..1bd19383 100644
--- a/src/api2/tape/drive.rs
+++ b/src/api2/tape/drive.rs
@@ -4,6 +4,7 @@ use std::sync::Arc;
 
 use anyhow::{bail, format_err, Error};
 use serde_json::Value;
+use tracing::{info, warn};
 
 use proxmox_router::{
     list_subdirs_api_method, Permission, Router, RpcEnvironment, RpcEnvironmentType, SubdirMap,
@@ -11,7 +12,6 @@ use proxmox_router::{
 use proxmox_schema::api;
 use proxmox_section_config::SectionConfigData;
 use proxmox_sortable_macro::sortable;
-use proxmox_sys::{task_log, task_warn};
 use proxmox_uuid::Uuid;
 
 use pbs_api_types::{
@@ -130,13 +130,8 @@ pub fn load_media(
         drive.clone(),
         "load-media",
         Some(job_id),
-        move |worker, config| {
-            task_log!(
-                worker,
-                "loading media '{}' into drive '{}'",
-                label_text,
-                drive
-            );
+        move |_worker, config| {
+            info!("loading media '{}' into drive '{}'", label_text, drive);
             let (mut changer, _) = required_media_changer(&config, &drive)?;
             changer.load_media(&label_text)?;
             Ok(())
@@ -249,8 +244,8 @@ pub fn unload(
         drive.clone(),
         "unload-media",
         Some(drive.clone()),
-        move |worker, config| {
-            task_log!(worker, "unloading media from drive '{}'", drive);
+        move |_worker, config| {
+            info!("unloading media from drive '{}'", drive);
 
             let (mut changer, _) = required_media_changer(&config, &drive)?;
             changer.unload_media(target_slot)?;
@@ -298,9 +293,9 @@ pub fn format_media(
         drive.clone(),
         "format-media",
         Some(drive.clone()),
-        move |worker, config| {
+        move |_worker, config| {
             if let Some(ref label) = label_text {
-                task_log!(worker, "try to load media '{}'", label);
+                info!("try to load media '{}'", label);
                 if let Some((mut changer, _)) = media_changer(&config, &drive)? {
                     changer.load_media(label)?;
                 }
@@ -314,11 +309,8 @@ pub fn format_media(
                 let mut handle = LtoTapeHandle::new(file)?;
                 if let Ok(status) = handle.get_drive_and_media_status() {
                     if status.density >= TapeDensity::LTO9 {
-                        task_log!(worker, "Slow formatting LTO9+ media.");
-                        task_log!(
-                            worker,
-                            "This can take a very long time due to media optimization."
-                        );
+                        info!("Slow formatting LTO9+ media.");
+                        info!("This can take a very long time due to media optimization.");
                     }
                 }
             }
@@ -329,15 +321,15 @@ pub fn format_media(
                         bail!("expected label '{}', found unrelated data", label);
                     }
                     /* assume drive contains no or unrelated data */
-                    task_log!(worker, "unable to read media label: {}", err);
-                    task_log!(worker, "format anyways");
+                    info!("unable to read media label: {}", err);
+                    info!("format anyways");
                     handle.format_media(fast.unwrap_or(true))?;
                 }
                 Ok((None, _)) => {
                     if let Some(label) = label_text {
                         bail!("expected label '{}', found empty tape", label);
                     }
-                    task_log!(worker, "found empty media - format anyways");
+                    info!("found empty media - format anyways");
                     handle.format_media(fast.unwrap_or(true))?;
                 }
                 Ok((Some(media_id), _key_config)) => {
@@ -351,11 +343,9 @@ pub fn format_media(
                         }
                     }
 
-                    task_log!(
-                        worker,
+                    info!(
                         "found media '{}' with uuid '{}'",
-                        media_id.label.label_text,
-                        media_id.label.uuid,
+                        media_id.label.label_text, media_id.label.uuid,
                     );
 
                     let mut inventory = Inventory::new(TAPE_STATUS_DIR);
@@ -503,7 +493,7 @@ pub fn label_media(
         drive.clone(),
         "label-media",
         Some(drive.clone()),
-        move |worker, config| {
+        move |_worker, config| {
             let mut drive = open_drive(&config, &drive)?;
 
             drive.rewind()?;
@@ -525,7 +515,7 @@ pub fn label_media(
                 pool: pool.clone(),
             };
 
-            write_media_label(worker, &mut drive, label, pool)
+            write_media_label(&mut drive, label, pool)
         },
     )?;
 
@@ -533,7 +523,6 @@ pub fn label_media(
 }
 
 fn write_media_label(
-    worker: Arc<WorkerTask>,
     drive: &mut Box<dyn TapeDriver>,
     label: MediaLabel,
     pool: Option<String>,
@@ -548,18 +537,9 @@ fn write_media_label(
     }
     drive.label_tape(&label)?;
     if let Some(ref pool) = pool {
-        task_log!(
-            worker,
-            "Label media '{}' for pool '{}'",
-            label.label_text,
-            pool
-        );
+        info!("Label media '{}' for pool '{}'", label.label_text, pool);
     } else {
-        task_log!(
-            worker,
-            "Label media '{}' (no pool assignment)",
-            label.label_text
-        );
+        info!("Label media '{}' (no pool assignment)", label.label_text);
     }
 
     let media_id = MediaId {
@@ -746,10 +726,10 @@ pub fn clean_drive(drive: String, rpcenv: &mut dyn RpcEnvironment) -> Result<Val
         drive.clone(),
         "clean-drive",
         Some(drive.clone()),
-        move |worker, config| {
+        move |_worker, config| {
             let (mut changer, _changer_name) = required_media_changer(&config, &drive)?;
 
-            task_log!(worker, "Starting drive clean");
+            info!("Starting drive clean");
 
             changer.clean_drive()?;
 
@@ -760,7 +740,7 @@ pub fn clean_drive(drive: String, rpcenv: &mut dyn RpcEnvironment) -> Result<Val
                 // test for critical tape alert flags
                 if let Ok(alert_flags) = handle.tape_alert_flags() {
                     if !alert_flags.is_empty() {
-                        task_log!(worker, "TapeAlertFlags: {:?}", alert_flags);
+                        info!("TapeAlertFlags: {:?}", alert_flags);
                         if tape_alert_flags_critical(alert_flags) {
                             bail!("found critical tape alert flags: {:?}", alert_flags);
                         }
@@ -769,13 +749,13 @@ pub fn clean_drive(drive: String, rpcenv: &mut dyn RpcEnvironment) -> Result<Val
 
                 // test wearout (max. 50 mounts)
                 if let Ok(volume_stats) = handle.volume_statistics() {
-                    task_log!(worker, "Volume mounts: {}", volume_stats.volume_mounts);
+                    info!("Volume mounts: {}", volume_stats.volume_mounts);
                     let wearout = volume_stats.volume_mounts * 2; // (*100.0/50.0);
-                    task_log!(worker, "Cleaning tape wearout: {}%", wearout);
+                    info!("Cleaning tape wearout: {}%", wearout);
                 }
             }
 
-            task_log!(worker, "Drive cleaned successfully");
+            info!("Drive cleaned successfully");
 
             Ok(())
         },
@@ -907,12 +887,12 @@ pub fn update_inventory(
         drive.clone(),
         "inventory-update",
         Some(drive.clone()),
-        move |worker, config| {
+        move |_worker, config| {
             let (mut changer, changer_name) = required_media_changer(&config, &drive)?;
 
             let label_text_list = changer.online_media_label_texts()?;
             if label_text_list.is_empty() {
-                task_log!(worker, "changer device does not list any media labels");
+                info!("changer device does not list any media labels");
             }
 
             let mut inventory = Inventory::load(TAPE_STATUS_DIR)?;
@@ -921,7 +901,7 @@ pub fn update_inventory(
 
             for label_text in label_text_list.iter() {
                 if label_text.starts_with("CLN") {
-                    task_log!(worker, "skip cleaning unit '{}'", label_text);
+                    info!("skip cleaning unit '{}'", label_text);
                     continue;
                 }
 
@@ -933,12 +913,12 @@ pub fn update_inventory(
                             if !catalog
                                 || MediaCatalog::exists(TAPE_STATUS_DIR, &media_id.label.uuid)
                             {
-                                task_log!(worker, "media '{}' already inventoried", label_text);
+                                info!("media '{}' already inventoried", label_text);
                                 continue;
                             }
                         }
                         Err(err) => {
-                            task_warn!(worker, "error getting media by unique label: {err}");
+                            warn!("error getting media by unique label: {err}");
                             // we can't be sure which uuid it is
                             continue;
                         }
@@ -947,38 +927,29 @@ pub fn update_inventory(
                 }
 
                 if let Err(err) = changer.load_media(&label_text) {
-                    task_warn!(worker, "unable to load media '{}' - {}", label_text, err);
+                    warn!("unable to load media '{}' - {}", label_text, err);
                     continue;
                 }
 
                 let mut drive = open_drive(&config, &drive)?;
                 match drive.read_label() {
                     Err(err) => {
-                        task_warn!(
-                            worker,
-                            "unable to read label form media '{}' - {}",
-                            label_text,
-                            err
-                        );
+                        warn!("unable to read label form media '{}' - {}", label_text, err);
                     }
                     Ok((None, _)) => {
-                        task_log!(worker, "media '{}' is empty", label_text);
+                        info!("media '{}' is empty", label_text);
                     }
                     Ok((Some(media_id), _key_config)) => {
                         if label_text != media_id.label.label_text {
-                            task_warn!(
-                                worker,
+                            warn!(
                                 "label text mismatch ({} != {})",
-                                label_text,
-                                media_id.label.label_text
+                                label_text, media_id.label.label_text
                             );
                             continue;
                         }
-                        task_log!(
-                            worker,
+                        info!(
                             "inventorize media '{}' with uuid '{}'",
-                            label_text,
-                            media_id.label.uuid
+                            label_text, media_id.label.uuid
                         );
 
                         let _pool_lock = if let Some(pool) = media_id.pool() {
@@ -999,15 +970,11 @@ pub fn update_inventory(
                             if catalog {
                                 let media_set = inventory.compute_media_set_members(&set.uuid)?;
                                 if let Err(err) = fast_catalog_restore(
-                                    &worker,
                                     &mut drive,
                                     &media_set,
                                     &media_id.label.uuid,
                                 ) {
-                                    task_warn!(
-                                        worker,
-                                        "could not restore catalog for {label_text}: {err}"
-                                    );
+                                    warn!("could not restore catalog for {label_text}: {err}");
                                 }
                             }
                         } else {
@@ -1063,14 +1030,13 @@ pub fn barcode_label_media(
         drive.clone(),
         "barcode-label-media",
         Some(drive.clone()),
-        move |worker, config| barcode_label_media_worker(worker, drive, &config, pool),
+        move |_worker, config| barcode_label_media_worker(drive, &config, pool),
     )?;
 
     Ok(upid_str.into())
 }
 
 fn barcode_label_media_worker(
-    worker: Arc<WorkerTask>,
     drive: String,
     drive_config: &SectionConfigData,
     pool: Option<String>,
@@ -1103,24 +1069,23 @@ fn barcode_label_media_worker(
         inventory.reload()?;
         match inventory.find_media_by_label_text(&label_text) {
             Ok(Some(_)) => {
-                task_log!(
-                    worker,
+                info!(
                     "media '{}' already inventoried (already labeled)",
                     label_text
                 );
                 continue;
             }
             Err(err) => {
-                task_warn!(worker, "error getting media by unique label: {err}",);
+                warn!("error getting media by unique label: {err}",);
                 continue;
             }
             Ok(None) => {} // ok to label
         }
 
-        task_log!(worker, "checking/loading media '{}'", label_text);
+        info!("checking/loading media '{}'", label_text);
 
         if let Err(err) = changer.load_media(&label_text) {
-            task_warn!(worker, "unable to load media '{}' - {}", label_text, err);
+            warn!("unable to load media '{}' - {}", label_text, err);
             continue;
         }
 
@@ -1129,18 +1094,13 @@ fn barcode_label_media_worker(
 
         match drive.read_next_file() {
             Ok(_reader) => {
-                task_log!(
-                    worker,
-                    "media '{}' is not empty (format it first)",
-                    label_text
-                );
+                info!("media '{}' is not empty (format it first)", label_text);
                 continue;
             }
             Err(BlockReadError::EndOfFile) => { /* EOF mark at BOT, assume tape is empty */ }
             Err(BlockReadError::EndOfStream) => { /* tape is empty */ }
             Err(_err) => {
-                task_warn!(
-                    worker,
+                warn!(
                     "media '{}' read error (maybe not empty - format it first)",
                     label_text
                 );
@@ -1156,7 +1116,7 @@ fn barcode_label_media_worker(
             pool: pool.clone(),
         };
 
-        write_media_label(worker.clone(), &mut drive, label, pool.clone())?
+        write_media_label(&mut drive, label, pool.clone())?
     }
 
     Ok(())
@@ -1315,14 +1275,12 @@ pub fn catalog_media(
 
             let media_id = match drive.read_label()? {
                 (Some(media_id), key_config) => {
-                    task_log!(
-                        worker,
+                    info!(
                         "found media label: {}",
                         serde_json::to_string_pretty(&serde_json::to_value(&media_id)?)?
                     );
                     if key_config.is_some() {
-                        task_log!(
-                            worker,
+                        info!(
                             "encryption key config: {}",
                             serde_json::to_string_pretty(&serde_json::to_value(&key_config)?)?
                         );
@@ -1336,7 +1294,7 @@ pub fn catalog_media(
 
             let (_media_set_lock, media_set_uuid) = match media_id.media_set_label {
                 None => {
-                    task_log!(worker, "media is empty");
+                    info!("media is empty");
                     let _pool_lock = if let Some(pool) = media_id.pool() {
                         lock_media_pool(TAPE_STATUS_DIR, &pool)?
                     } else {
@@ -1349,7 +1307,7 @@ pub fn catalog_media(
                 Some(ref set) => {
                     if set.unassigned() {
                         // media is empty
-                        task_log!(worker, "media is empty");
+                        info!("media is empty");
                         let _lock = lock_unassigned_media_pool(TAPE_STATUS_DIR)?;
                         MediaCatalog::destroy(TAPE_STATUS_DIR, &media_id.label.uuid)?;
                         inventory.store(media_id.clone(), false)?;
@@ -1374,14 +1332,14 @@ pub fn catalog_media(
             if !scan {
                 let media_set = inventory.compute_media_set_members(media_set_uuid)?;
 
-                if fast_catalog_restore(&worker, &mut drive, &media_set, &media_id.label.uuid)? {
+                if fast_catalog_restore(&mut drive, &media_set, &media_id.label.uuid)? {
                     return Ok(());
                 }
 
-                task_log!(worker, "no catalog found");
+                info!("no catalog found");
             }
 
-            task_log!(worker, "scanning entire media to reconstruct catalog");
+            info!("scanning entire media to reconstruct catalog");
 
             drive.rewind()?;
             drive.read_label()?; // skip over labels - we already read them above
diff --git a/src/api2/tape/restore.rs b/src/api2/tape/restore.rs
index 8273c867..14a164e0 100644
--- a/src/api2/tape/restore.rs
+++ b/src/api2/tape/restore.rs
@@ -6,6 +6,7 @@ use std::sync::Arc;
 
 use anyhow::{bail, format_err, Error};
 use serde_json::Value;
+use tracing::{info, warn};
 
 use proxmox_human_byte::HumanByte;
 use proxmox_io::ReadExt;
@@ -13,7 +14,7 @@ use proxmox_router::{Permission, Router, RpcEnvironment, RpcEnvironmentType};
 use proxmox_schema::{api, ApiType};
 use proxmox_section_config::SectionConfigData;
 use proxmox_sys::fs::{replace_file, CreateOptions};
-use proxmox_sys::{task_log, task_warn, WorkerTaskContext};
+use proxmox_sys::WorkerTaskContext;
 use proxmox_uuid::Uuid;
 
 use pbs_api_types::{
@@ -399,12 +400,12 @@ pub fn restore(
                 .and_then(lookup_user_email)
                 .or_else(|| lookup_user_email(&auth_id.clone().into()));
 
-            task_log!(worker, "Mediaset '{media_set}'");
-            task_log!(worker, "Pool: {pool}");
+            info!("Mediaset '{media_set}'");
+            info!("Pool: {pool}");
 
             let res = if snapshots.is_some() || namespaces {
                 restore_list_worker(
-                    worker.clone(),
+                    worker,
                     snapshots.unwrap_or_default(),
                     inventory,
                     media_set_uuid,
@@ -418,7 +419,7 @@ pub fn restore(
                 )
             } else {
                 restore_full_worker(
-                    worker.clone(),
+                    worker,
                     inventory,
                     media_set_uuid,
                     drive_config,
@@ -430,10 +431,10 @@ pub fn restore(
                 )
             };
             if res.is_ok() {
-                task_log!(worker, "Restore mediaset '{media_set}' done");
+                info!("Restore mediaset '{media_set}' done");
             }
             if let Err(err) = set_tape_device_state(&drive, "") {
-                task_log!(worker, "could not unset drive state for {drive}: {err}");
+                info!("could not unset drive state for {drive}: {err}");
             }
 
             res
@@ -484,7 +485,7 @@ fn restore_full_worker(
     }
 
     if let Some(fingerprint) = encryption_key_fingerprint {
-        task_log!(worker, "Encryption key fingerprint: {fingerprint}");
+        info!("Encryption key fingerprint: {fingerprint}");
     }
 
     let used_datastores = store_map.used_datastores();
@@ -493,13 +494,9 @@ fn restore_full_worker(
         .map(|(t, _)| String::from(t.name()))
         .collect::<Vec<String>>()
         .join(", ");
-    task_log!(worker, "Datastore(s): {datastore_list}",);
-    task_log!(worker, "Drive: {drive_name}");
-    log_required_tapes(
-        &worker,
-        &inventory,
-        media_id_list.iter().map(|id| &id.label.uuid),
-    );
+    info!("Datastore(s): {datastore_list}",);
+    info!("Drive: {drive_name}");
+    log_required_tapes(&inventory, media_id_list.iter().map(|id| &id.label.uuid));
 
     let mut datastore_locks = Vec::new();
     for (target, _) in used_datastores.values() {
@@ -529,7 +526,6 @@ fn restore_full_worker(
 
 #[allow(clippy::too_many_arguments)]
 fn check_snapshot_restorable(
-    worker: &WorkerTask,
     store_map: &DataStoreMap,
     store: &str,
     snapshot: &str,
@@ -570,7 +566,7 @@ fn check_snapshot_restorable(
             auth_id,
             Some(restore_owner),
         ) {
-            task_warn!(worker, "cannot restore {store}:{snapshot} to {ns}: '{err}'");
+            warn!("cannot restore {store}:{snapshot} to {ns}: '{err}'");
             continue;
         }
 
@@ -578,8 +574,7 @@ fn check_snapshot_restorable(
         if let Ok(owner) = datastore.get_owner(&ns, dir.as_ref()) {
             if restore_owner != &owner {
                 // only the owner is allowed to create additional snapshots
-                task_warn!(
-                    worker,
+                warn!(
                     "restore  of '{snapshot}' to {ns} failed, owner check failed ({restore_owner} \
                     != {owner})",
                 );
@@ -590,10 +585,7 @@ fn check_snapshot_restorable(
         have_some_permissions = true;
 
         if datastore.snapshot_path(&ns, dir).exists() {
-            task_warn!(
-                worker,
-                "found snapshot {snapshot} on target datastore/namespace, skipping...",
-            );
+            warn!("found snapshot {snapshot} on target datastore/namespace, skipping...",);
             continue;
         }
         can_restore_some = true;
@@ -606,11 +598,7 @@ fn check_snapshot_restorable(
     Ok(can_restore_some)
 }
 
-fn log_required_tapes<'a>(
-    worker: &WorkerTask,
-    inventory: &Inventory,
-    list: impl Iterator<Item = &'a Uuid>,
-) {
+fn log_required_tapes<'a>(inventory: &Inventory, list: impl Iterator<Item = &'a Uuid>) {
     let mut tape_list = list
         .map(|uuid| {
             inventory
@@ -622,7 +610,7 @@ fn log_required_tapes<'a>(
         })
         .collect::<Vec<&str>>();
     tape_list.sort_unstable();
-    task_log!(worker, "Required media list: {}", tape_list.join(";"));
+    info!("Required media list: {}", tape_list.join(";"));
 }
 
 #[allow(clippy::too_many_arguments)]
@@ -654,14 +642,13 @@ fn restore_list_worker(
                 let (ns, dir) = match parse_ns_and_snapshot(snapshot) {
                     Ok((ns, dir)) if store_map.has_full_mapping(store, &ns) => (ns, dir),
                     Err(err) => {
-                        task_warn!(worker, "couldn't parse snapshot {snapshot} - {err}");
+                        warn!("couldn't parse snapshot {snapshot} - {err}");
                         continue;
                     }
                     _ => continue,
                 };
                 let snapshot = print_ns_and_snapshot(&ns, &dir);
                 match check_snapshot_restorable(
-                    &worker,
                     &store_map,
                     store,
                     &snapshot,
@@ -675,7 +662,7 @@ fn restore_list_worker(
                     Ok(true) => restorable.push((store.to_string(), snapshot.to_string(), ns, dir)),
                     Ok(false) => {}
                     Err(err) => {
-                        task_warn!(worker, "{err}");
+                        warn!("{err}");
                         skipped.push(format!("{store}:{snapshot}"));
                     }
                 }
@@ -693,7 +680,6 @@ fn restore_list_worker(
                     match parse_ns_and_snapshot(snapshot) {
                         Ok((ns, dir)) => {
                             match check_snapshot_restorable(
-                                &worker,
                                 &store_map,
                                 store,
                                 snapshot,
@@ -709,14 +695,14 @@ fn restore_list_worker(
                                 }
                                 Ok(false) => None,
                                 Err(err) => {
-                                    task_warn!(worker, "{err}");
+                                    warn!("{err}");
                                     skipped.push(format!("{store}:{snapshot}"));
                                     None
                                 }
                             }
                         }
                         Err(err) => {
-                            task_warn!(worker, "could not restore {store_snapshot}: {err}");
+                            warn!("could not restore {store_snapshot}: {err}");
                             skipped.push(store_snapshot);
                             None
                         }
@@ -734,10 +720,7 @@ fn restore_list_worker(
                     let media_id = inventory.lookup_media(media_uuid).unwrap();
                     (media_id, file_num)
                 } else {
-                    task_warn!(
-                        worker,
-                        "did not find snapshot '{store}:{snapshot}' in media set",
-                    );
+                    warn!("did not find snapshot '{store}:{snapshot}' in media set",);
                     skipped.push(format!("{store}:{snapshot}"));
                     continue;
                 };
@@ -750,26 +733,25 @@ fn restore_list_worker(
                 .or_default();
             file_list.push(file_num);
 
-            task_log!(
-                worker,
+            info!(
                 "found snapshot {snapshot} on {}: file {file_num}",
                 media_id.label.label_text,
             );
         }
 
         if snapshot_file_hash.is_empty() {
-            task_log!(worker, "nothing to restore, skipping remaining phases...");
+            info!("nothing to restore, skipping remaining phases...");
             if !skipped.is_empty() {
-                task_log!(worker, "skipped the following snapshots:");
+                info!("skipped the following snapshots:");
                 for snap in skipped {
-                    task_log!(worker, "  {snap}");
+                    info!("  {snap}");
                 }
             }
             return Ok(());
         }
 
-        task_log!(worker, "Phase 1: temporarily restore snapshots to temp dir");
-        log_required_tapes(&worker, &inventory, snapshot_file_hash.keys());
+        info!("Phase 1: temporarily restore snapshots to temp dir");
+        log_required_tapes(&inventory, snapshot_file_hash.keys());
         let mut datastore_chunk_map: HashMap<String, HashSet<[u8; 32]>> = HashMap::new();
         let mut tmp_paths = Vec::new();
         for (media_uuid, file_list) in snapshot_file_hash.iter_mut() {
@@ -820,10 +802,10 @@ fn restore_list_worker(
         drop(catalog);
 
         if !media_file_chunk_map.is_empty() {
-            task_log!(worker, "Phase 2: restore chunks to datastores");
-            log_required_tapes(&worker, &inventory, media_file_chunk_map.keys());
+            info!("Phase 2: restore chunks to datastores");
+            log_required_tapes(&inventory, media_file_chunk_map.keys());
         } else {
-            task_log!(worker, "All chunks are already present, skip phase 2...");
+            info!("All chunks are already present, skip phase 2...");
         }
 
         for (media_uuid, file_chunk_map) in media_file_chunk_map.iter_mut() {
@@ -838,10 +820,7 @@ fn restore_list_worker(
             restore_file_chunk_map(worker.clone(), &mut drive, &store_map, file_chunk_map)?;
         }
 
-        task_log!(
-            worker,
-            "Phase 3: copy snapshots from temp dir to datastores"
-        );
+        info!("Phase 3: copy snapshots from temp dir to datastores");
         let mut errors = false;
         for (source_datastore, snapshot, source_ns, backup_dir) in snapshots.into_iter() {
             if let Err(err) = proxmox_lang::try_block!({
@@ -898,20 +877,14 @@ fn restore_list_worker(
 
                         Ok(())
                     }) {
-                        task_warn!(
-                            worker,
-                            "could not restore {source_datastore}:{snapshot}: '{err}'"
-                        );
+                        warn!("could not restore {source_datastore}:{snapshot}: '{err}'");
                         skipped.push(format!("{source_datastore}:{snapshot}"));
                     }
                 }
-                task_log!(worker, "Restore snapshot '{}' done", snapshot);
+                info!("Restore snapshot '{}' done", snapshot);
                 Ok::<_, Error>(())
             }) {
-                task_warn!(
-                    worker,
-                    "could not copy {source_datastore}:{snapshot}: {err}"
-                );
+                warn!("could not copy {source_datastore}:{snapshot}: {err}");
                 errors = true;
             }
         }
@@ -921,7 +894,7 @@ fn restore_list_worker(
                 std::fs::remove_dir_all(&tmp_path)
                     .map_err(|err| format_err!("remove_dir_all failed - {err}"))
             }) {
-                task_warn!(worker, "could not clean up temp dir {tmp_path:?}: {err}");
+                warn!("could not clean up temp dir {tmp_path:?}: {err}");
                 errors = true;
             };
         }
@@ -930,19 +903,16 @@ fn restore_list_worker(
             bail!("errors during copy occurred");
         }
         if !skipped.is_empty() {
-            task_log!(worker, "(partially) skipped the following snapshots:");
+            info!("(partially) skipped the following snapshots:");
             for snap in skipped {
-                task_log!(worker, "  {snap}");
+                info!("  {snap}");
             }
         }
         Ok(())
     });
 
     if res.is_err() {
-        task_warn!(
-            worker,
-            "Error during restore, partially restored snapshots will NOT be cleaned up"
-        );
+        warn!("Error during restore, partially restored snapshots will NOT be cleaned up");
     }
 
     for (datastore, _) in store_map.used_datastores().values() {
@@ -950,7 +920,7 @@ fn restore_list_worker(
         match std::fs::remove_dir_all(tmp_path) {
             Ok(()) => {}
             Err(err) if err.kind() == std::io::ErrorKind::NotFound => {}
-            Err(err) => task_warn!(worker, "error cleaning up: {}", err),
+            Err(err) => warn!("error cleaning up: {}", err),
         }
     }
 
@@ -1033,13 +1003,10 @@ fn restore_snapshots_to_tmpdir(
     for file_num in file_list {
         let current_file_number = drive.current_file_number()?;
         if current_file_number != *file_num {
-            task_log!(
-                worker,
-                "was at file {current_file_number}, moving to {file_num}"
-            );
+            info!("was at file {current_file_number}, moving to {file_num}");
             drive.move_to_file(*file_num)?;
             let current_file_number = drive.current_file_number()?;
-            task_log!(worker, "now at file {}", current_file_number);
+            info!("now at file {}", current_file_number);
         }
         let mut reader = drive.read_next_file()?;
 
@@ -1061,20 +1028,14 @@ fn restore_snapshots_to_tmpdir(
                 let source_datastore = archive_header.store;
                 let snapshot = archive_header.snapshot;
 
-                task_log!(
-                    worker,
-                    "File {file_num}: snapshot archive {source_datastore}:{snapshot}",
-                );
+                info!("File {file_num}: snapshot archive {source_datastore}:{snapshot}",);
 
                 let mut decoder = pxar::decoder::sync::Decoder::from_std(reader)?;
 
                 let target_datastore = match store_map.target_store(&source_datastore) {
                     Some(datastore) => datastore,
                     None => {
-                        task_warn!(
-                            worker,
-                            "could not find target datastore for {source_datastore}:{snapshot}",
-                        );
+                        warn!("could not find target datastore for {source_datastore}:{snapshot}",);
                         continue;
                     }
                 };
@@ -1126,10 +1087,10 @@ fn restore_file_chunk_map(
     for (nr, chunk_map) in file_chunk_map.iter_mut() {
         let current_file_number = drive.current_file_number()?;
         if current_file_number != *nr {
-            task_log!(worker, "was at file {current_file_number}, moving to {nr}");
+            info!("was at file {current_file_number}, moving to {nr}");
             drive.move_to_file(*nr)?;
             let current_file_number = drive.current_file_number()?;
-            task_log!(worker, "now at file {}", current_file_number);
+            info!("now at file {}", current_file_number);
         }
         let mut reader = drive.read_next_file()?;
         let header: MediaContentHeader = unsafe { reader.read_le_value()? };
@@ -1146,10 +1107,7 @@ fn restore_file_chunk_map(
 
                 let source_datastore = archive_header.store;
 
-                task_log!(
-                    worker,
-                    "File {nr}: chunk archive for datastore '{source_datastore}'",
-                );
+                info!("File {nr}: chunk archive for datastore '{source_datastore}'",);
 
                 let datastore = store_map.target_store(&source_datastore).ok_or_else(|| {
                     format_err!("unexpected chunk archive for store: {source_datastore}")
@@ -1161,7 +1119,7 @@ fn restore_file_chunk_map(
                     datastore.clone(),
                     chunk_map,
                 )?;
-                task_log!(worker, "restored {count} chunks");
+                info!("restored {count} chunks");
             }
             _ => bail!("unexpected content magic {:?}", header.content_magic),
         }
@@ -1221,8 +1179,7 @@ fn restore_partial_chunk_archive<'a>(
 
     let elapsed = start_time.elapsed()?.as_secs_f64();
     let bytes = bytes.load(std::sync::atomic::Ordering::SeqCst) as f64;
-    task_log!(
-        worker,
+    info!(
         "restored {} ({:.2}/s)",
         HumanByte::new_decimal(bytes),
         HumanByte::new_decimal(bytes / elapsed),
@@ -1301,15 +1258,11 @@ pub fn restore_media(
         let current_file_number = drive.current_file_number()?;
         let reader = match drive.read_next_file() {
             Err(BlockReadError::EndOfFile) => {
-                task_log!(
-                    worker,
-                    "skip unexpected filemark at pos {}",
-                    current_file_number
-                );
+                info!("skip unexpected filemark at pos {}", current_file_number);
                 continue;
             }
             Err(BlockReadError::EndOfStream) => {
-                task_log!(worker, "detected EOT after {} files", current_file_number);
+                info!("detected EOT after {} files", current_file_number);
                 break;
             }
             Err(BlockReadError::Error(err)) => {
@@ -1373,12 +1326,9 @@ fn restore_archive<'a>(
             let datastore_name = archive_header.store;
             let snapshot = archive_header.snapshot;
 
-            task_log!(
-                worker,
+            info!(
                 "File {}: snapshot archive {}:{}",
-                current_file_number,
-                datastore_name,
-                snapshot
+                current_file_number, datastore_name, snapshot
             );
 
             let (backup_ns, backup_dir) = parse_ns_and_snapshot(&snapshot)?;
@@ -1413,16 +1363,16 @@ fn restore_archive<'a>(
                     path.push(rel_path);
 
                     if is_new {
-                        task_log!(worker, "restore snapshot {}", backup_dir);
+                        info!("restore snapshot {}", backup_dir);
 
-                        match restore_snapshot_archive(worker.clone(), reader, &path) {
+                        match restore_snapshot_archive(worker, reader, &path) {
                             Err(err) => {
                                 std::fs::remove_dir_all(&path)?;
                                 bail!("restore snapshot {} failed - {}", backup_dir, err);
                             }
                             Ok(false) => {
                                 std::fs::remove_dir_all(&path)?;
-                                task_log!(worker, "skip incomplete snapshot {}", backup_dir);
+                                info!("skip incomplete snapshot {}", backup_dir);
                             }
                             Ok(true) => {
                                 catalog.register_snapshot(
@@ -1438,7 +1388,7 @@ fn restore_archive<'a>(
                         return Ok(());
                     }
                 } else {
-                    task_log!(worker, "skipping...");
+                    info!("skipping...");
                 }
             }
 
@@ -1465,11 +1415,9 @@ fn restore_archive<'a>(
 
             let source_datastore = archive_header.store;
 
-            task_log!(
-                worker,
+            info!(
                 "File {}: chunk archive for datastore '{}'",
-                current_file_number,
-                source_datastore
+                current_file_number, source_datastore
             );
             let datastore = target
                 .as_ref()
@@ -1487,15 +1435,9 @@ fn restore_archive<'a>(
                     .or_default();
 
                 let chunks = if let Some(datastore) = datastore {
-                    restore_chunk_archive(
-                        worker.clone(),
-                        reader,
-                        datastore,
-                        checked_chunks,
-                        verbose,
-                    )?
+                    restore_chunk_archive(worker, reader, datastore, checked_chunks, verbose)?
                 } else {
-                    scan_chunk_archive(worker.clone(), reader, verbose)?
+                    scan_chunk_archive(worker, reader, verbose)?
                 };
 
                 if let Some(chunks) = chunks {
@@ -1505,12 +1447,12 @@ fn restore_archive<'a>(
                         &source_datastore,
                         &chunks[..],
                     )?;
-                    task_log!(worker, "register {} chunks", chunks.len());
+                    info!("register {} chunks", chunks.len());
                     catalog.commit_if_large()?;
                 }
                 return Ok(());
             } else if target.is_some() {
-                task_log!(worker, "skipping...");
+                info!("skipping...");
             }
 
             reader.skip_data()?; // read all data
@@ -1521,11 +1463,9 @@ fn restore_archive<'a>(
             let archive_header: CatalogArchiveHeader = serde_json::from_slice(&header_data)
                 .map_err(|err| format_err!("unable to parse catalog archive header - {}", err))?;
 
-            task_log!(
-                worker,
+            info!(
                 "File {}: skip catalog '{}'",
-                current_file_number,
-                archive_header.uuid
+                current_file_number, archive_header.uuid
             );
 
             reader.skip_data()?; // read all data
@@ -1560,7 +1500,7 @@ fn scan_chunk_archive<'a>(
 
                 // check if this is an aborted stream without end marker
                 if let Ok(false) = reader.has_end_marker() {
-                    task_log!(worker, "missing stream end marker");
+                    info!("missing stream end marker");
                     return Ok(None);
                 }
 
@@ -1572,7 +1512,7 @@ fn scan_chunk_archive<'a>(
         worker.check_abort()?;
 
         if verbose {
-            task_log!(worker, "Found chunk: {}", hex::encode(digest));
+            info!("Found chunk: {}", hex::encode(digest));
         }
 
         chunks.push(digest);
@@ -1596,8 +1536,6 @@ fn restore_chunk_archive<'a>(
     let bytes = Arc::new(std::sync::atomic::AtomicU64::new(0));
     let bytes2 = bytes.clone();
 
-    let worker2 = worker.clone();
-
     let writer_pool = ParallelHandler::new(
         "tape restore chunk writer",
         4,
@@ -1605,7 +1543,7 @@ fn restore_chunk_archive<'a>(
             let chunk_exists = datastore.cond_touch_chunk(&digest, false)?;
             if !chunk_exists {
                 if verbose {
-                    task_log!(worker2, "Insert chunk: {}", hex::encode(digest));
+                    info!("Insert chunk: {}", hex::encode(digest));
                 }
                 bytes2.fetch_add(chunk.raw_size(), std::sync::atomic::Ordering::SeqCst);
                 // println!("verify and write {}", hex::encode(&digest));
@@ -1616,7 +1554,7 @@ fn restore_chunk_archive<'a>(
 
                 datastore.insert_chunk(&chunk, &digest)?;
             } else if verbose {
-                task_log!(worker2, "Found existing chunk: {}", hex::encode(digest));
+                info!("Found existing chunk: {}", hex::encode(digest));
             }
             Ok(())
         },
@@ -1638,7 +1576,7 @@ fn restore_chunk_archive<'a>(
 
                 // check if this is an aborted stream without end marker
                 if let Ok(false) = reader.has_end_marker() {
-                    task_log!(worker, "missing stream end marker");
+                    info!("missing stream end marker");
                     return Ok(None);
                 }
 
@@ -1662,8 +1600,7 @@ fn restore_chunk_archive<'a>(
 
     let elapsed = start_time.elapsed()?.as_secs_f64();
     let bytes = bytes.load(std::sync::atomic::Ordering::SeqCst) as f64;
-    task_log!(
-        worker,
+    info!(
         "restored {} ({:.2}/s)",
         HumanByte::new_decimal(bytes),
         HumanByte::new_decimal(bytes / elapsed),
@@ -1814,7 +1751,6 @@ fn try_restore_snapshot_archive<R: pxar::decoder::SeqRead>(
 
 /// Try to restore media catalogs (form catalog_archives)
 pub fn fast_catalog_restore(
-    worker: &WorkerTask,
     drive: &mut Box<dyn TapeDriver>,
     media_set: &MediaSet,
     uuid: &Uuid, // current media Uuid
@@ -1835,14 +1771,11 @@ pub fn fast_catalog_restore(
             // limit reader scope
             let mut reader = match drive.read_next_file() {
                 Err(BlockReadError::EndOfFile) => {
-                    task_log!(
-                        worker,
-                        "skip unexpected filemark at pos {current_file_number}"
-                    );
+                    info!("skip unexpected filemark at pos {current_file_number}");
                     continue;
                 }
                 Err(BlockReadError::EndOfStream) => {
-                    task_log!(worker, "detected EOT after {current_file_number} files");
+                    info!("detected EOT after {current_file_number} files");
                     break;
                 }
                 Err(BlockReadError::Error(err)) => {
@@ -1859,7 +1792,7 @@ pub fn fast_catalog_restore(
             if header.content_magic == PROXMOX_BACKUP_CATALOG_ARCHIVE_MAGIC_1_0
                 || header.content_magic == PROXMOX_BACKUP_CATALOG_ARCHIVE_MAGIC_1_1
             {
-                task_log!(worker, "found catalog at pos {}", current_file_number);
+                info!("found catalog at pos {}", current_file_number);
 
                 let header_data = reader.read_exact_allocated(header.size as usize)?;
 
@@ -1869,11 +1802,7 @@ pub fn fast_catalog_restore(
                     })?;
 
                 if &archive_header.media_set_uuid != media_set.uuid() {
-                    task_log!(
-                        worker,
-                        "skipping unrelated catalog at pos {}",
-                        current_file_number
-                    );
+                    info!("skipping unrelated catalog at pos {}", current_file_number);
                     reader.skip_data()?; // read all data
                     continue;
                 }
@@ -1886,8 +1815,7 @@ pub fn fast_catalog_restore(
                 });
 
                 if !wanted {
-                    task_log!(
-                        worker,
+                    info!(
                         "skip catalog because media '{}' not inventarized",
                         catalog_uuid
                     );
@@ -1900,11 +1828,7 @@ pub fn fast_catalog_restore(
                 } else {
                     // only restore if catalog does not exist
                     if MediaCatalog::exists(TAPE_STATUS_DIR, catalog_uuid) {
-                        task_log!(
-                            worker,
-                            "catalog for media '{}' already exists",
-                            catalog_uuid
-                        );
+                        info!("catalog for media '{}' already exists", catalog_uuid);
                         reader.skip_data()?; // read all data
                         continue;
                     }
@@ -1920,19 +1844,11 @@ pub fn fast_catalog_restore(
                 match MediaCatalog::parse_catalog_header(&mut file)? {
                     (true, Some(media_uuid), Some(media_set_uuid)) => {
                         if &media_uuid != catalog_uuid {
-                            task_log!(
-                                worker,
-                                "catalog uuid mismatch at pos {}",
-                                current_file_number
-                            );
+                            info!("catalog uuid mismatch at pos {}", current_file_number);
                             continue;
                         }
                         if media_set_uuid != archive_header.media_set_uuid {
-                            task_log!(
-                                worker,
-                                "catalog media_set mismatch at pos {}",
-                                current_file_number
-                            );
+                            info!("catalog media_set mismatch at pos {}", current_file_number);
                             continue;
                         }
 
@@ -1943,18 +1859,14 @@ pub fn fast_catalog_restore(
                         )?;
 
                         if catalog_uuid == uuid {
-                            task_log!(worker, "successfully restored catalog");
+                            info!("successfully restored catalog");
                             found_catalog = true
                         } else {
-                            task_log!(
-                                worker,
-                                "successfully restored related catalog {}",
-                                media_uuid
-                            );
+                            info!("successfully restored related catalog {}", media_uuid);
                         }
                     }
                     _ => {
-                        task_warn!(worker, "got incomplete catalog header - skip file");
+                        warn!("got incomplete catalog header - skip file");
                         continue;
                     }
                 }
@@ -1968,7 +1880,7 @@ pub fn fast_catalog_restore(
         }
         moved_to_eom = true;
 
-        task_log!(worker, "searching for catalog at EOT (moving to EOT)");
+        info!("searching for catalog at EOT (moving to EOT)");
         drive.move_to_last_file()?;
 
         let new_file_number = drive.current_file_number()?;
-- 
2.43.0





^ permalink raw reply	[flat|nested] 5+ messages in thread

* [pbs-devel] [PATCH proxmox v2 3/3] proxmox-log: added tracing infra
  2024-04-10 11:48 [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
  2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 1/3] removed task_log! macro and moved to tracing Gabriel Goller
  2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 2/3] removed task_log! macro and moved to tracing in api Gabriel Goller
@ 2024-04-10 11:49 ` Gabriel Goller
  2024-04-10 14:17 ` [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
  3 siblings, 0 replies; 5+ messages in thread
From: Gabriel Goller @ 2024-04-10 11:49 UTC (permalink / raw)
  To: pbs-devel

Added the `proxmox_log` crate which includes the new logging infra.
Exports the `init_logger` function, which creates the `tracing` logger
that includes the default Subscriber and two custom layers. The first
layer is the syslog layer, which uses the `syslog` crate. The second
layer is the `file_layer` which uses the original `FileLogger` and
writes to a file (the tasklog). This last layer stores the `FileLogger`
as a `tokio::task_local` variable, which gets initialized at `spawn` or
`new_thread` in the `WorkerTask`.

Signed-off-by: Gabriel Goller <g.goller@proxmox.com>
---
 Cargo.toml                                    |   6 +
 proxmox-log/Cargo.toml                        |  23 ++++
 proxmox-log/debian/changelog                  |   5 +
 proxmox-log/debian/control                    |  53 +++++++++
 proxmox-log/debian/copyright                  |  18 +++
 proxmox-log/debian/debcargo.toml              |   7 ++
 .../src/file_logger.rs                        |   2 +-
 proxmox-log/src/lib.rs                        |  34 ++++++
 proxmox-log/src/syslog_tasklog_layer.rs       | 106 +++++++++++++++++
 proxmox-rest-server/Cargo.toml                |   2 +
 proxmox-rest-server/src/api_config.rs         |   3 +-
 proxmox-rest-server/src/lib.rs                |   3 -
 proxmox-rest-server/src/rest.rs               |   4 +-
 proxmox-rest-server/src/worker_task.rs        | 108 +++++++++---------
 proxmox-sys/src/worker_task_context.rs        |  47 --------
 15 files changed, 315 insertions(+), 106 deletions(-)
 create mode 100644 proxmox-log/Cargo.toml
 create mode 100644 proxmox-log/debian/changelog
 create mode 100644 proxmox-log/debian/control
 create mode 100644 proxmox-log/debian/copyright
 create mode 100644 proxmox-log/debian/debcargo.toml
 rename {proxmox-rest-server => proxmox-log}/src/file_logger.rs (98%)
 create mode 100644 proxmox-log/src/lib.rs
 create mode 100644 proxmox-log/src/syslog_tasklog_layer.rs

diff --git a/Cargo.toml b/Cargo.toml
index 535d245..ac51f96 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -14,6 +14,7 @@ members = [
     "proxmox-io",
     "proxmox-lang",
     "proxmox-ldap",
+    "proxmox-log",
     "proxmox-login",
     "proxmox-metrics",
     "proxmox-notify",
@@ -92,10 +93,14 @@ tokio = "1.6"
 tokio-openssl = "0.6.1"
 tokio-stream = "0.1.0"
 tower-service = "0.3.0"
+tracing = "0.1"
+tracing-log = { version = "0.2.0", default-features = false }
+tracing-subscriber = "0.3.16"
 url = "2.2"
 walkdir = "2"
 webauthn-rs = "0.3"
 zstd = { version = "0.12", features = [ "bindgen" ] }
+syslog = "6"
 
 # workspace dependencies
 proxmox-api-macro = { version = "1.0.8", path = "proxmox-api-macro" }
@@ -106,6 +111,7 @@ proxmox-http-error = { version = "0.1.0", path = "proxmox-http-error" }
 proxmox-human-byte = { version = "0.1.0", path = "proxmox-human-byte" }
 proxmox-io = { version = "1.0.0", path = "proxmox-io" }
 proxmox-lang = { version = "1.1", path = "proxmox-lang" }
+proxmox-log= { version = "0.1.0", path = "proxmox-log" }
 proxmox-login = { version = "0.1.0", path = "proxmox-login" }
 proxmox-rest-server = { version = "0.5.2", path = "proxmox-rest-server" }
 proxmox-router = { version = "2.1.3", path = "proxmox-router" }
diff --git a/proxmox-log/Cargo.toml b/proxmox-log/Cargo.toml
new file mode 100644
index 0000000..e05b0be
--- /dev/null
+++ b/proxmox-log/Cargo.toml
@@ -0,0 +1,23 @@
+[package]
+name = "proxmox-log"
+version = "0.1.0"
+authors.workspace = true
+edition.workspace = true
+license.workspace = true
+repository.workspace = true
+description = "Logging infrastructure for proxmox"
+
+exclude.workspace = true
+
+[dependencies]
+anyhow.workspace = true
+syslog.workspace = true
+nix.workspace = true
+log.workspace = true
+tracing.workspace = true
+tracing-subscriber.workspace = true
+tracing-log.workspace = true
+tokio = { workspace = true, features = ["rt-multi-thread"] }
+proxmox-time.workspace = true
+proxmox-sys.workspace = true
+
diff --git a/proxmox-log/debian/changelog b/proxmox-log/debian/changelog
new file mode 100644
index 0000000..aaf8073
--- /dev/null
+++ b/proxmox-log/debian/changelog
@@ -0,0 +1,5 @@
+rust-proxmox-log (0.1.0-3) UNRELEASED; urgency=medium
+
+  * Initial release 
+
+ -- Gabriel Goller <ggoller@luna.proxmox.com>  Wed, 11 Oct 2023 15:13:58 +0200
diff --git a/proxmox-log/debian/control b/proxmox-log/debian/control
new file mode 100644
index 0000000..4f22ecb
--- /dev/null
+++ b/proxmox-log/debian/control
@@ -0,0 +1,53 @@
+Source: rust-proxmox-log
+Section: rust
+Priority: optional
+Build-Depends: debhelper (>= 12),
+ dh-cargo (>= 25),
+ cargo:native <!nocheck>,
+ rustc:native <!nocheck>,
+ libstd-rust-dev <!nocheck>,
+ librust-anyhow-1+default-dev <!nocheck>,
+ librust-log-0.4+default-dev (>= 0.4.17-~~) <!nocheck>,
+ librust-nix-0.26+default-dev (>= 0.26.1-~~) <!nocheck>,
+ librust-proxmox-sys-0.5+default-dev <!nocheck>,
+ librust-proxmox-time-1+default-dev (>= 1.1.4-~~) <!nocheck>,
+ librust-syslog-6+default-dev <!nocheck>,
+ librust-tokio-1+default-dev (>= 1.6-~~) <!nocheck>,
+ librust-tokio-1+rt-multi-thread-dev (>= 1.6-~~) <!nocheck>,
+ librust-tracing-0.1+default-dev <!nocheck>,
+ librust-tracing-log-0.1-dev (>= 0.1.3-~~) <!nocheck>,
+ librust-tracing-subscriber-0.3+default-dev (>= 0.3.16-~~) <!nocheck>
+Maintainer: Proxmox Support Team <support@proxmox.com>
+Standards-Version: 4.6.1
+Vcs-Git: git://git.proxmox.com/git/proxmox.git
+Vcs-Browser: https://git.proxmox.com/?p=proxmox.git
+X-Cargo-Crate: proxmox-log
+Rules-Requires-Root: no
+
+Package: librust-proxmox-log-dev
+Architecture: any
+Multi-Arch: same
+Depends:
+ ${misc:Depends},
+ librust-anyhow-1+default-dev,
+ librust-log-0.4+default-dev (>= 0.4.17-~~),
+ librust-nix-0.26+default-dev (>= 0.26.1-~~),
+ librust-proxmox-sys-0.5+default-dev,
+ librust-proxmox-time-1+default-dev (>= 1.1.4-~~),
+ librust-syslog-6+default-dev,
+ librust-tokio-1+default-dev (>= 1.6-~~),
+ librust-tokio-1+rt-multi-thread-dev (>= 1.6-~~),
+ librust-tracing-0.1+default-dev,
+ librust-tracing-log-0.1-dev (>= 0.1.3-~~),
+ librust-tracing-subscriber-0.3+default-dev (>= 0.3.16-~~)
+Provides:
+ librust-proxmox-log+default-dev (= ${binary:Version}),
+ librust-proxmox-log-0-dev (= ${binary:Version}),
+ librust-proxmox-log-0+default-dev (= ${binary:Version}),
+ librust-proxmox-log-0.1-dev (= ${binary:Version}),
+ librust-proxmox-log-0.1+default-dev (= ${binary:Version}),
+ librust-proxmox-log-0.1.0-dev (= ${binary:Version}),
+ librust-proxmox-log-0.1.0+default-dev (= ${binary:Version})
+Description: Logging infrastructure for proxmox - Rust source code
+ This package contains the source for the Rust proxmox-log crate, packaged by
+ debcargo for use with cargo and dh-cargo.
diff --git a/proxmox-log/debian/copyright b/proxmox-log/debian/copyright
new file mode 100644
index 0000000..0d9eab3
--- /dev/null
+++ b/proxmox-log/debian/copyright
@@ -0,0 +1,18 @@
+Format: https://www.debian.org/doc/packaging-manuals/copyright-format/1.0/
+
+Files:
+ *
+Copyright: 2019 - 2023 Proxmox Server Solutions GmbH <support@proxmox.com>
+License: AGPL-3.0-or-later
+ This program is free software: you can redistribute it and/or modify it under
+ the terms of the GNU Affero General Public License as published by the Free
+ Software Foundation, either version 3 of the License, or (at your option) any
+ later version.
+ .
+ This program is distributed in the hope that it will be useful, but WITHOUT
+ ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
+ FOR A PARTICULAR PURPOSE. See the GNU Affero General Public License for more
+ details.
+ .
+ You should have received a copy of the GNU Affero General Public License along
+ with this program. If not, see <https://www.gnu.org/licenses/>.
diff --git a/proxmox-log/debian/debcargo.toml b/proxmox-log/debian/debcargo.toml
new file mode 100644
index 0000000..b7864cd
--- /dev/null
+++ b/proxmox-log/debian/debcargo.toml
@@ -0,0 +1,7 @@
+overlay = "."
+crate_src_path = ".."
+maintainer = "Proxmox Support Team <support@proxmox.com>"
+
+[source]
+vcs_git = "git://git.proxmox.com/git/proxmox.git"
+vcs_browser = "https://git.proxmox.com/?p=proxmox.git"
diff --git a/proxmox-rest-server/src/file_logger.rs b/proxmox-log/src/file_logger.rs
similarity index 98%
rename from proxmox-rest-server/src/file_logger.rs
rename to proxmox-log/src/file_logger.rs
index 2bb1fac..c7e1d64 100644
--- a/proxmox-rest-server/src/file_logger.rs
+++ b/proxmox-log/src/file_logger.rs
@@ -30,7 +30,7 @@ pub struct FileLogOptions {
 /// #### Example:
 /// ```
 /// # use anyhow::{bail, format_err, Error};
-/// use proxmox_rest_server::{flog, FileLogger, FileLogOptions};
+/// use proxmox_log::{flog, FileLogger, FileLogOptions};
 ///
 /// # std::fs::remove_file("test.log");
 /// let options = FileLogOptions {
diff --git a/proxmox-log/src/lib.rs b/proxmox-log/src/lib.rs
new file mode 100644
index 0000000..15fa22d
--- /dev/null
+++ b/proxmox-log/src/lib.rs
@@ -0,0 +1,34 @@
+use std::{cell::RefCell, env};
+use syslog_tasklog_layer::SyslogAndTasklogLayer;
+use tracing_log::{AsLog, LogTracer};
+use tracing_subscriber::filter::LevelFilter;
+use tracing_subscriber::prelude::*;
+
+mod file_logger;
+pub use file_logger::{FileLogOptions, FileLogger};
+
+mod syslog_tasklog_layer;
+
+tokio::task_local! {
+    pub static LOGGER: RefCell<FileLogger>;
+    pub static WARN_COUNTER: RefCell<u64>;
+}
+
+pub fn init_logger(
+    env_var_name: &str,
+    default_log_level: LevelFilter,
+    application_name: &str,
+) -> Result<(), anyhow::Error> {
+    let mut log_level = default_log_level;
+    if let Ok(v) = env::var(env_var_name) {
+        if let Ok(l) = v.parse::<LevelFilter>() {
+            log_level = l;
+        }
+    }
+    let registry = tracing_subscriber::registry()
+        .with(SyslogAndTasklogLayer::new(application_name.to_string()).with_filter(log_level));
+
+    tracing::subscriber::set_global_default(registry)?;
+    LogTracer::init_with_filter(log_level.as_log())?;
+    Ok(())
+}
diff --git a/proxmox-log/src/syslog_tasklog_layer.rs b/proxmox-log/src/syslog_tasklog_layer.rs
new file mode 100644
index 0000000..344a514
--- /dev/null
+++ b/proxmox-log/src/syslog_tasklog_layer.rs
@@ -0,0 +1,106 @@
+use std::fmt::Write as _;
+use std::sync::Arc;
+use std::sync::Mutex;
+
+use syslog::{Formatter3164, LoggerBackend};
+use tracing::field::Field;
+use tracing::field::Visit;
+use tracing::Event;
+use tracing::Level;
+use tracing::Subscriber;
+use tracing_subscriber::layer::Context;
+use tracing_subscriber::Layer;
+
+use crate::FileLogger;
+use crate::LOGGER;
+use crate::WARN_COUNTER;
+
+pub struct SyslogAndTasklogLayer {
+    syslog_logger: Arc<Mutex<syslog::Logger<LoggerBackend, Formatter3164>>>,
+}
+
+impl SyslogAndTasklogLayer {
+    pub fn new(application_name: String) -> Self {
+        let formatter = Formatter3164 {
+            facility: syslog::Facility::LOG_DAEMON,
+            process: application_name,
+            ..Formatter3164::default()
+        };
+
+        // we panic here if we can't initialize the syslogger
+        let logger = syslog::unix(formatter)
+            .map_err(|e| {
+                anyhow::Error::new(std::io::Error::new(
+                    std::io::ErrorKind::Other,
+                    e.description(),
+                ))
+            })
+            .unwrap();
+
+        let logger = Arc::new(Mutex::new(logger));
+
+        Self {
+            syslog_logger: logger,
+        }
+    }
+}
+
+impl<S: Subscriber> Layer<S> for SyslogAndTasklogLayer {
+    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
+        let mut buf = String::new();
+        event.record(&mut EventVisitor::new(&mut buf));
+        let level = event.metadata().level();
+
+        let result = LOGGER.try_with(|logger| {
+            log_to_file(&mut logger.borrow_mut(), level, &buf);
+        });
+        if result.is_err() || *level == Level::ERROR {
+            log_to_syslog(&mut self.syslog_logger.lock().unwrap(), level, &buf);
+        }
+    }
+}
+
+fn log_to_syslog(
+    logger: &mut syslog::Logger<LoggerBackend, Formatter3164>,
+    level: &Level,
+    buf: &String,
+) {
+    let _ = match *level {
+        Level::ERROR => logger.err(buf),
+        Level::WARN => logger.warning(buf),
+        Level::INFO => logger.info(buf),
+        Level::DEBUG => logger.debug(buf),
+        Level::TRACE => logger.debug(buf),
+    };
+}
+fn log_to_file(logger: &mut FileLogger, level: &Level, buf: &String) {
+    match *level {
+        Level::ERROR | Level::WARN => {
+            WARN_COUNTER.with(|counter| {
+                counter.replace_with(|c| c.to_owned() + 1);
+            });
+            logger.log(buf);
+        }
+        Level::INFO => logger.log(buf),
+        Level::DEBUG => logger.log(format!("DEBUG: {}", buf)),
+        Level::TRACE => logger.log(format!("TRACE: {}", buf)),
+    };
+}
+
+struct EventVisitor<'a> {
+    buf: &'a mut String,
+}
+
+impl<'a> EventVisitor<'a> {
+    fn new(buf: &'a mut String) -> Self {
+        Self { buf }
+    }
+}
+
+impl Visit for EventVisitor<'_> {
+    fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
+        if field.name() == "message" {
+            let _ = write!(self.buf, "{value:?}");
+        }
+    }
+}
diff --git a/proxmox-rest-server/Cargo.toml b/proxmox-rest-server/Cargo.toml
index 94330ff..2bfea4a 100644
--- a/proxmox-rest-server/Cargo.toml
+++ b/proxmox-rest-server/Cargo.toml
@@ -34,6 +34,7 @@ tokio-openssl.workspace = true
 tokio-stream.workspace = true
 tower-service.workspace = true
 url.workspace = true
+tracing.workspace = true
 
 proxmox-async.workspace = true
 proxmox-compression.workspace = true
@@ -44,6 +45,7 @@ proxmox-router.workspace = true
 proxmox-schema = { workspace = true, features = [ "api-macro", "upid-api-impl" ] }
 proxmox-sys = { workspace = true, features = [ "logrotate", "timer" ] }
 proxmox-time.workspace = true
+proxmox-log.workspace = true
 
 [features]
 default = []
diff --git a/proxmox-rest-server/src/api_config.rs b/proxmox-rest-server/src/api_config.rs
index 8058944..308c9c9 100644
--- a/proxmox-rest-server/src/api_config.rs
+++ b/proxmox-rest-server/src/api_config.rs
@@ -12,11 +12,12 @@ use hyper::http::request::Parts;
 use hyper::{Body, Response};
 use tower_service::Service;
 
+use proxmox_log::{FileLogOptions, FileLogger};
 use proxmox_router::{Router, RpcEnvironmentType, UserInformation};
 use proxmox_sys::fs::{create_path, CreateOptions};
 
 use crate::rest::Handler;
-use crate::{CommandSocket, FileLogOptions, FileLogger, RestEnvironment};
+use crate::{CommandSocket, RestEnvironment};
 
 /// REST server configuration
 pub struct ApiConfig {
diff --git a/proxmox-rest-server/src/lib.rs b/proxmox-rest-server/src/lib.rs
index ce9e4f1..e886636 100644
--- a/proxmox-rest-server/src/lib.rs
+++ b/proxmox-rest-server/src/lib.rs
@@ -41,9 +41,6 @@ pub use state::*;
 mod command_socket;
 pub use command_socket::*;
 
-mod file_logger;
-pub use file_logger::{FileLogOptions, FileLogger};
-
 mod api_config;
 pub use api_config::{ApiConfig, AuthError, AuthHandler, IndexHandler, UnixAcceptor};
 
diff --git a/proxmox-rest-server/src/rest.rs b/proxmox-rest-server/src/rest.rs
index 4900592..efc198f 100644
--- a/proxmox-rest-server/src/rest.rs
+++ b/proxmox-rest-server/src/rest.rs
@@ -31,10 +31,10 @@ use proxmox_schema::{ObjectSchemaType, ParameterSchema};
 
 use proxmox_async::stream::AsyncReaderStream;
 use proxmox_compression::{DeflateEncoder, Level};
+use proxmox_log::FileLogger;
 
 use crate::{
-    formatter::*, normalize_path, ApiConfig, AuthError, CompressionMethod, FileLogger,
-    RestEnvironment,
+    formatter::*, normalize_path, ApiConfig, AuthError, CompressionMethod, RestEnvironment,
 };
 
 extern "C" {
diff --git a/proxmox-rest-server/src/worker_task.rs b/proxmox-rest-server/src/worker_task.rs
index 4cf24cc..b06eae7 100644
--- a/proxmox-rest-server/src/worker_task.rs
+++ b/proxmox-rest-server/src/worker_task.rs
@@ -1,3 +1,4 @@
+use std::cell::RefCell;
 use std::collections::{HashMap, VecDeque};
 use std::fs::File;
 use std::io::{BufRead, BufReader, Read, Write};
@@ -12,21 +13,23 @@ use futures::*;
 use lazy_static::lazy_static;
 use nix::fcntl::OFlag;
 use once_cell::sync::OnceCell;
+use proxmox_log::{LOGGER, WARN_COUNTER};
 use serde::{Deserialize, Serialize};
 use serde_json::{json, Value};
 use tokio::signal::unix::SignalKind;
 use tokio::sync::oneshot;
+use tracing::{info, warn};
 
 use proxmox_lang::try_block;
+use proxmox_log::{FileLogOptions, FileLogger};
 use proxmox_schema::upid::UPID;
 use proxmox_sys::fs::{atomic_open_or_create_file, create_path, replace_file, CreateOptions};
 use proxmox_sys::linux::procfs;
-use proxmox_sys::task_warn;
 
 use proxmox_sys::logrotate::{LogRotate, LogRotateFiles};
 use proxmox_sys::WorkerTaskContext;
 
-use crate::{CommandSocket, FileLogOptions, FileLogger};
+use crate::CommandSocket;
 
 struct TaskListLockGuard(File);
 
@@ -294,7 +297,7 @@ pub fn rotate_task_log_archive(
 
 /// removes all task logs that are older than the oldest task entry in the
 /// task archive
-pub fn cleanup_old_tasks(worker: &dyn WorkerTaskContext, compressed: bool) -> Result<(), Error> {
+pub fn cleanup_old_tasks(compressed: bool) -> Result<(), Error> {
     let setup = worker_task_setup()?;
 
     let _lock = setup.lock_task_list_files(true)?;
@@ -332,7 +335,10 @@ pub fn cleanup_old_tasks(worker: &dyn WorkerTaskContext, compressed: bool) -> Re
                 Ok(files) => files,
                 Err(err) if err.kind() == std::io::ErrorKind::NotFound => continue,
                 Err(err) => {
-                    task_warn!(worker, "could not check task logs in '{:02X}': {}", i, err);
+                    warn!(
+                        tasklog = true,
+                        "could not check task logs in '{:02X}': {}", i, err
+                    );
                     continue;
                 }
             };
@@ -340,11 +346,9 @@ pub fn cleanup_old_tasks(worker: &dyn WorkerTaskContext, compressed: bool) -> Re
                 let file = match file {
                     Ok(file) => file,
                     Err(err) => {
-                        task_warn!(
-                            worker,
-                            "could not check some task log in '{:02X}': {}",
-                            i,
-                            err
+                        warn!(
+                            tasklog = true,
+                            "could not check some task log in '{:02X}': {}", i, err
                         );
                         continue;
                     }
@@ -354,7 +358,10 @@ pub fn cleanup_old_tasks(worker: &dyn WorkerTaskContext, compressed: bool) -> Re
                 let modified = match get_modified(file) {
                     Ok(modified) => modified,
                     Err(err) => {
-                        task_warn!(worker, "error getting mtime for '{:?}': {}", path, err);
+                        warn!(
+                            tasklog = true,
+                            "error getting mtime for '{:?}': {}", path, err
+                        );
                         continue;
                     }
                 };
@@ -364,7 +371,10 @@ pub fn cleanup_old_tasks(worker: &dyn WorkerTaskContext, compressed: bool) -> Re
                         Ok(()) => {}
                         Err(err) if err.kind() == std::io::ErrorKind::NotFound => {}
                         Err(err) => {
-                            task_warn!(worker, "could not remove file '{:?}': {}", path, err)
+                            warn!(
+                                tasklog = true,
+                                "could not remove file '{:?}': {}", path, err
+                            )
                         }
                     }
                 }
@@ -822,9 +832,7 @@ impl std::fmt::Display for WorkerTask {
 }
 
 struct WorkerTaskData {
-    logger: FileLogger,
     progress: f64, // 0..1
-    warn_count: u64,
     pub abort_listeners: Vec<oneshot::Sender<()>>,
 }
 
@@ -834,7 +842,7 @@ impl WorkerTask {
         worker_id: Option<String>,
         auth_id: String,
         to_stdout: bool,
-    ) -> Result<Arc<Self>, Error> {
+    ) -> Result<(Arc<Self>, FileLogger), Error> {
         let setup = worker_task_setup()?;
 
         let upid = UPID::new(worker_type, worker_id, auth_id)?;
@@ -857,9 +865,7 @@ impl WorkerTask {
             upid: upid.clone(),
             abort_requested: AtomicBool::new(false),
             data: Mutex::new(WorkerTaskData {
-                logger,
                 progress: 0.0,
-                warn_count: 0,
                 abort_listeners: vec![],
             }),
         });
@@ -873,7 +879,7 @@ impl WorkerTask {
 
         setup.update_active_workers(Some(&upid))?;
 
-        Ok(worker)
+        Ok((worker, logger))
     }
 
     /// Spawn a new tokio task/future.
@@ -888,13 +894,20 @@ impl WorkerTask {
         F: Send + 'static + FnOnce(Arc<WorkerTask>) -> T,
         T: Send + 'static + Future<Output = Result<(), Error>>,
     {
-        let worker = WorkerTask::new(worker_type, worker_id, auth_id, to_stdout)?;
+        let (worker, logger) = WorkerTask::new(worker_type, worker_id, auth_id, to_stdout)?;
         let upid_str = worker.upid.to_string();
         let f = f(worker.clone());
-        tokio::spawn(async move {
-            let result = f.await;
-            worker.log_result(&result);
-        });
+
+        let logger = RefCell::new(logger);
+        let counter = RefCell::new(0);
+        tokio::spawn(LOGGER.scope(logger, async move {
+            WARN_COUNTER
+                .scope(counter, async move {
+                    let result = f.await;
+                    worker.log_result(&result);
+                })
+                .await;
+        }));
 
         Ok(upid_str)
     }
@@ -910,22 +923,27 @@ impl WorkerTask {
     where
         F: Send + UnwindSafe + 'static + FnOnce(Arc<WorkerTask>) -> Result<(), Error>,
     {
-        let worker = WorkerTask::new(worker_type, worker_id, auth_id, to_stdout)?;
+        let (worker, logger) = WorkerTask::new(worker_type, worker_id, auth_id, to_stdout)?;
         let upid_str = worker.upid.to_string();
 
         let _child = std::thread::Builder::new()
             .name(upid_str.clone())
             .spawn(move || {
-                let worker1 = worker.clone();
-                let result = match std::panic::catch_unwind(move || f(worker1)) {
-                    Ok(r) => r,
-                    Err(panic) => match panic.downcast::<&str>() {
-                        Ok(panic_msg) => Err(format_err!("worker panicked: {}", panic_msg)),
-                        Err(_) => Err(format_err!("worker panicked: unknown type.")),
-                    },
-                };
+                LOGGER.sync_scope(RefCell::new(logger), || {
+                    WARN_COUNTER.sync_scope(RefCell::new(0), || {
+                        let worker1 = worker.clone();
+
+                        let result = match std::panic::catch_unwind(move || f(worker1)) {
+                            Ok(r) => r,
+                            Err(panic) => match panic.downcast::<&str>() {
+                                Ok(panic_msg) => Err(format_err!("worker panicked: {}", panic_msg)),
+                                Err(_) => Err(format_err!("worker panicked: unknown type.")),
+                            },
+                        };
 
-                worker.log_result(&result);
+                        worker.log_result(&result);
+                    });
+                });
             });
 
         Ok(upid_str)
@@ -933,7 +951,11 @@ impl WorkerTask {
 
     /// create state from self and a result
     pub fn create_state(&self, result: &Result<(), Error>) -> TaskState {
-        let warn_count = self.data.lock().unwrap().warn_count;
+        let mut warn_count: u64 = 0;
+
+        let _ = WARN_COUNTER.try_with(|counter| {
+            warn_count = counter.borrow_mut().to_owned();
+        });
 
         let endtime = proxmox_time::epoch_i64();
 
@@ -964,15 +986,7 @@ impl WorkerTask {
 
     /// Log a message.
     pub fn log_message<S: AsRef<str>>(&self, msg: S) {
-        let mut data = self.data.lock().unwrap();
-        data.logger.log(msg);
-    }
-
-    /// Log a message as warning.
-    pub fn log_warning<S: AsRef<str>>(&self, msg: S) {
-        let mut data = self.data.lock().unwrap();
-        data.logger.log(format!("WARN: {}", msg.as_ref()));
-        data.warn_count += 1;
+        info!(tasklog = true, "{}", msg.as_ref());
     }
 
     /// Set progress indicator
@@ -1035,16 +1049,6 @@ impl WorkerTaskContext for WorkerTask {
     fn fail_on_shutdown(&self) -> Result<(), Error> {
         crate::fail_on_shutdown()
     }
-
-    fn log(&self, level: log::Level, message: &std::fmt::Arguments) {
-        match level {
-            log::Level::Error => self.log_warning(message.to_string()),
-            log::Level::Warn => self.log_warning(message.to_string()),
-            log::Level::Info => self.log_message(message.to_string()),
-            log::Level::Debug => self.log_message(format!("DEBUG: {}", message)),
-            log::Level::Trace => self.log_message(format!("TRACE: {}", message)),
-        }
-    }
 }
 
 /// Wait for a locally spanned worker task
diff --git a/proxmox-sys/src/worker_task_context.rs b/proxmox-sys/src/worker_task_context.rs
index 2c86857..743ae53 100644
--- a/proxmox-sys/src/worker_task_context.rs
+++ b/proxmox-sys/src/worker_task_context.rs
@@ -26,9 +26,6 @@ pub trait WorkerTaskContext: Send + Sync {
         }
         Ok(())
     }
-
-    /// Create a log message for this task.
-    fn log(&self, level: log::Level, message: &std::fmt::Arguments);
 }
 
 /// Convenience implementation:
@@ -48,48 +45,4 @@ impl<T: WorkerTaskContext + ?Sized> WorkerTaskContext for std::sync::Arc<T> {
     fn fail_on_shutdown(&self) -> Result<(), Error> {
         <T as WorkerTaskContext>::fail_on_shutdown(self)
     }
-
-    fn log(&self, level: log::Level, message: &std::fmt::Arguments) {
-        <T as WorkerTaskContext>::log(self, level, message)
-    }
-}
-
-/// Log an error to a [WorkerTaskContext]
-#[macro_export]
-macro_rules! task_error {
-    ($task:expr, $($fmt:tt)+) => {{
-        $crate::WorkerTaskContext::log(&*$task, log::Level::Error, &format_args!($($fmt)+))
-    }};
-}
-
-/// Log a warning to a [WorkerTaskContext]
-#[macro_export]
-macro_rules! task_warn {
-    ($task:expr, $($fmt:tt)+) => {{
-        $crate::WorkerTaskContext::log(&*$task, log::Level::Warn, &format_args!($($fmt)+))
-    }};
-}
-
-/// Log a message to a [WorkerTaskContext]
-#[macro_export]
-macro_rules! task_log {
-    ($task:expr, $($fmt:tt)+) => {{
-        $crate::WorkerTaskContext::log(&*$task, log::Level::Info, &format_args!($($fmt)+))
-    }};
-}
-
-/// Log a debug message to a [WorkerTaskContext]
-#[macro_export]
-macro_rules! task_debug {
-    ($task:expr, $($fmt:tt)+) => {{
-        $crate::WorkerTaskContext::log(&*$task, log::Level::Debug, &format_args!($($fmt)+))
-    }};
-}
-
-/// Log a trace message to a [WorkerTaskContext]
-#[macro_export]
-macro_rules! task_trace {
-    ($task:expr, $($fmt:tt)+) => {{
-        $crate::WorkerTaskContext::log(&*$task, log::Level::Trace, &format_args!($($fmt)+))
-    }};
 }
-- 
2.43.0





^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction
  2024-04-10 11:48 [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
                   ` (2 preceding siblings ...)
  2024-04-10 11:49 ` [pbs-devel] [PATCH proxmox v2 3/3] proxmox-log: added tracing infra Gabriel Goller
@ 2024-04-10 14:17 ` Gabriel Goller
  3 siblings, 0 replies; 5+ messages in thread
From: Gabriel Goller @ 2024-04-10 14:17 UTC (permalink / raw)
  To: Proxmox Backup Server development discussion

Forgot to update the debian/control files :)
Sent a v3!




^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2024-04-10 14:17 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-04-10 11:48 [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller
2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 1/3] removed task_log! macro and moved to tracing Gabriel Goller
2024-04-10 11:48 ` [pbs-devel] [PATCH proxmox-backup v2 2/3] removed task_log! macro and moved to tracing in api Gabriel Goller
2024-04-10 11:49 ` [pbs-devel] [PATCH proxmox v2 3/3] proxmox-log: added tracing infra Gabriel Goller
2024-04-10 14:17 ` [pbs-devel] [PATCH proxmox{-backup, } v2 0/3] proxmox-log introduction Gabriel Goller

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
Service provided by Proxmox Server Solutions GmbH | Privacy | Legal