From b475eeb387bb574d08c4af079a1b993b53ee2bb2 Mon Sep 17 00:00:00 2001 From: Carl Johnsen Date: Tue, 30 Sep 2025 21:38:04 +0200 Subject: [PATCH] Moved formatting of the explicit log messages to occur later to alleviate having to do that when that log level is disabled, which should decrease wasted processing. --- .../Main/Operation/Restore/BlockManager.cs | 18 +++++++++--------- .../Main/Operation/Restore/FileProcessor.cs | 2 +- .../Operation/Restore/VolumeDecompressor.cs | 12 ++++++------ .../Main/Operation/Restore/VolumeDecryptor.cs | 8 ++++---- .../Main/Operation/Restore/VolumeDownloader.cs | 6 +++--- 5 files changed, 23 insertions(+), 23 deletions(-) diff --git a/Duplicati/Library/Main/Operation/Restore/BlockManager.cs b/Duplicati/Library/Main/Operation/Restore/BlockManager.cs index 76ee8474b..28d6b4762 100644 --- a/Duplicati/Library/Main/Operation/Restore/BlockManager.cs +++ b/Duplicati/Library/Main/Operation/Restore/BlockManager.cs @@ -144,7 +144,7 @@ namespace Duplicati.Library.Main.Operation.Restore m_entry_options.RegisterPostEvictionCallback((key, value, reason, state) => { Interlocked.Decrement(ref m_block_cache_count); - Logging.Log.WriteExplicitMessage(LOGTAG, "CacheEvictCallback", $"Evicted block {key} from cache"); + Logging.Log.WriteExplicitMessage(LOGTAG, "CacheEvictCallback", "Evicted block {0} from cache", key); }); m_readers = readers; sw_cacheevict = options.InternalProfiling ? new() : null; @@ -240,12 +240,12 @@ namespace Duplicati.Library.Main.Operation.Restore if (error_block_id != -1) { - Logging.Log.WriteWarningMessage(LOGTAG, "BlockCountError", null, $"Block {blockRequest.BlockID} has a count below 0"); + Logging.Log.WriteWarningMessage(LOGTAG, "BlockCountError", null, "Block {0} has a count below 0", blockRequest.BlockID); } if (error_volume_id != -1) { - Logging.Log.WriteWarningMessage(LOGTAG, "VolumeCountError", null, $"Volume {blockRequest.VolumeID} has a count below 0"); + Logging.Log.WriteWarningMessage(LOGTAG, "VolumeCountError", null, "Volume {0} has a count below 0", blockRequest.VolumeID); } } @@ -454,7 +454,7 @@ namespace Duplicati.Library.Main.Operation.Restore var (block_request, data) = await self.Input.ReadAsync().ConfigureAwait(false); sw_read?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "VolumeConsumer", null, $"Received block request: {block_request.RequestType} for block {block_request.BlockID} from volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "VolumeConsumer", null, "Received block request: {0} for block {1} from volume {2}", block_request.RequestType, block_request.BlockID, block_request.VolumeID); sw_ack?.Start(); block_request.RequestType = BlockRequestType.DecompressAck; while (true) @@ -466,7 +466,7 @@ namespace Duplicati.Library.Main.Operation.Restore } sw_ack?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "VolumeConsumer", null, $"Received data for block {block_request.BlockID} from volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "VolumeConsumer", null, "Received data for block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); sw_set?.Start(); cache.Set(block_request.BlockID, data); sw_set?.Stop(); @@ -509,19 +509,19 @@ namespace Duplicati.Library.Main.Operation.Restore sw_req?.Start(); var block_request = await req.ReadAsync().ConfigureAwait(false); sw_req?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, $"Received block request: {block_request.RequestType}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, "Received block request: {0}", block_request.RequestType); switch (block_request.RequestType) { case BlockRequestType.Download: sw_get?.Start(); var datatask = cache.Get(block_request); sw_get?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, $"Retrieved data for block {block_request.BlockID} and volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, "Retrieved data for block {0} and volume {1}", block_request.BlockID, block_request.VolumeID); sw_resp?.Start(); await res.WriteAsync(datatask).ConfigureAwait(false); sw_resp?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, $"Passed data for block {block_request.BlockID} and volume {block_request.VolumeID} to FileProcessor"); + Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, "Passed data for block {0} and volume {1} to FileProcessor", block_request.BlockID, block_request.VolumeID); break; case BlockRequestType.CacheEvict: sw_cache?.Start(); @@ -529,7 +529,7 @@ namespace Duplicati.Library.Main.Operation.Restore await cache.CheckCounts(block_request).ConfigureAwait(false); sw_cache?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, $"Decremented counts for block {block_request.BlockID} and volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "BlockHandler", null, "Decremented counts for block {0} and volume {1}", block_request.BlockID, block_request.VolumeID); break; case BlockRequestType.DecompressAck: default: diff --git a/Duplicati/Library/Main/Operation/Restore/FileProcessor.cs b/Duplicati/Library/Main/Operation/Restore/FileProcessor.cs index 19be4bd03..66ba57cf6 100644 --- a/Duplicati/Library/Main/Operation/Restore/FileProcessor.cs +++ b/Duplicati/Library/Main/Operation/Restore/FileProcessor.cs @@ -115,7 +115,7 @@ namespace Duplicati.Library.Main.Operation.Restore var file = await self.Input.ReadAsync().ConfigureAwait(false); sw_file?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "FileRestored", null, $"{my_id} Restoring file {file.TargetPath}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "FileRestored", null, "{0} Restoring file {1}", my_id, file.TargetPath); if (file.BlocksetID == LocalDatabase.FOLDER_BLOCKSET_ID && !options.SkipMetadata) { diff --git a/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs b/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs index 2c0ffcebd..0c31e7717 100644 --- a/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs +++ b/Duplicati/Library/Main/Operation/Restore/VolumeDecompressor.cs @@ -73,12 +73,12 @@ namespace Duplicati.Library.Main.Operation.Restore // Get the block request and volume from the `VolumeDecryptor` process. var (block_request, volume_reader) = await self.Input.ReadAsync().ConfigureAwait(false); sw_read?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", $"Decompressing block {block_request.BlockID} from volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Decompressing block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); sw_decompress_alloc?.Start(); var data = ArrayPool.Shared.Rent(options.Blocksize); sw_decompress_alloc?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", $"Allocated buffer for block {block_request.BlockID} from volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Allocated buffer for block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); sw_decompress_locking?.Start(); lock (volume_reader) // The BlockVolumeReader is not thread-safe @@ -88,22 +88,22 @@ namespace Duplicati.Library.Main.Operation.Restore volume_reader.ReadBlock(block_request.BlockHash, data); sw_decompress_read?.Stop(); } - Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", $"Decompressed block {block_request.BlockID} from volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Decompressed block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); sw_verify?.Start(); var hash = Convert.ToBase64String(block_hasher.ComputeHash(data, 0, (int)block_request.BlockSize)); if (hash != block_request.BlockHash) { - Logging.Log.WriteErrorMessage(LOGTAG, "InvalidBlock", null, $"Invalid block detected for block {block_request.BlockID} in volume {block_request.VolumeID}, expected hash: {block_request.BlockHash}, actual hash: {hash}"); + Logging.Log.WriteErrorMessage(LOGTAG, "InvalidBlock", null, "Invalid block detected for block {0} in volume {1}, expected hash: {2}, actual hash: {3}", block_request.BlockID, block_request.VolumeID, block_request.BlockHash, hash); } sw_verify?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", $"Verified block {block_request.BlockID} from volume {block_request.VolumeID}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Verified block {0} from volume {1}", block_request.BlockID, block_request.VolumeID); sw_write?.Start(); // Send the block to the `BlockManager` process. await self.Output.WriteAsync((block_request, data)).ConfigureAwait(false); sw_write?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", $"Sent block {block_request.BlockID} from volume {block_request.VolumeID} to BlockManager"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecompressBlock", "Sent block {0} from volume {1} to BlockManager", block_request.BlockID, block_request.VolumeID); } } catch (RetiredException) diff --git a/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs b/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs index 5d8f2c10e..99d1d3c2a 100644 --- a/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs +++ b/Duplicati/Library/Main/Operation/Restore/VolumeDecryptor.cs @@ -69,23 +69,23 @@ namespace Duplicati.Library.Main.Operation.Restore sw_read?.Start(); var (volume_id, volume_name, volume) = await self.Input.ReadAsync().ConfigureAwait(false); sw_read?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, $"Decrypting volume {volume_name} (ID: {volume_id})"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, "Decrypting volume {0} (ID: {1})", volume_name, volume_id); sw_decrypt?.Start(); var tmpfile = backend.DecryptFile(volume, volume_name, options); sw_decrypt?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, $"Decrypted volume {volume_name} (ID: {volume_id})"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, "Decrypted volume {0} (ID: {1})", volume_name, volume_id); sw_bvr?.Start(); var bvr = new BlockVolumeReader(options.CompressionModule, tmpfile, options); sw_bvr?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "BlockVolumeReader", null, $"Created BlockVolumeReader for volume {volume_name} (ID: {volume_id})"); + Logging.Log.WriteExplicitMessage(LOGTAG, "BlockVolumeReader", null, "Created BlockVolumeReader for volume {0} (ID: {1})", volume_name, volume_id); sw_write?.Start(); // Pass the decrypted volume to the `VolumeDecompressor` process. await self.Output.WriteAsync((volume_id, tmpfile, bvr)).ConfigureAwait(false); sw_write?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, $"Passed decrypted volume {volume_name} (ID: {volume_id}) to next stage"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DecryptVolume", null, "Passed decrypted volume {0} (ID: {1}) to next stage", volume_name, volume_id); } } catch (RetiredException) diff --git a/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs b/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs index 27c835513..2b0889707 100644 --- a/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs +++ b/Duplicati/Library/Main/Operation/Restore/VolumeDownloader.cs @@ -73,7 +73,7 @@ namespace Duplicati.Library.Main.Operation.Restore sw_read?.Start(); var volume_id = await self.Input.ReadAsync().ConfigureAwait(false); sw_read?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, $"Downloaded volume {volume_id}"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, "Downloaded volume {0}", volume_id); // Trigger the download. sw_wait?.Start(); @@ -94,13 +94,13 @@ namespace Duplicati.Library.Main.Operation.Restore throw; } sw_wait?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, $"Downloaded volume {volume_name} (ID: {volume_id})"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, "Downloaded volume {0} (ID: {1})", volume_name, volume_id); // Pass the download handle (which may or may not have downloaded already) to the `VolumeDecryptor` process. sw_write?.Start(); await self.Output.WriteAsync((volume_id, volume_name, f)).ConfigureAwait(false); sw_write?.Stop(); - Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, $"Passed volume {volume_name} (ID: {volume_id}) to next stage"); + Logging.Log.WriteExplicitMessage(LOGTAG, "DownloadVolume", null, "Passed volume {0} (ID: {1}) to next stage", volume_name, volume_id); } } catch (RetiredException)