From ccfcffcc1e1fbe89943d84a44675457b32d20efe Mon Sep 17 00:00:00 2001 From: Carl Johnsen Date: Tue, 28 Oct 2025 14:41:39 +0100 Subject: [PATCH] Added internal timers to keep track of maximum processing times of the restore processes --- .../Operation/Restore/VolumeDecompressor.cs | 17 +++++++++++++++++ .../Main/Operation/Restore/VolumeDecryptor.cs | 19 +++++++++++++++++++ .../Operation/Restore/VolumeDownloader.cs | 17 +++++++++++++++++ 3 files changed, 53 insertions(+) diff --git a/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs b/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs index 03da907b7..63be8da11 100644 --- a/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs +++ b/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs @@ -22,6 +22,7 @@ using System; using System.Buffers; using System.Diagnostics; +using System.Threading; using System.Threading.Tasks; using CoCoL; using Duplicati.Library.Utility; @@ -41,6 +42,15 @@ namespace Duplicati.Library.Main.Operation.Restore /// private static readonly string LOGTAG = Logging.Log.LogTagFromType(); + /// + /// Id of the next decompressor. Used to give each decompressor a unique index. + /// + public static int IdCounter = -1; + /// + /// Maximum processing times for each active decompressor. + /// + public static int[] MaxProcessingTimes = []; + /// /// Runs the volume decompressor process. /// @@ -64,6 +74,9 @@ namespace Duplicati.Library.Main.Operation.Restore Stopwatch? sw_decompress_read = options.InternalProfiling ? new() : null; Stopwatch? sw_verify = options.InternalProfiling ? new() : null; + Stopwatch sw_processing = new(); + int id = Interlocked.Increment(ref IdCounter); + try { using var block_hasher = HashFactory.CreateHasher(options.BlockHashAlgorithm); @@ -77,6 +90,7 @@ namespace Duplicati.Library.Main.Operation.Restore sw_read?.Stop(); Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Decompressing block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); + sw_processing.Restart(); sw_decompress_alloc?.Start(); var data = ArrayPool.Shared.Rent(options.Blocksize); sw_decompress_alloc?.Stop(); @@ -105,6 +119,9 @@ namespace Duplicati.Library.Main.Operation.Restore } sw_verify?.Stop(); Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Verified block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); + sw_processing.Stop(); + // This is the only writing process to that int, so an update is safe. + MaxProcessingTimes[id] = Math.Max(MaxProcessingTimes[id], (int)sw_processing.ElapsedMilliseconds); sw_write?.Start(); // Send the block to the `BlockManager` process. diff --git a/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs b/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs index f6351fe00..9e5a50348 100644 --- a/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs +++ b/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs @@ -22,6 +22,7 @@ using System; using System.Diagnostics; using System.Linq; +using System.Threading; using System.Threading.Tasks; using CoCoL; using Duplicati.Library.Main.Volumes; @@ -41,6 +42,15 @@ namespace Duplicati.Library.Main.Operation.Restore /// private static readonly string LOGTAG = Logging.Log.LogTagFromType(); + /// + /// Id of the next decryptor. Used to give each decryptor a unique index. + /// + public static int IdCounter = -1; + /// + /// Maximum processing times for each active decryptor. + /// + public static int[] MaxProcessingTimes = []; + /// /// Runs the volume decryptor process. /// @@ -62,6 +72,10 @@ namespace Duplicati.Library.Main.Operation.Restore Stopwatch? sw_decrypt = options.InternalProfiling ? new() : null; Stopwatch? sw_bvr = options.InternalProfiling ? new() : null; Stopwatch? sw_vw = options.InternalProfiling ? new() : null; + + Stopwatch sw_processing = new(); + int id = Interlocked.Increment(ref IdCounter); + try { while (true) @@ -72,6 +86,8 @@ namespace Duplicati.Library.Main.Operation.Restore sw_read?.Stop(); Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, "Decrypting volume {0} (ID: {1})", volume_name, volume_id); + sw_processing.Restart(); + // Decrypt the volume. sw_decrypt?.Start(); var tmpfile = backend.DecryptFile(volume, volume_name, options); sw_decrypt?.Stop(); @@ -85,6 +101,9 @@ namespace Duplicati.Library.Main.Operation.Restore var volume_wrapper = new VolumeWrapper(tmpfile, bvr); sw_vw?.Stop(); Logging.Log.WriteExplicitMessage(LOGTAG, "BlockVolumeReader", null, "Created BlockVolumeReader for volume {0} (ID: {1})", volume_name, volume_id); + sw_processing.Stop(); + // This is the only writing process to that int, so an update is safe. + MaxProcessingTimes[id] = Math.Max(MaxProcessingTimes[id], (int)sw_processing.ElapsedMilliseconds); sw_write?.Start(); // Pass the decrypted volume to the `VolumeDecompressor` process. diff --git a/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs b/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs index 2b0889707..b3b930d79 100644 --- a/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs +++ b/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs @@ -43,6 +43,16 @@ namespace Duplicati.Library.Main.Operation.Restore /// private static readonly string LOGTAG = Logging.Log.LogTagFromType(); + + /// + /// Id of the next downloader. Used to give each downloader a unique index. + /// + public static int IdCounter = -1; + /// + /// Maximum processing times for each active downloader. + /// + public static int[] MaxProcessingTimes = []; + /// /// Runs the volume downloader process. /// @@ -65,6 +75,9 @@ namespace Duplicati.Library.Main.Operation.Restore Stopwatch? sw_write = options.InternalProfiling ? new() : null; Stopwatch? sw_wait = options.InternalProfiling ? new() : null; + Stopwatch sw_processing = new(); + var id = Interlocked.Increment(ref IdCounter); + try { while (true) @@ -77,6 +90,7 @@ namespace Duplicati.Library.Main.Operation.Restore // Trigger the download. sw_wait?.Start(); + sw_processing.Restart(); TempFile f; var (volume_name, size, hash) = await db .GetVolumeInfo(volume_id, results.TaskControl.ProgressToken) @@ -93,6 +107,9 @@ namespace Duplicati.Library.Main.Operation.Restore throw; } + sw_processing.Stop(); + // This is the only writing process to that int, so an update is safe. + MaxProcessingTimes[id] = Math.Max(MaxProcessingTimes[id], (int)sw_processing.ElapsedMilliseconds); sw_wait?.Stop(); Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, "Downloaded volume {0} (ID: {1})", volume_name, volume_id);