From 4244e71feecfa2ca449e520cc8760188131bfb6d Mon Sep 17 00:00:00 2001 From: Kenneth Skovhede Date: Wed, 6 May 2026 10:52:58 +0200 Subject: [PATCH] Improve SQL logging This PR improves SQL logging by capturing many places where the calls would previously just hit the database and not produce any logging output. --- .../Library/Main/Database/ChangeStatistics.cs | 2 +- .../Main/Database/LocalBackupDatabase.cs | 83 +++++++------ .../Main/Database/LocalBugReportDatabase.cs | 2 +- .../Library/Main/Database/LocalDatabase.cs | 76 ++++++------ .../Main/Database/LocalDeleteDatabase.cs | 16 +-- .../Database/LocalListBrokenFilesDatabase.cs | 6 +- .../Main/Database/LocalListChangesDatabase.cs | 55 +++++---- .../Main/Database/LocalListDatabase.cs | 13 +- .../Main/Database/LocalLockDatabase.cs | 2 +- .../Main/Database/LocalPurgeDatabase.cs | 39 +++--- .../Main/Database/LocalRecreateDatabase.cs | 39 +++--- .../Main/Database/LocalRepairDatabase.cs | 48 ++++---- .../Main/Database/LocalRestoreDatabase.cs | 115 ++++++++++-------- .../Main/Database/LocalTestDatabase.cs | 18 +-- .../Main/Operation/ListChangesHandler.cs | 6 +- 15 files changed, 278 insertions(+), 242 deletions(-) diff --git a/Duplicati/Library/Main/Database/ChangeStatistics.cs b/Duplicati/Library/Main/Database/ChangeStatistics.cs index 788c0b00f..cdfd3de73 100644 --- a/Duplicati/Library/Main/Database/ChangeStatistics.cs +++ b/Duplicati/Library/Main/Database/ChangeStatistics.cs @@ -80,7 +80,7 @@ public static class ChangeStatistics ") .SetParameterValue("@LastFilesetId", previousFilesetId) .SetParameterValue("@CurrentFilesetId", currentFilesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Index for fast comparison diff --git a/Duplicati/Library/Main/Database/LocalBackupDatabase.cs b/Duplicati/Library/Main/Database/LocalBackupDatabase.cs index 5331a501e..077d52c80 100644 --- a/Duplicati/Library/Main/Database/LocalBackupDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalBackupDatabase.cs @@ -434,7 +434,7 @@ namespace Duplicati.Library.Main.Database RemoteVolumeState.Deleted, RemoteVolumeState.Deleting ]) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); var deletedBlocks = await cmd.ExecuteScalarInt64Async(@$" @@ -1584,7 +1584,7 @@ namespace Duplicati.Library.Main.Database ") .SetParameterValue("@PreviousFilesetId", lastFilesetId) .SetParameterValue("@CurrentFilesetId", fileSetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // now we need to remove, from the above, any entries that were enumerated by the @@ -1614,16 +1614,17 @@ namespace Duplicati.Library.Main.Database ON ""f"".""BlocksetID"" = ""bs"".""ID""; "); - await foreach (var row in cmd.ExecuteReaderEnumerableAsync(token).ConfigureAwait(false)) - { - var path = row.ConvertValueToString(0) ?? throw new Exception("Unexpected null value for path"); - var size = row.ConvertValueToInt64(3); + using (new Logging.Timer(LOGTAG, "DeletePreviousFiles", $"Deleting files not included in the current backup")) + await foreach (var row in cmd.ExecuteReaderEnumerableAsync(token).ConfigureAwait(false)) + { + var path = row.ConvertValueToString(0) ?? throw new Exception("Unexpected null value for path"); + var size = row.ConvertValueToInt64(3); - if (exclusionPredicate(path, size)) - await cmdDelete.SetParameterValue("@FileId", row.ConvertValueToInt64(1)) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } + if (exclusionPredicate(path, size)) + await cmdDelete.SetParameterValue("@FileId", row.ConvertValueToInt64(1)) + .ExecuteNonQueryAsync(token) // Not logging because we log the full operation + .ConfigureAwait(false); + } // now copy the temporary table into the FileSetEntry table await cmd.SetCommandAndParameters($@" @@ -1639,7 +1640,7 @@ namespace Duplicati.Library.Main.Database FROM ""{tempFileSetTable}"" ") .SetParameterValue("@FilesetId", fileSetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await m_rtr.CommitAsync(token).ConfigureAwait(false); @@ -1741,7 +1742,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Hash", blockkey) .SetParameterValue("@Size", size) .SetParameterValue("@PreviousVolumeId", sourcevolumeid) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -1870,10 +1871,11 @@ namespace Duplicati.Library.Main.Database /// Thrown if unable to add change journal entry. public async Task CreateChangeJournalData(IEnumerable data, CancellationToken token) { - foreach (var entry in data) - { - await using var cmd = m_connection.CreateCommand(m_rtr); - var c = await cmd.SetCommandAndParameters(@" + using (new Logging.Timer(LOGTAG, "CreateChangeJournalData", "Inserting USN entries")) + foreach (var entry in data) + { + await using var cmd = m_connection.CreateCommand(m_rtr); + var c = await cmd.SetCommandAndParameters(@" INSERT INTO ""ChangeJournalData"" ( ""FilesetID"", ""VolumeName"", @@ -1889,17 +1891,17 @@ namespace Duplicati.Library.Main.Database @ConfigHash ); ") - .SetParameterValue("@FilesetId", m_filesetId) - .SetParameterValue("@VolumeName", entry.Volume) - .SetParameterValue("@JournalId", entry.JournalId) - .SetParameterValue("@NextUsn", entry.NextUsn) - .SetParameterValue("@ConfigHash", entry.ConfigHash) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + .SetParameterValue("@FilesetId", m_filesetId) + .SetParameterValue("@VolumeName", entry.Volume) + .SetParameterValue("@JournalId", entry.JournalId) + .SetParameterValue("@NextUsn", entry.NextUsn) + .SetParameterValue("@ConfigHash", entry.ConfigHash) + .ExecuteNonQueryAsync(token) // Not logging, as we log the whole operation + .ConfigureAwait(false); - if (c != 1) - throw new Exception("Unable to add change journal entry"); - } + if (c != 1) + throw new Exception("Unable to add change journal entry"); + } await m_rtr.CommitAsync(token: token).ConfigureAwait(false); } @@ -1913,10 +1915,11 @@ namespace Duplicati.Library.Main.Database /// A task that completes when the data is added. public async Task UpdateChangeJournalData(IEnumerable data, long fileSetId, CancellationToken token) { - foreach (var entry in data) - { - await using var cmd = m_connection.CreateCommand(); - await cmd.SetCommandAndParameters(@" + using (new Logging.Timer(LOGTAG, "UpdateChangeJournalData", "Updating USN entries")) + foreach (var entry in data) + { + await using var cmd = m_connection.CreateCommand(); + await cmd.SetCommandAndParameters(@" UPDATE ""ChangeJournalData"" SET ""NextUSN"" = @NextUsn WHERE @@ -1924,14 +1927,14 @@ namespace Duplicati.Library.Main.Database AND ""VolumeName"" = @VolumeName AND ""JournalID"" = @JournalId; ") - .SetTransaction(m_rtr) - .SetParameterValue("@NextUsn", entry.NextUsn) - .SetParameterValue("@FilesetId", fileSetId) - .SetParameterValue("@VolumeName", entry.Volume) - .SetParameterValue("@JournalId", entry.JournalId) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } + .SetTransaction(m_rtr) + .SetParameterValue("@NextUsn", entry.NextUsn) + .SetParameterValue("@FilesetId", fileSetId) + .SetParameterValue("@VolumeName", entry.Volume) + .SetParameterValue("@JournalId", entry.JournalId) + .ExecuteNonQueryAsync(token) // Not logging, as we log the whole operation + .ConfigureAwait(false); + } await m_rtr.CommitAsync(token: token).ConfigureAwait(false); } @@ -1989,7 +1992,7 @@ namespace Duplicati.Library.Main.Database var deletedCount = await cmd .SetCommandAndParameters(sql) .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (deletedCount > 0) diff --git a/Duplicati/Library/Main/Database/LocalBugReportDatabase.cs b/Duplicati/Library/Main/Database/LocalBugReportDatabase.cs index 9cae4e015..78f15f600 100644 --- a/Duplicati/Library/Main/Database/LocalBugReportDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalBugReportDatabase.cs @@ -107,7 +107,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@StartPath", !OperatingSystem.IsWindows() ? "/" : "X:\\") .SetParameterValue("@DirSep", Util.DirectorySeparatorString) .SetParameterValue("@FileExt", ".bin") - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); /*long id = 1; diff --git a/Duplicati/Library/Main/Database/LocalDatabase.cs b/Duplicati/Library/Main/Database/LocalDatabase.cs index 99f636616..1a5ed1116 100644 --- a/Duplicati/Library/Main/Database/LocalDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalDatabase.cs @@ -653,7 +653,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) .SetParameterValue("@Name", name) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -673,7 +673,7 @@ namespace Duplicati.Library.Main.Database c = await cmd.SetTransaction(m_rtr) .SetParameterValue("@DeleteGraceTime", Library.Utility.Utility.NormalizeDateTimeToEpochSeconds(DateTime.UtcNow + deleteGraceTime)) .SetParameterValue("@Name", name) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -692,7 +692,7 @@ namespace Duplicati.Library.Main.Database c = await cmd.SetTransaction(m_rtr) .SetParameterValue("@ArchiveTime", setArchived.Value ? Library.Utility.Utility.NormalizeDateTimeToEpochSeconds(DateTime.UtcNow) : 0) .SetParameterValue("@Name", name) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -936,7 +936,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Operation", operation) .SetParameterValue("@Path", path) .SetParameterValue("@Data", data) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -957,7 +957,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Type", type) .SetParameterValue("@Message", message) .SetParameterValue("@Exception", exception?.ToString()) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -983,7 +983,7 @@ namespace Duplicati.Library.Main.Database var c = await cmd.SetTransaction(m_rtr) .SetParameterValue("@Name", name) .SetParameterValue("@State", state.ToString()) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -1053,7 +1053,7 @@ namespace Duplicati.Library.Main.Database await deletecmd.ExpandInClauseParameterMssqliteAsync("@VolumeNames", tmptable, token) .ConfigureAwait(false); await deletecmd - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); var volIdsSubQuery = $@" @@ -1299,7 +1299,7 @@ namespace Duplicati.Library.Main.Database RemoteVolumeState.Verified.ToString(), RemoteVolumeState.Temporary.ToString() ]) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await deletecmd.ExecuteNonQueryAsync($@" @@ -1340,14 +1340,14 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_rtr) .SetParameterValue("@Now", Library.Utility.Utility.NormalizeDateTimeToEpochSeconds(DateTime.UtcNow)) .SetParameterValue("@State", RemoteVolumeState.Deleted.ToString()); - foreach (var name in names) - { - await m_removeremotevolumeCommand - .SetTransaction(m_rtr) - .SetParameterValue("@Name", name) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } + + using (new Logging.Timer(LOGTAG, "RemoveRemoteVolumes", "Removing remote volumes")) + foreach (var name in names) + await m_removeremotevolumeCommand + .SetTransaction(m_rtr) + .SetParameterValue("@Name", name) + .ExecuteNonQueryAsync(token) // Not logging because we log the whole operation + .ConfigureAwait(false); // Validate before commiting changes var nonAttachedFiles = await deletecmd.ExecuteScalarInt64Async(@" @@ -1695,9 +1695,10 @@ namespace Duplicati.Library.Main.Database ", token) .ConfigureAwait(false); - foreach (var kp in options) - { - await cmd.SetCommandAndParameters(@" + using (new Logging.Timer(LOGTAG, "SetDbOptions", "Setting database options")) + foreach (var kp in options) + { + await cmd.SetCommandAndParameters(@" INSERT INTO ""Configuration"" ( ""Key"", ""Value"" @@ -1707,11 +1708,11 @@ namespace Duplicati.Library.Main.Database @Value ) ") - .SetParameterValue("@Key", kp.Key) - .SetParameterValue("@Value", kp.Value) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } + .SetParameterValue("@Key", kp.Key) + .SetParameterValue("@Value", kp.Value) + .ExecuteNonQueryAsync(token) // Not logging, as we log the whole operation + .ConfigureAwait(false); + } } /// @@ -2598,7 +2599,7 @@ namespace Duplicati.Library.Main.Database var c = await cmd.SetTransaction(m_rtr) .SetParameterValue("@VolumeId", volumeid) .SetParameterValue("@FilesetId", filesetid) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -2635,7 +2636,7 @@ namespace Duplicati.Library.Main.Database await cmd.SetTransaction(m_rtr) .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -2698,7 +2699,7 @@ namespace Duplicati.Library.Main.Database .ConfigureAwait(false); await cmd.SetTransaction(db.Transaction) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); return ftt; @@ -2715,7 +2716,7 @@ namespace Duplicati.Library.Main.Database .ConfigureAwait(false); await cmd.SetTransaction(db.Transaction) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); cmd.SetCommandAndParameters($@" @@ -2730,6 +2731,7 @@ namespace Duplicati.Library.Main.Database .ConfigureAwait(false); c2.SetTransaction(db.Transaction); + using (new Logging.Timer(LOGTAG, "CreateFilteredFilenameTable", "Filtering paths")) await using (var rd = await c2.ExecuteReaderAsync(token).ConfigureAwait(false)) while (await rd.ReadAsync(token).ConfigureAwait(false)) { @@ -2738,7 +2740,7 @@ namespace Duplicati.Library.Main.Database { await cmd .SetParameterValue("@Path", p) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(token) // Not logging as we log the whole operation .ConfigureAwait(false); } } @@ -2833,7 +2835,7 @@ namespace Duplicati.Library.Main.Database var c = await cmd.SetTransaction(m_rtr) .SetParameterValue("@Newname", newname) .SetParameterValue("@Oldname", oldname) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -2848,7 +2850,7 @@ namespace Duplicati.Library.Main.Database WHERE ""Name"" = @Name ") .SetParameterValue("@Name", newname) - .ExecuteScalarAsync(token) + .ExecuteScalarAsync(true, token) .ConfigureAwait(false) )?.ToString() ?? "", true @@ -2926,7 +2928,7 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_rtr) .SetParameterValue("@IndexVolumeId", indexVolumeID) .SetParameterValue("@BlockVolumeId", blockVolumeID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -3045,7 +3047,7 @@ namespace Duplicati.Library.Main.Database await cmd.SetTransaction(m_rtr) .SetParameterValue("@FilesetId", fileSetId) .SetParameterValue("@IsFullBackup", isFullBackup ? BackupType.FULL_BACKUP : BackupType.PARTIAL_BACKUP) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -3065,7 +3067,7 @@ namespace Duplicati.Library.Main.Database await cmd.SetTransaction(m_rtr) .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -3197,7 +3199,7 @@ namespace Duplicati.Library.Main.Database WHERE ""Timestamp"" < @Timestamp ") .SetParameterValue("@Timestamp", t) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await cmd.SetCommandAndParameters(@" @@ -3205,7 +3207,7 @@ namespace Duplicati.Library.Main.Database WHERE ""Timestamp"" < @Timestamp ") .SetParameterValue("@Timestamp", t) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await m_rtr.CommitAsync(token: token).ConfigureAwait(false); @@ -3221,7 +3223,7 @@ namespace Duplicati.Library.Main.Database await m_removedeletedremotevolumeCommand .SetTransaction(m_rtr) .SetParameterValue("@Now", Library.Utility.Utility.NormalizeDateTimeToEpochSeconds(threshold)) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await m_rtr.CommitAsync(token: token).ConfigureAwait(false); diff --git a/Duplicati/Library/Main/Database/LocalDeleteDatabase.cs b/Duplicati/Library/Main/Database/LocalDeleteDatabase.cs index 7994d5717..d4067be18 100644 --- a/Duplicati/Library/Main/Database/LocalDeleteDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalDeleteDatabase.cs @@ -134,7 +134,7 @@ namespace Duplicati.Library.Main.Database .ExpandInClauseParameterMssqliteAsync("@Timestamps", tempTable, token) .ConfigureAwait(false) ) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (deleted != toDelete.Length) @@ -267,7 +267,7 @@ namespace Duplicati.Library.Main.Database RemoteVolumeState.Temporary.ToString(), RemoteVolumeState.Deleting.ToString() ]) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (deleted != updated) @@ -540,7 +540,7 @@ namespace Duplicati.Library.Main.Database RemoteVolumeState.Uploaded.ToString(), RemoteVolumeState.Verified.ToString() ]) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); cmd.SetCommandAndParameters($@" @@ -901,7 +901,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@VolumeId", volumeID) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -931,7 +931,7 @@ namespace Duplicati.Library.Main.Database WHERE ""VolumeID"" = @VolumeId ") .SetParameterValue("@VolumeId", deletedVolume.ID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await using (var tempTable = await TemporaryDbValueList.CreateAsync(this, volumeIdsToBeRemoved, token).ConfigureAwait(false)) @@ -953,7 +953,7 @@ namespace Duplicati.Library.Main.Database .ExpandInClauseParameterMssqliteAsync("@VolumeIds", tempTable, token) .ConfigureAwait(false) ) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); var targetCount = await cmd.ExecuteScalarInt64Async($@" @@ -984,7 +984,7 @@ namespace Duplicati.Library.Main.Database AND ""Block"".""ID"" IN (SELECT ""BlockID"" FROM ""{replacementBlocks}"") ") .SetParameterValue("@VolumeId", deletedVolume.ID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); var deleteCount = await cmd.ExecuteNonQueryAsync(@$" @@ -1017,7 +1017,7 @@ namespace Duplicati.Library.Main.Database WHERE ""VolumeID"" = @VolumeId ") .SetParameterValue("@VolumeId", deletedVolume.ID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } finally diff --git a/Duplicati/Library/Main/Database/LocalListBrokenFilesDatabase.cs b/Duplicati/Library/Main/Database/LocalListBrokenFilesDatabase.cs index 5b09584ea..1e2c70f51 100644 --- a/Duplicati/Library/Main/Database/LocalListBrokenFilesDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalListBrokenFilesDatabase.cs @@ -300,7 +300,7 @@ namespace Duplicati.Library.Main.Database .SetCommandAndParameters(INSERT_BROKEN_IDS(tablename, IDfieldname)) .SetParameterValue("@FilesetId", filesetid); - await cmd.ExecuteNonQueryAsync(token) + await cmd.ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -339,7 +339,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@EmptyBlocksetID", emptyBlocksetId) .SetParameterValue("@FilesetID", filesetId); - return await cmd.ExecuteNonQueryAsync(token).ConfigureAwait(false); + return await cmd.ExecuteNonQueryAsync(true, token).ConfigureAwait(false); } /// @@ -375,7 +375,7 @@ namespace Duplicati.Library.Main.Database .ExpandInClauseParameterMssqliteAsync("@Names", tmptable, token) .ConfigureAwait(false) ) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); var volIdsSubQuery = $@" diff --git a/Duplicati/Library/Main/Database/LocalListChangesDatabase.cs b/Duplicati/Library/Main/Database/LocalListChangesDatabase.cs index 573dd79ac..57320b983 100644 --- a/Duplicati/Library/Main/Database/LocalListChangesDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalListChangesDatabase.cs @@ -36,6 +36,10 @@ namespace Duplicati.Library.Main.Database /// internal class LocalListChangesDatabase : LocalDatabase { + /// + /// The log tag for this class. + /// + private static readonly string LOGTAG = Logging.Log.LogTagFromType(); /// /// Creates a new instance of the class. @@ -70,9 +74,10 @@ namespace Duplicati.Library.Main.Database /// The size of the file or folder. /// The type of the element (file, folder, symlink). /// If true, adds to the current table; otherwise, adds to the previous table. + /// If true, logs the SQL query. /// A cancellation token to cancel the operation. /// A task that completes when the element is added. - Task AddElement(string path, string filehash, string metahash, long size, Interface.ListChangesElementType type, bool asNew, CancellationToken token); + Task AddElement(string path, string filehash, string metahash, long size, Interface.ListChangesElementType type, bool asNew, bool logQuery, CancellationToken token); /// /// Adds elements from the database to the temporary storage. @@ -419,7 +424,7 @@ namespace Duplicati.Library.Main.Database WHERE ""A"".""FilesetID"" = @FilesetId ") .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } else if (Library.Utility.Utility.IsFSCaseSensitive && filter is FilterExpression expression && expression.Type == Duplicati.Library.Utility.FilterType.Simple) @@ -443,11 +448,12 @@ namespace Duplicati.Library.Main.Database .PrepareAsync(token) .ConfigureAwait(false); - foreach (var s in p) - await cmd - .SetParameterValue("@Path", s) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + using (new Logging.Timer(LOGTAG, "AddFromDb", $"Inserting {p.Length} paths into {filenamestable}")) + foreach (var s in p) + await cmd + .SetParameterValue("@Path", s) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); string whereClause; if (expression.Result) @@ -490,7 +496,7 @@ namespace Duplicati.Library.Main.Database WHERE {whereClause} ") .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await cmd @@ -538,27 +544,28 @@ namespace Duplicati.Library.Main.Database .ExecuteReaderAsync(token) .ConfigureAwait(false); - while (await rd.ReadAsync(token).ConfigureAwait(false)) - { - rd.GetValues(values); - var path = values[0] as string; - if (path != null && FilterExpression.Matches(filter, path.ToString())) + using (new Logging.Timer(LOGTAG, "AddFromDb", $"Evaluating paths and updating table")) + while (await rd.ReadAsync(token).ConfigureAwait(false)) { - await cmd2 - .SetParameterValue("@Path", values[0]) - .SetParameterValue("@FileHash", values[1]) - .SetParameterValue("@MetaHash", values[2]) - .SetParameterValue("@Size", values[3]) - .SetParameterValue("@Type", values[4]) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + rd.GetValues(values); + var path = values[0] as string; + if (path != null && FilterExpression.Matches(filter, path.ToString())) + { + await cmd2 + .SetParameterValue("@Path", values[0]) + .SetParameterValue("@FileHash", values[1]) + .SetParameterValue("@MetaHash", values[2]) + .SetParameterValue("@Size", values[3]) + .SetParameterValue("@Type", values[4]) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } } - } } } /// - public async Task AddElement(string path, string filehash, string metahash, long size, Interface.ListChangesElementType type, bool asNew, CancellationToken token) + public async Task AddElement(string path, string filehash, string metahash, long size, Interface.ListChangesElementType type, bool asNew, bool logQuery, CancellationToken token) { var cmd = asNew ? m_insertCurrentElementCommand : m_insertPreviousElementCommand; await cmd @@ -567,7 +574,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@MetaHash", metahash) .SetParameterValue("@Size", size) .SetParameterValue("@Type", (int)type) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(logQuery, token) .ConfigureAwait(false); } diff --git a/Duplicati/Library/Main/Database/LocalListDatabase.cs b/Duplicati/Library/Main/Database/LocalListDatabase.cs index 638c0355f..4c6e49e21 100644 --- a/Duplicati/Library/Main/Database/LocalListDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalListDatabase.cs @@ -368,7 +368,7 @@ namespace Duplicati.Library.Main.Database WHERE SUBSTR(""Path"", 1, {Library.Utility.Utility.FormatInvariantValue(prefixrule.Length)}) != @Rule ") .SetParameterValue("@Rule", prefixrule) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Then we recursively find the largest prefix @@ -563,11 +563,12 @@ namespace Duplicati.Library.Main.Database VALUES (@Path) "); - await foreach (var n in SelectFolderEntries(cmd, pathprefix, tmpnames.Tablename, token).Distinct().ConfigureAwait(false)) - await c2 - .SetParameterValue("@Path", n) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + using (new Logging.Timer(LOGTAG, "ListFolderContents", "Inserting paths into table")) + await foreach (var n in SelectFolderEntries(cmd, pathprefix, tmpnames.Tablename, token).Distinct().ConfigureAwait(false)) + await c2 + .SetParameterValue("@Path", n) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); await c2.ExecuteNonQueryAsync($@" CREATE INDEX ""{tbname}_PathIndex"" diff --git a/Duplicati/Library/Main/Database/LocalLockDatabase.cs b/Duplicati/Library/Main/Database/LocalLockDatabase.cs index a3c5996c7..c0320a2d2 100644 --- a/Duplicati/Library/Main/Database/LocalLockDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalLockDatabase.cs @@ -73,7 +73,7 @@ namespace Duplicati.Library.Main.Database cmd.SetParameterValue("@Name", name); cmd.SetParameterValue("@LockExpirationTime", Library.Utility.Utility.NormalizeDateTimeToEpochSeconds(lockExpirationTime)); - var c = await cmd.ExecuteNonQueryAsync(token).ConfigureAwait(false); + var c = await cmd.ExecuteNonQueryAsync(true, token).ConfigureAwait(false); if (c != 1) throw new Exception($"Unexpected number of remote volumes updated: {c}, expected 1"); } diff --git a/Duplicati/Library/Main/Database/LocalPurgeDatabase.cs b/Duplicati/Library/Main/Database/LocalPurgeDatabase.cs index e09ee12ed..79f754609 100644 --- a/Duplicati/Library/Main/Database/LocalPurgeDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalPurgeDatabase.cs @@ -36,6 +36,11 @@ namespace Duplicati.Library.Main.Database /// internal class LocalPurgeDatabase : LocalDeleteDatabase { + /// + /// The log tag used for logging + /// + private static readonly string LOGTAG = Logging.Log.LogTagFromType(); + /// /// Creates a new instance of the class. /// @@ -300,10 +305,11 @@ namespace Duplicati.Library.Main.Database .PrepareAsync(token) .ConfigureAwait(false); - foreach (var s in p) - await cmd.SetParameterValue("@Path", s) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + using (new Logging.Timer(LOGTAG, "ApplyFilter", "Inserting paths into table")) + foreach (var s in p) + await cmd.SetParameterValue("@Path", s) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); await cmd.SetCommandAndParameters($@" INSERT INTO ""{m_tablename}"" (""FileID"") @@ -317,7 +323,7 @@ namespace Duplicati.Library.Main.Database AND ""B"".""Path"" IN ""{filenamestable}"" ") .SetParameterValue("@FilesetId", ParentID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await cmd @@ -350,17 +356,20 @@ namespace Duplicati.Library.Main.Database ") .SetParameterValue("@FilesetId", ParentID); - await using var rd = await cmd.ExecuteReaderAsync(token).ConfigureAwait(false); - while (await rd.ReadAsync(token).ConfigureAwait(false)) + using (new Logging.Timer(LOGTAG, "ApplyFilter", "Iterating files with filter")) { - rd.GetValues(values); - var path = values[0] as string; - if (path != null && Library.Utility.FilterExpression.Matches(filter, path.ToString())) + await using var rd = await cmd.ExecuteReaderAsync(token).ConfigureAwait(false); + while (await rd.ReadAsync(token).ConfigureAwait(false)) { - await cmd2 - .SetParameterValue("@FileId", values[1]) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + rd.GetValues(values); + var path = values[0] as string; + if (path != null && Library.Utility.FilterExpression.Matches(filter, path.ToString())) + { + await cmd2 + .SetParameterValue("@FileId", values[1]) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } } } } @@ -480,7 +489,7 @@ namespace Duplicati.Library.Main.Database ") .SetParameterValue("@TargetFilesetId", filesetid) .SetParameterValue("@SourceFilesetId", ParentID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); return new Tuple(remotevolid, filesetid); diff --git a/Duplicati/Library/Main/Database/LocalRecreateDatabase.cs b/Duplicati/Library/Main/Database/LocalRecreateDatabase.cs index 2084bc83b..768b73b23 100644 --- a/Duplicati/Library/Main/Database/LocalRecreateDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalRecreateDatabase.cs @@ -873,7 +873,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@FilesetId", filesetid) .SetParameterValue("@FileId", fileid) .SetParameterValue("@LastModified", time.ToUniversalTime().Ticks) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -953,21 +953,22 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_rtr) .SetParameterValue("@BlocksetId", blocksetid); - foreach (var hash in blocklisthashes) - { - if (!string.IsNullOrEmpty(hash)) + using (new Logging.Timer(LOGTAG, "AddBlockset", "Inserting blocklist hashes")) + foreach (var hash in blocklisthashes) { - c++; - if (c <= expectedblocklisthashes) + if (!string.IsNullOrEmpty(hash)) { - await m_insertBlocklistHashCommand - .SetParameterValue("@Index", index++) - .SetParameterValue("@Hash", hash) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + c++; + if (c <= expectedblocklisthashes) + { + await m_insertBlocklistHashCommand + .SetParameterValue("@Index", index++) + .SetParameterValue("@Hash", hash) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } } } - } } if (c != expectedblocklisthashes) @@ -1008,7 +1009,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) .SetParameterValue("@VolumeId", volumeID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); return (anyChange, true); @@ -1021,7 +1022,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@VolumeId", volumeID) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -1036,7 +1037,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) .SetParameterValue("@VolumeId", volumeID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); return (anyChange, false); @@ -1059,7 +1060,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@FileHash", filehash) .SetParameterValue("@BlockHash", blockhash) .SetParameterValue("@BlockSize", blocksize) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -1076,7 +1077,7 @@ namespace Duplicati.Library.Main.Database var r = await m_findTempBlockListHashCommand .SetTransaction(m_rtr) .SetParameterValue("@BlocklistHash", hash) - .ExecuteScalarAsync(token) + .ExecuteScalarAsync(true, token) .ConfigureAwait(false); if (r != null && r != DBNull.Value) @@ -1093,7 +1094,7 @@ namespace Duplicati.Library.Main.Database await m_insertTempBlockListHash .SetParameterValue("@BlockHash", s) .SetParameterValue("@Index", index++) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -1572,7 +1573,7 @@ namespace Duplicati.Library.Main.Database update.Parameters.AddWithValue("@Content", content); update.Parameters.AddWithValue("@MetadataId", metadataId); - await update.ExecuteNonQueryAsync(token).ConfigureAwait(false); + await update.ExecuteNonQueryAsync(true, token).ConfigureAwait(false); } public override void Dispose() diff --git a/Duplicati/Library/Main/Database/LocalRepairDatabase.cs b/Duplicati/Library/Main/Database/LocalRepairDatabase.cs index 8fb4db855..0fc9064fa 100644 --- a/Duplicati/Library/Main/Database/LocalRepairDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalRepairDatabase.cs @@ -143,7 +143,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@CurrentFilesetId", filesetid) .SetParameterValue("@PreviousFilesetId", prevFilesetId); - await cmd.ExecuteNonQueryAsync(token).ConfigureAwait(false); + await cmd.ExecuteNonQueryAsync(true, token).ConfigureAwait(false); } /// @@ -220,7 +220,7 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_rtr) .SetParameterValue("@FilesetId", filesetid); - return await cmd.ExecuteNonQueryAsync(token).ConfigureAwait(false); + return await cmd.ExecuteNonQueryAsync(true, token).ConfigureAwait(false); } /// @@ -480,7 +480,7 @@ namespace Duplicati.Library.Main.Database ") .SetParameterValue("@Name", volumename); - var blockCount = await cmd.ExecuteNonQueryAsync(token) + var blockCount = await cmd.ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (blockCount == 0) @@ -561,7 +561,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) .SetParameterValue("@PreviousRestoredValue", 0) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false) == 1; if (restored) @@ -569,14 +569,14 @@ namespace Duplicati.Library.Main.Database await m_copyIntoDuplicatedBlocks.SetTransaction(m_rtr) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); var c = await m_assignBlocksToNewVolume.SetTransaction(m_rtr) .SetParameterValue("@TargetVolumeId", targetVolumeId) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != 1) @@ -709,7 +709,7 @@ namespace Duplicati.Library.Main.Database ") .SetParameterValue("@HashesPerBlock", hashesPerBlock) .SetParameterValue("@Restored", 0) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); cmd.SetCommandAndParameters($@" @@ -816,7 +816,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@SourceVolumeId", sourceVolumeId) .SetParameterValue("@Restored", 1); - var moved = await cmd.ExecuteNonQueryAsync(token) + var moved = await cmd.ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Then update the blocks table to point to the new volume @@ -836,7 +836,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@TargetVolumeId", targetVolumeId) .SetParameterValue("@SourceVolumeId", sourceVolumeId) .SetParameterValue("@Restored", 1) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (updated != moved) @@ -1070,7 +1070,7 @@ namespace Duplicati.Library.Main.Database await c2 .SetParameterValue("@MetadataId", rd.GetValue(0)) .SetParameterValue("@BlocksetId", rd.GetValue(1)) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } } @@ -1127,7 +1127,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Path", rd.GetValue(1)) .SetParameterValue("@BlocksetId", rd.GetValue(2)) .SetParameterValue("@MetadataId", rd.GetValue(3)) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } } @@ -1270,7 +1270,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Path", rd.GetValue(2)) .SetParameterValue("@BlocksetId", rd.GetValue(3)) .SetParameterValue("@MetadataId", rd.GetValue(4)) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } } @@ -1484,7 +1484,7 @@ namespace Duplicati.Library.Main.Database WHERE ""BlocksetID"" = @BlocksetId ") .SetParameterValue("@BlocksetId", blocksetid) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); c2.SetCommandAndParameters(@" @@ -1530,7 +1530,7 @@ namespace Duplicati.Library.Main.Database { var rc = await c6 .SetParameterValue("@DeletedBlockId", deletedBlockId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (rc != 2) @@ -1542,7 +1542,7 @@ namespace Duplicati.Library.Main.Database await c3.SetParameterValue("@BlocksetId", blocksetid) .SetParameterValue("@Index", ix) .SetParameterValue("@Hash", blkey) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); ix++; @@ -1582,7 +1582,7 @@ namespace Duplicati.Library.Main.Database { var rc = await c6 .SetParameterValue("@DeletedBlockId", deletedBlockId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (rc != 2) throw new Exception($"Unexpected update count: {rc}"); @@ -1594,7 +1594,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@BlocksetId", blocksetid) .SetParameterValue("@Index", ix) .SetParameterValue("@Hash", blkeyfinal) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } } @@ -1684,7 +1684,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@BlocksetId", rd.GetValue(0)) .SetParameterValue("@Index", rd.GetValue(1)) .SetParameterValue("@Limit", expected) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (actual != expected) @@ -1762,7 +1762,7 @@ namespace Duplicati.Library.Main.Database await cmd .SetParameterValue("@Hash", kp.Key) .SetParameterValue("@Size", kp.Value) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -2014,7 +2014,7 @@ namespace Duplicati.Library.Main.Database AND ""m"".""BlocksetID"" != @KeepBlockset ") .SetParameterValue("@KeepBlockset", emptyBlocksetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Step 2: Update FileLookup to use a valid metadata ID @@ -2032,7 +2032,7 @@ namespace Duplicati.Library.Main.Database ) ") .SetParameterValue("@KeepBlockset", emptyBlocksetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Step 3: Delete obsolete Metadataset entries @@ -2043,7 +2043,7 @@ namespace Duplicati.Library.Main.Database FROM ""{tablename}"" ) ") - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Step 4: Delete orphaned blocksets (affected only) @@ -2065,7 +2065,7 @@ namespace Duplicati.Library.Main.Database WHERE ""BlocksetID"" = ""Blockset"".""ID"" ) ") - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Step 5: Confirm all broken metadata entries are resolved @@ -2093,7 +2093,7 @@ namespace Duplicati.Library.Main.Database try { await cmd.SetCommandAndParameters($@"DROP TABLE IF EXISTS ""{tablename}"" ") - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } catch (Exception ex) diff --git a/Duplicati/Library/Main/Database/LocalRestoreDatabase.cs b/Duplicati/Library/Main/Database/LocalRestoreDatabase.cs index 29704742d..c79c44808 100644 --- a/Duplicati/Library/Main/Database/LocalRestoreDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalRestoreDatabase.cs @@ -509,7 +509,7 @@ namespace Duplicati.Library.Main.Database AND ""FilesetEntry"".""FilesetID"" = @FilesetId ") .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } else if (Library.Utility.Utility.IsFSCaseSensitive && filter is FilterExpression expression && expression.Type == FilterType.Simple) @@ -536,13 +536,14 @@ namespace Duplicati.Library.Main.Database ") .ConfigureAwait(false); - foreach (var s in p) - { - await cmd - .SetParameterValue("@Path", s) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } + using (new Logging.Timer(LOGTAG, "InsertFilteredPaths", "Inserting filtered paths into temporary table")) + foreach (var s in p) + { + await cmd + .SetParameterValue("@Path", s) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } var c = await cmd.SetCommandAndParameters($@" INSERT INTO ""{m_tempfiletable}"" ( @@ -570,7 +571,7 @@ namespace Duplicati.Library.Main.Database ) ") .SetParameterValue("@FilesetId", filesetId) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (c != p.Length && c != 0) @@ -647,21 +648,25 @@ namespace Duplicati.Library.Main.Database 0 ) "); - await using var rd = await cmd.ExecuteReaderAsync(token) - .ConfigureAwait(false); - while (await rd.ReadAsync(token).ConfigureAwait(false)) + + using (new Logging.Timer(LOGTAG, "ApplyFilter", "Iterating files with filter")) { - rd.GetValues(values); - var path = values[1] as string; - if (path != null && FilterExpression.Matches(filter, path.ToString()!)) + await using var rd = await cmd.ExecuteReaderAsync(token) + .ConfigureAwait(false); + while (await rd.ReadAsync(token).ConfigureAwait(false)) { - await cmd2 - .SetParameterValue("@ID", values[0]) - .SetParameterValue("@Path", values[1]) - .SetParameterValue("@BlocksetID", values[2]) - .SetParameterValue("@MetadataID", values[3]) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); + rd.GetValues(values); + var path = values[1] as string; + if (path != null && FilterExpression.Matches(filter, path.ToString()!)) + { + await cmd2 + .SetParameterValue("@ID", values[0]) + .SetParameterValue("@Path", values[1]) + .SetParameterValue("@BlocksetID", values[2]) + .SetParameterValue("@MetadataID", values[3]) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } } } } @@ -734,7 +739,7 @@ namespace Duplicati.Library.Main.Database ") .SetTransaction(m_rtr); - var v0 = await cmd.ExecuteScalarAsync(token).ConfigureAwait(false); + var v0 = await cmd.ExecuteScalarAsync(true, token).ConfigureAwait(false); if (v0 == null || v0 == DBNull.Value) return null; @@ -756,7 +761,7 @@ namespace Duplicati.Library.Main.Database ") .SetTransaction(m_rtr); - var v0 = await cmd.ExecuteScalarAsync(token).ConfigureAwait(false); + var v0 = await cmd.ExecuteScalarAsync(true, token).ConfigureAwait(false); var maxpath = ""; if (v0 != null && v0 != DBNull.Value) maxpath = v0.ToString()!; @@ -863,7 +868,7 @@ namespace Duplicati.Library.Main.Database END ") .SetParameterValue("@Path", Util.AppendDirSeparator(System.IO.Path.GetPathRoot(Library.Utility.TempFolder.SystemTempPath) ?? "").Replace("\\", "/")) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } else @@ -914,7 +919,7 @@ namespace Duplicati.Library.Main.Database SET ""TargetPath"" = SUBSTR(""Path"", @PrefixLength) ") .SetParameterValue("@PrefixLength", largest_prefix.Length + 1) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } } @@ -944,7 +949,7 @@ namespace Duplicati.Library.Main.Database SET ""TargetPath"" = @Destination || ""TargetPath"" ") .SetParameterValue("@Destination", Util.AppendDirSeparator(destination)) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -1068,7 +1073,7 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_rtr) .SetParameterValue("@TargetPath", newname) .SetParameterValue("@ID", ID) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); await m_rtr.CommitAsync(token: token).ConfigureAwait(false); @@ -1702,13 +1707,15 @@ namespace Duplicati.Library.Main.Database @Size ) "); - foreach (var s in curvolume.Blocks) - { - await c.SetParameterValue("@Hash", s.Key) - .SetParameterValue("@Size", s.Value) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } + + using (new Logging.Timer(LOGTAG, "InsertBlocks", "Inserting blocks from current volume")) + foreach (var s in curvolume.Blocks) + { + await c.SetParameterValue("@Hash", s.Key) + .SetParameterValue("@Size", s.Value) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } // The index _HashSizeIndex is not needed anymore. Index on "Blocks-..." is used on Join in GetMissingBlocks @@ -2251,7 +2258,7 @@ namespace Duplicati.Library.Main.Database ") .SetTransaction(m_rtr); - var result = await cmd.ExecuteScalarAsync(token) + var result = await cmd.ExecuteScalarAsync(true, token) .ConfigureAwait(false); if (result == DBNull.Value || result == null) @@ -2598,7 +2605,7 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_db.Transaction) .SetParameterValue("@TargetFileId", targetfileid); - var r = await m_resetfileCommand.ExecuteNonQueryAsync(token) + var r = await m_resetfileCommand.ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (r <= 0) throw new Exception("Unexpected reset result"); @@ -2614,7 +2621,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Metadata", includeMetadata ? 1 : 0); var r = await m_updateAsRestoredCommand - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (r <= 0) throw new Exception("Unexpected reset result"); @@ -2629,7 +2636,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@TargetFileId", targetfileid); var r = await m_updateFileAsDataVerifiedCommand - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (r != 1) throw new Exception("Unexpected result when marking file as verified."); @@ -2648,7 +2655,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Metadata", metadata); var r = await m_insertblockCommand - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); if (r != 1) @@ -2887,21 +2894,25 @@ namespace Duplicati.Library.Main.Database SELECT DISTINCT ""{m_tempfiletable}"".""Path"" FROM ""{m_tempfiletable}"" "); - await using (var rd = await cmdReader.ExecuteReaderAsync(token).ConfigureAwait(false)) + + using (new Logging.Timer(LOGTAG, "CheckLocalSourceExists", "Checking if local source files exist")) { - while (await rd.ReadAsync(token).ConfigureAwait(false)) + await using (var rd = await cmdReader.ExecuteReaderAsync(token).ConfigureAwait(false)) { - var sourcepath = rd.ConvertValueToString(0); - if (SystemIO.IO_OS.FileExists(sourcepath)) + while (await rd.ReadAsync(token).ConfigureAwait(false)) { - await cmd - .SetParameterValue("@Path", sourcepath) - .ExecuteNonQueryAsync(token) - .ConfigureAwait(false); - } - else - { - Logging.Log.WriteVerboseMessage(LOGTAG, "LocalSourceMissing", "Local source file not found: {0}", sourcepath); + var sourcepath = rd.ConvertValueToString(0); + if (SystemIO.IO_OS.FileExists(sourcepath)) + { + await cmd + .SetParameterValue("@Path", sourcepath) + .ExecuteNonQueryAsync(token) // Not logging as we log the total time + .ConfigureAwait(false); + } + else + { + Logging.Log.WriteVerboseMessage(LOGTAG, "LocalSourceMissing", "Local source file not found: {0}", sourcepath); + } } } } diff --git a/Duplicati/Library/Main/Database/LocalTestDatabase.cs b/Duplicati/Library/Main/Database/LocalTestDatabase.cs index dc19dfffc..9535ba9ea 100644 --- a/Duplicati/Library/Main/Database/LocalTestDatabase.cs +++ b/Duplicati/Library/Main/Database/LocalTestDatabase.cs @@ -100,7 +100,7 @@ namespace Duplicati.Library.Main.Database WHERE ""Name"" = @Name ") .SetParameterValue("@Name", name) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -556,7 +556,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Hash", hash) .SetParameterValue("@Metasize", metasize) .SetParameterValue("@Metahash", metahash) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -646,7 +646,7 @@ namespace Duplicati.Library.Main.Database await cmd .SetCommandAndParameters(create) .SetParameterValue("@Name", m_volumename) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); cmd @@ -775,7 +775,7 @@ namespace Duplicati.Library.Main.Database .SetParameterValue("@Name", filename) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", length) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -844,7 +844,7 @@ namespace Duplicati.Library.Main.Database await cmd .SetCommandAndParameters(create) .SetParameterValue("@Name", m_volumename) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); cmd @@ -980,7 +980,7 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_db.Transaction) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -1083,7 +1083,7 @@ namespace Duplicati.Library.Main.Database await cmd .SetCommandAndParameters(create) .SetParameterValue("@Name", m_volumename) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); cmd @@ -1181,7 +1181,7 @@ namespace Duplicati.Library.Main.Database .SetTransaction(m_db.Transaction) .SetParameterValue("@Hash", hash) .SetParameterValue("@Size", size) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); } @@ -1303,7 +1303,7 @@ namespace Duplicati.Library.Main.Database await cmd .SetCommandAndParameters(create) .SetParameterValue("@Name", m_volumename) - .ExecuteNonQueryAsync(token) + .ExecuteNonQueryAsync(true, token) .ConfigureAwait(false); // Compare against actual values inserted into temp table diff --git a/Duplicati/Library/Main/Operation/ListChangesHandler.cs b/Duplicati/Library/Main/Operation/ListChangesHandler.cs index b5717efe3..a23ee7774 100644 --- a/Duplicati/Library/Main/Operation/ListChangesHandler.cs +++ b/Duplicati/Library/Main/Operation/ListChangesHandler.cs @@ -146,23 +146,25 @@ namespace Duplicati.Library.Main.Operation if (!await m_result.TaskControl.ProgressRendevouz().ConfigureAwait(false)) return; + using (new Logging.Timer(LOGTAG, "InsertBaseFiles", "Inserting base files into database")) using (var tmpfile = await backendManager.GetAsync(baseFile.File.Name, null, baseFile.File.Size, m_result.TaskControl.ProgressToken).ConfigureAwait(false)) using (var rd = new Volumes.FilesetVolumeReader(RestoreHandler.GetCompressionModule(baseFile.File.Name), tmpfile, m_options)) foreach (var f in rd.Files) if (FilterExpression.Matches(filter, f.Path)) await storageKeeper - .AddElement(f.Path, f.Hash, f.Metahash, f.Size, conv(f.Type), false, m_result.TaskControl.ProgressToken) + .AddElement(f.Path, f.Hash, f.Metahash, f.Size, conv(f.Type), false, false, m_result.TaskControl.ProgressToken) .ConfigureAwait(false); if (!await m_result.TaskControl.ProgressRendevouz().ConfigureAwait(false)) return; + using (new Logging.Timer(LOGTAG, "InsertCompareFiles", "Inserting compare files into database")) using (var tmpfile = await backendManager.GetAsync(compareFile.File.Name, null, compareFile.File.Size, m_result.TaskControl.ProgressToken).ConfigureAwait(false)) using (var rd = new Volumes.FilesetVolumeReader(RestoreHandler.GetCompressionModule(compareFile.File.Name), tmpfile, m_options)) foreach (var f in rd.Files) if (FilterExpression.Matches(filter, f.Path)) await storageKeeper - .AddElement(f.Path, f.Hash, f.Metahash, f.Size, conv(f.Type), true, m_result.TaskControl.ProgressToken) + .AddElement(f.Path, f.Hash, f.Metahash, f.Size, conv(f.Type), true, false, m_result.TaskControl.ProgressToken) .ConfigureAwait(false); }