From bb484d0c5f618d5a54f66af99c2017b05b8f7520 Mon Sep 17 00:00:00 2001 From: Maciej Aszyk Date: Fri, 26 Apr 2024 14:31:59 +0200 Subject: [PATCH 01/27] RavenDB-22318 Missing SliceComparer --- .../Documents/Expiration/ExpiredDocumentsCleaner.cs | 2 +- src/Raven.Server/ServerWide/CompareExchangeExpirationStorage.cs | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/Raven.Server/Documents/Expiration/ExpiredDocumentsCleaner.cs b/src/Raven.Server/Documents/Expiration/ExpiredDocumentsCleaner.cs index 2892bede6a36..cb83a5483a51 100644 --- a/src/Raven.Server/Documents/Expiration/ExpiredDocumentsCleaner.cs +++ b/src/Raven.Server/Documents/Expiration/ExpiredDocumentsCleaner.cs @@ -235,7 +235,7 @@ internal class DeleteExpiredDocumentsCommandDto : TransactionOperationsMerger.IR { public ExpiredDocumentsCleaner.DeleteExpiredDocumentsCommand ToCommand(DocumentsOperationContext context, DocumentDatabase database) { - var expired = new Dictionary>(); + var expired = new Dictionary>(SliceComparer.Instance); foreach (var item in Expired) { expired[item.Key] = item.Value; diff --git a/src/Raven.Server/ServerWide/CompareExchangeExpirationStorage.cs b/src/Raven.Server/ServerWide/CompareExchangeExpirationStorage.cs index 1ffbd2634ba7..67cc7117f88a 100644 --- a/src/Raven.Server/ServerWide/CompareExchangeExpirationStorage.cs +++ b/src/Raven.Server/ServerWide/CompareExchangeExpirationStorage.cs @@ -99,7 +99,7 @@ public static bool TryGetExpires(BlittableJsonReaderObject value, out long ticks public static unsafe bool DeleteExpiredCompareExchange(ClusterOperationContext context, Table items, long ticks, long take = long.MaxValue) { // we have to use a dictionary to remove from expired multi tree, because there is a chance that not all keys for certain ticks will be returned in single delete iteration - var expired = new Dictionary>(); + var expired = new Dictionary>(SliceComparer.Instance); foreach ((Slice keySlice, long expiredTicks, Slice ticksSlice) in GetExpiredValues(context, ticks)) { From c4d773e96390f4c8a033bcc31798f1489550d303 Mon Sep 17 00:00:00 2001 From: Lev Skuditsky Date: Sun, 3 Dec 2023 11:11:33 +0200 Subject: [PATCH 02/27] RavenDB-21718: Fix bug when downloading logs from the Studio returns empty zip --- .../Documents/Handlers/Admin/AdminLogsHandler.cs | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) diff --git a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs index 8fa29b4092e9..21b5689fac07 100644 --- a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs +++ b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs @@ -132,14 +132,8 @@ public async Task Download() continue; var hasLogDateTime = LoggingSource.LogInfo.TryGetDate(filePath, out var logDateTime); - if (hasLogDateTime) - { - if (from != null && logDateTime < from) - continue; - - if (to != null && logDateTime > to) - continue; - } + if (hasLogDateTime && from.HasValue && logDateTime < from) + continue; try { @@ -161,6 +155,9 @@ public async Task Download() { await DebugInfoPackageUtils.WriteExceptionAsZipEntryAsync(e, archive, fileName); } + + if (hasLogDateTime && to.HasValue && logDateTime > to) + break; } } From 0a0ea5695b4d6c2008e8ea07305fb7a631ccdbac Mon Sep 17 00:00:00 2001 From: Lev Skuditsky Date: Wed, 6 Dec 2023 10:43:15 +0200 Subject: [PATCH 03/27] RavenDB-21718: Considering Time Zones --- .../Handlers/Admin/AdminLogsHandler.cs | 12 +++++----- src/Sparrow/Logging/LoggingSource.cs | 22 ++++++++++++++----- .../SparrowTests/LoggingSourceTests.cs | 4 ++-- 3 files changed, 25 insertions(+), 13 deletions(-) diff --git a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs index 21b5689fac07..1f41293b93c5 100644 --- a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs +++ b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs @@ -116,8 +116,8 @@ public async Task Download() var adminLogsFileName = $"admin.logs.download.{Guid.NewGuid():N}"; var adminLogsFilePath = ServerStore._env.Options.DataPager.Options.TempPath.Combine(adminLogsFileName); - var from = GetDateTimeQueryString("from", required: false); - var to = GetDateTimeQueryString("to", required: false); + var fromUtc = GetDateTimeQueryString("from", required: false); + var toUtc = GetDateTimeQueryString("to", required: false); using (var stream = SafeFileStream.Create(adminLogsFilePath.FullPath, FileMode.CreateNew, FileAccess.ReadWrite, FileShare.ReadWrite, 4096, FileOptions.DeleteOnClose | FileOptions.SequentialScan)) @@ -131,15 +131,15 @@ public async Task Download() fileName.EndsWith(LoggingSource.LogInfo.FullCompressExtension, StringComparison.OrdinalIgnoreCase) == false) continue; - var hasLogDateTime = LoggingSource.LogInfo.TryGetDate(filePath, out var logDateTime); - if (hasLogDateTime && from.HasValue && logDateTime < from) + var hasLogDateTime = LoggingSource.LogInfo.TryGetDateUtc(filePath, out var logDateTimeUtc); + if (hasLogDateTime && fromUtc.HasValue && logDateTimeUtc < fromUtc) continue; try { var entry = archive.CreateEntry(fileName); if (hasLogDateTime) - entry.LastWriteTime = logDateTime; + entry.LastWriteTime = logDateTimeUtc; using (var fs = File.Open(filePath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) { @@ -156,7 +156,7 @@ public async Task Download() await DebugInfoPackageUtils.WriteExceptionAsZipEntryAsync(e, archive, fileName); } - if (hasLogDateTime && to.HasValue && logDateTime > to) + if (hasLogDateTime && toUtc.HasValue && logDateTimeUtc >= toUtc) break; } } diff --git a/src/Sparrow/Logging/LoggingSource.cs b/src/Sparrow/Logging/LoggingSource.cs index 140dda6d6286..64e90d195752 100644 --- a/src/Sparrow/Logging/LoggingSource.cs +++ b/src/Sparrow/Logging/LoggingSource.cs @@ -371,13 +371,25 @@ public LogInfo(string fileName) } } - public static bool TryGetDate(string fileName, out DateTime dateTime) + public static bool TryGetDateUtc(string fileName, out DateTime dateTimeUtc) + { + if (TryGetDateLocal(fileName, out var dateTimeLocal)) + { + dateTimeUtc = dateTimeLocal.ToUniversalTime(); + return true; + } + + dateTimeUtc = default; + return false; + } + + public static bool TryGetDateLocal(string fileName, out DateTime dateTimeLocal) { try { if (File.Exists(fileName)) { - dateTime = File.GetLastWriteTime(fileName); + dateTimeLocal = File.GetLastWriteTime(fileName); return true; } } @@ -386,7 +398,7 @@ public static bool TryGetDate(string fileName, out DateTime dateTime) // ignored } - dateTime = default; + dateTimeLocal = default; return false; } public static bool TryGetNumber(string fileName, out int n) @@ -434,7 +446,7 @@ private int LastLogNumberForToday(string[] files) { for (int i = files.Length - 1; i >= 0; i--) { - if(LogInfo.TryGetDate(files[i], out var fileDate) == false || fileDate.Date.Equals(_today) == false) + if(LogInfo.TryGetDateLocal(files[i], out var fileDate) == false || fileDate.Date.Equals(_today) == false) continue; if (LogInfo.TryGetNumber(files[i], out var n)) @@ -451,7 +463,7 @@ private void CleanupOldLogFiles(string[] logFiles) foreach (var logFile in logFiles) { - if (LogInfo.TryGetDate(logFile, out var logDateTime) == false + if (LogInfo.TryGetDateLocal(logFile, out var logDateTime) == false || DateTime.Now - logDateTime <= RetentionTime) continue; diff --git a/test/SlowTests/SparrowTests/LoggingSourceTests.cs b/test/SlowTests/SparrowTests/LoggingSourceTests.cs index 820f91f2372d..3ea660230619 100644 --- a/test/SlowTests/SparrowTests/LoggingSourceTests.cs +++ b/test/SlowTests/SparrowTests/LoggingSourceTests.cs @@ -162,7 +162,7 @@ public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForTod { var afterEndFiles = Directory.GetFiles(path); todayLog = afterEndFiles.FirstOrDefault(f => - LoggingSource.LogInfo.TryGetDate(f, out var date) && date.Date.Equals(DateTime.Today)); + LoggingSource.LogInfo.TryGetDateLocal(f, out var date) && date.Date.Equals(DateTime.Today)); return todayLog != null; }, true, 10_000, 1_000); @@ -210,7 +210,7 @@ public async Task LoggingSource_WhenExistFileFromToday_ShouldIncrementNumberByOn var strings = Directory.GetFiles(path); return strings.Any(f => { - if (LoggingSource.LogInfo.TryGetDate(f, out var d) == false || d.Date.Equals(DateTime.Today) == false) + if (LoggingSource.LogInfo.TryGetDateLocal(f, out var d) == false || d.Date.Equals(DateTime.Today) == false) return false; return LoggingSource.LogInfo.TryGetNumber(f, out var n) && n == 11; From efa702c3c3cacd1faacc44f94e2b674d0fadc960 Mon Sep 17 00:00:00 2001 From: Lev Skuditsky Date: Fri, 15 Dec 2023 19:43:19 +0200 Subject: [PATCH 04/27] RavenDB-21718: Considering the Creation File's DateTime --- .../Handlers/Admin/AdminLogsHandler.cs | 52 +- src/Sparrow/Logging/LoggingSource.cs | 64 +- .../SparrowTests/DownloadLogsCommand.cs | 63 ++ .../SparrowTests/LoggingSourceTests.cs | 558 +++++++++++++++++- 4 files changed, 703 insertions(+), 34 deletions(-) create mode 100644 test/SlowTests/SparrowTests/DownloadLogsCommand.cs diff --git a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs index 1f41293b93c5..22c5f7248a46 100644 --- a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs +++ b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs @@ -116,10 +116,13 @@ public async Task Download() var adminLogsFileName = $"admin.logs.download.{Guid.NewGuid():N}"; var adminLogsFilePath = ServerStore._env.Options.DataPager.Options.TempPath.Combine(adminLogsFileName); - var fromUtc = GetDateTimeQueryString("from", required: false); - var toUtc = GetDateTimeQueryString("to", required: false); + var startUtc = GetDateTimeQueryString("from", required: false); + var endUtc = GetDateTimeQueryString("to", required: false); - using (var stream = SafeFileStream.Create(adminLogsFilePath.FullPath, FileMode.CreateNew, FileAccess.ReadWrite, FileShare.ReadWrite, 4096, + if (startUtc >= endUtc) + throw new ArgumentException($"End Date '{endUtc:yyyy-MM-ddTHH:mm:ss.fffffff} UTC' must be greater than Start Date '{startUtc:yyyy-MM-ddTHH:mm:ss.fffffff} UTC'"); + + await using (var stream = SafeFileStream.Create(adminLogsFilePath.FullPath, FileMode.CreateNew, FileAccess.ReadWrite, FileShare.ReadWrite, 4096, FileOptions.DeleteOnClose | FileOptions.SequentialScan)) { using (var archive = new ZipArchive(stream, ZipArchiveMode.Create, true)) @@ -131,17 +134,25 @@ public async Task Download() fileName.EndsWith(LoggingSource.LogInfo.FullCompressExtension, StringComparison.OrdinalIgnoreCase) == false) continue; - var hasLogDateTime = LoggingSource.LogInfo.TryGetDateUtc(filePath, out var logDateTimeUtc); - if (hasLogDateTime && fromUtc.HasValue && logDateTimeUtc < fromUtc) + // Skip this file if either the last write time or the creation time could not be determined + if (LoggingSource.LogInfo.TryGetLastWriteTimeUtc(filePath, out var logLastWriteTimeUtc) == false || + LoggingSource.LogInfo.TryGetCreationTimeUtc(filePath, out var logCreationTimeUtc) == false) + continue; + + bool isWithinDateRange = + // Check if the file was created before the end date. + (endUtc.HasValue == false || logCreationTimeUtc < endUtc.Value) && + // Check if the file was last modified after the start date. + (startUtc.HasValue == false || logLastWriteTimeUtc > startUtc.Value); + + // Skip this file if it does not fall within the specified date range + if (isWithinDateRange == false) continue; try { var entry = archive.CreateEntry(fileName); - if (hasLogDateTime) - entry.LastWriteTime = logDateTimeUtc; - - using (var fs = File.Open(filePath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) + await using (var fs = File.Open(filePath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) { entry.ExternalAttributes = ((int)(FilePermissions.S_IRUSR | FilePermissions.S_IWUSR)) << 16; @@ -155,9 +166,28 @@ public async Task Download() { await DebugInfoPackageUtils.WriteExceptionAsZipEntryAsync(e, archive, fileName); } + } + } + + // Add an informational file to the archive if no log files match the specified date range, + // ensuring the user receives a non-empty archive with an explanation. + using (var archive = new ZipArchive(stream, ZipArchiveMode.Update, true)) + { + // Check if any file was added to the zip + if (archive.Entries.Count == 0) + { + const string infoFileName = "No logs matched the date range.txt"; + + // Create a dummy entry in the zip file + var infoEntry = archive.CreateEntry(infoFileName); + await using var entryStream = infoEntry.Open(); + await using var streamWriter = new StreamWriter(entryStream); + + var formattedStartUtc = startUtc.HasValue ? startUtc.Value.ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"; + var formattedEndUtc = endUtc.HasValue ? endUtc.Value.ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"; - if (hasLogDateTime && toUtc.HasValue && logDateTimeUtc >= toUtc) - break; + await streamWriter.WriteAsync( + $"No log files were found that matched the specified date range from '{formattedStartUtc}' to '{formattedEndUtc}'."); } } diff --git a/src/Sparrow/Logging/LoggingSource.cs b/src/Sparrow/Logging/LoggingSource.cs index 64e90d195752..b07c163c0df5 100644 --- a/src/Sparrow/Logging/LoggingSource.cs +++ b/src/Sparrow/Logging/LoggingSource.cs @@ -371,36 +371,62 @@ public LogInfo(string fileName) } } - public static bool TryGetDateUtc(string fileName, out DateTime dateTimeUtc) - { - if (TryGetDateLocal(fileName, out var dateTimeLocal)) - { - dateTimeUtc = dateTimeLocal.ToUniversalTime(); - return true; - } + public static bool TryGetLastWriteTimeUtc(string fileName, out DateTime dateTimeUtc) => + TryGetFileTimeInternal(fileName, File.GetLastWriteTimeUtc, out dateTimeUtc); - dateTimeUtc = default; - return false; - } + public static bool TryGetLastWriteTimeLocal(string fileName, out DateTime dateTimeLocal) => + TryGetFileTimeInternal(fileName, File.GetLastWriteTime, out dateTimeLocal); - public static bool TryGetDateLocal(string fileName, out DateTime dateTimeLocal) + public static bool TryGetCreationTimeUtc(string fileName, out DateTime dateTimeUtc) => + TryGetFileTimeInternal(fileName, fn => GetLogFileCreationTime(fn, DateTimeKind.Utc), out dateTimeUtc); + + public static bool TryGetCreationTimeLocal(string fileName, out DateTime dateTimeLocal) => + TryGetFileTimeInternal(fileName, fn => GetLogFileCreationTime(fn, DateTimeKind.Local), out dateTimeLocal); + + private static bool TryGetFileTimeInternal(string fileName, Func fileTimeGetter, out DateTime dateTime) { + dateTime = default; try { - if (File.Exists(fileName)) - { - dateTimeLocal = File.GetLastWriteTime(fileName); - return true; - } + if (File.Exists(fileName) == false) + return false; + + dateTime = fileTimeGetter(fileName); + return true; } catch { // ignored } - dateTimeLocal = default; return false; } + + protected internal static DateTime GetLogFileCreationTime(string fileName, DateTimeKind timeKind) + { + using var sr = new StreamReader(fileName); + sr.ReadLine(); + + var line = sr.ReadLine(); + if (line == null) + throw new InvalidOperationException("Log file is empty or does not contain a second line."); + + var commaIndex = line.IndexOf(','); + if (commaIndex <= 0) + throw new InvalidOperationException("Second line of log file does not contain a valid timestamp."); + + var timestamp = line.Substring(0, commaIndex).Trim(); + if (DateTime.TryParse(timestamp, CultureInfo.InvariantCulture, DateTimeStyles.AssumeUniversal, out var dateTime) == false) + throw new InvalidOperationException("Unable to parse timestamp from the log file."); + + return timeKind switch + { + DateTimeKind.Utc => UseUtcTime ? dateTime : dateTime.ToUniversalTime(), + DateTimeKind.Local => UseUtcTime ? dateTime.ToLocalTime() : dateTime, + _ => throw new ArgumentOutOfRangeException(nameof(timeKind), timeKind, null) + }; + } + public static bool TryGetNumber(string fileName, out int n) { n = -1; @@ -446,7 +472,7 @@ private int LastLogNumberForToday(string[] files) { for (int i = files.Length - 1; i >= 0; i--) { - if(LogInfo.TryGetDateLocal(files[i], out var fileDate) == false || fileDate.Date.Equals(_today) == false) + if(LogInfo.TryGetCreationTimeLocal(files[i], out var fileDate) == false || fileDate.Date.Equals(_today) == false) continue; if (LogInfo.TryGetNumber(files[i], out var n)) @@ -463,7 +489,7 @@ private void CleanupOldLogFiles(string[] logFiles) foreach (var logFile in logFiles) { - if (LogInfo.TryGetDateLocal(logFile, out var logDateTime) == false + if (LogInfo.TryGetLastWriteTimeLocal(logFile, out var logDateTime) == false || DateTime.Now - logDateTime <= RetentionTime) continue; diff --git a/test/SlowTests/SparrowTests/DownloadLogsCommand.cs b/test/SlowTests/SparrowTests/DownloadLogsCommand.cs new file mode 100644 index 000000000000..3ea66a3ec503 --- /dev/null +++ b/test/SlowTests/SparrowTests/DownloadLogsCommand.cs @@ -0,0 +1,63 @@ +using System; +using System.IO; +using System.Net.Http; +using System.Text; +using Raven.Client.Http; +using Sparrow; +using Sparrow.Json; + +namespace SlowTests.SparrowTests; + +public class DownloadLogsCommand : RavenCommand +{ + private readonly DateTime? _startDate; + private readonly DateTime? _endDate; + + public DownloadLogsCommand(DateTime? startDate, DateTime? endDate) + { + _startDate = startDate; + _endDate = endDate; + ResponseType = RavenCommandResponseType.Raw; + } + + public override bool IsReadRequest => true; + + public override HttpRequestMessage CreateRequest(JsonOperationContext ctx, ServerNode node, out string url) + { + var pathBuilder = new StringBuilder(node.Url); + + pathBuilder.Append("/admin/logs/download"); + + if (_startDate.HasValue || _endDate.HasValue) + pathBuilder.Append('?'); + + if (_startDate.HasValue) + { + pathBuilder.Append("from="); + pathBuilder.Append(_startDate.Value.ToUniversalTime().ToString(DefaultFormat.DateTimeFormatsToWrite)); + + if (_endDate.HasValue) + pathBuilder.Append('&'); + } + + if (_endDate.HasValue) + { + pathBuilder.Append("to="); + pathBuilder.Append(_endDate.Value.ToUniversalTime().ToString(DefaultFormat.DateTimeFormatsToWrite)); + } + + url = pathBuilder.ToString(); + return new HttpRequestMessage { Method = HttpMethod.Get }; + } + + public override void SetResponseRaw(HttpResponseMessage response, Stream stream, JsonOperationContext context) + { + if (response == null) + return; + + var ms = new MemoryStream(); + stream.CopyTo(ms); + + Result = ms.ToArray(); + } +} diff --git a/test/SlowTests/SparrowTests/LoggingSourceTests.cs b/test/SlowTests/SparrowTests/LoggingSourceTests.cs index 3ea660230619..90a93683be29 100644 --- a/test/SlowTests/SparrowTests/LoggingSourceTests.cs +++ b/test/SlowTests/SparrowTests/LoggingSourceTests.cs @@ -11,9 +11,13 @@ using System.Threading; using System.Threading.Tasks; using FastTests; +using Raven.Client.Exceptions; using Raven.Client.Extensions; +using Raven.Server.Config; using Sparrow; +using Sparrow.Extensions; using Sparrow.Logging; +using Tests.Infrastructure; using Voron.Global; using Xunit; using Xunit.Abstractions; @@ -22,6 +26,7 @@ namespace SlowTests.SparrowTests { public class LoggingSourceTests : RavenTestBase { + public LoggingSourceTests(ITestOutputHelper output) : base(output) { } @@ -145,7 +150,7 @@ public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForTod var yesterday = DateTime.Now - TimeSpan.FromDays(1); var yesterdayLog = Path.Combine(path, $"{LoggingSource.LogInfo.DateToLogFormat(yesterday)}.010.{extension}"); await File.Create(yesterdayLog).DisposeAsync(); - File.SetLastWriteTime(yesterdayLog, yesterday); + File.SetCreationTime(yesterdayLog, yesterday); var loggingSource = new LoggingSource( LogMode.Information, @@ -162,7 +167,7 @@ public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForTod { var afterEndFiles = Directory.GetFiles(path); todayLog = afterEndFiles.FirstOrDefault(f => - LoggingSource.LogInfo.TryGetDateLocal(f, out var date) && date.Date.Equals(DateTime.Today)); + LoggingSource.LogInfo.TryGetCreationTimeLocal(f, out var date) && date.Date.Equals(DateTime.Today)); return todayLog != null; }, true, 10_000, 1_000); @@ -210,7 +215,7 @@ public async Task LoggingSource_WhenExistFileFromToday_ShouldIncrementNumberByOn var strings = Directory.GetFiles(path); return strings.Any(f => { - if (LoggingSource.LogInfo.TryGetDateLocal(f, out var d) == false || d.Date.Equals(DateTime.Today) == false) + if (LoggingSource.LogInfo.TryGetLastWriteTimeLocal(f, out var d) == false || d.Date.Equals(DateTime.Today) == false) return false; return LoggingSource.LogInfo.TryGetNumber(f, out var n) && n == 11; @@ -703,7 +708,7 @@ private Action AssertContainsLog(LogMode logType, LogMode logMod return Assert.DoesNotContain; } - [Fact] + [RavenFact(RavenTestCategory.Logging)] public async Task Register_WhenLogModeIsNone_ShouldNotWriteToLogFile() { var name = GetTestName(); @@ -747,6 +752,551 @@ public async Task Register_WhenLogModeIsNone_ShouldNotWriteToLogFile() Assert.DoesNotContain(uniqForInformation, logContent); } + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_Created_And_Modified_Within_Date_Range(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 03, 01), + LastWriteTime = new DateTime(2023, 03, 06), + ShouldBeIncluded = true + }, + new() + { + CreationTime = new DateTime(2023, 03, 07), + LastWriteTime = new DateTime(2023, 03, 29), + ShouldBeIncluded = true + }, + new() + { + CreationTime = new DateTime(2023, 03, 30), + LastWriteTime = new DateTime(2023, 03, 31), + ShouldBeIncluded = true + }, + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Not_Include_Files_Created_Before_And_Modified_After_Date_Range(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 02, 01), + LastWriteTime = new DateTime(2023, 02, 27), + ShouldBeIncluded = false + }, + new() + { + CreationTime = new DateTime(2023, 02, 28), + LastWriteTime = new DateTime(2023, 03, 01), + ShouldBeIncluded = false + }, + new() + { + CreationTime = new DateTime(2023, 03, 31), + LastWriteTime = new DateTime(2023, 04, 01), + ShouldBeIncluded = false + }, + new() + { + CreationTime = new DateTime(2023, 04, 02), + LastWriteTime = new DateTime(2023, 04, 07), + ShouldBeIncluded = false + } + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_Created_Within_And_Modified_After_Date_Range(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 03, 29), + LastWriteTime = new DateTime(2023, 04, 01), + ShouldBeIncluded = true + }, + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_Created_Before_And_Modified_Within_Date_Range(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 02, 15), + LastWriteTime = new DateTime(2023, 03, 15), + ShouldBeIncluded = true + }, + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_Created_Before_And_Modified_After_Date_Range(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 02, 27), + LastWriteTime = new DateTime(2023, 04, 05), + ShouldBeIncluded = true + } + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_With_Creation_And_Modification_Dates_Matching_Exact_Date_Range(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 03, 01), + LastWriteTime = new DateTime(2023, 03, 31), + ShouldBeIncluded = true + }, + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_When_No_Start_Date_Is_Specified(Options options, bool useUtc) + { + // No start date specified, only end date + var endDate = new DateTime(2023, 03, 31); + + // List of test files with their expected inclusion based on the end date + var testFiles = new List + { + // Files modified before the end date should be included + new() + { + CreationTime = new DateTime(2023, 03, 20), + LastWriteTime = new DateTime(2023, 03, 29), + ShouldBeIncluded = true + }, + new() + { + CreationTime = new DateTime(2023, 03, 30), + LastWriteTime = new DateTime(2023, 03, 31), + ShouldBeIncluded = true + }, + // Files modified on or after the end date should not be included + new() + { + CreationTime = new DateTime(2023, 03, 31), + LastWriteTime = new DateTime(2023, 04, 01), + ShouldBeIncluded = false + }, + new() + { + CreationTime = new DateTime(2023, 04, 01), + LastWriteTime = new DateTime(2023, 04, 16), + ShouldBeIncluded = false + }, + }; + + await VerifyLogDownloadByDateRange(startDate: null, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_Files_When_No_End_Date_Is_Specified(Options options, bool useUtc) + { + // Only start date specified, no end date + var startDate = new DateTime(2023, 03, 01); + + // List of test files with their expected inclusion based on the start date + var testFiles = new List + { + // Files modified before the start date should not be included + new() + { + CreationTime = new DateTime(2023, 02, 21), + LastWriteTime = new DateTime(2023, 02, 27), + ShouldBeIncluded = false + }, + new() + { + CreationTime = new DateTime(2023, 02, 28), + LastWriteTime = new DateTime(2023, 03, 01), + ShouldBeIncluded = false + }, + // Files modified after the start date should be included + new() + { + CreationTime = new DateTime(2023, 03, 01), + LastWriteTime = new DateTime(2023, 03, 02), + ShouldBeIncluded = true + }, + new() + { + CreationTime = new DateTime(2023, 03, 03), + LastWriteTime = new DateTime(2023, 03, 15), + ShouldBeIncluded = true + }, + }; + + await VerifyLogDownloadByDateRange(startDate, endDate: null, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Include_All_Files_When_No_Dates_Are_Specified(Options options, bool useUtc) + { + // No start and end dates specified + + // List of test files, all of which should be included as there are no date constraints + var testFiles = new List + { + // All files should be included regardless of their dates + new() + { + CreationTime = new DateTime(2020, 03, 01), + LastWriteTime = new DateTime(2021, 03, 31), + ShouldBeIncluded = true + }, + new() + { + CreationTime = new DateTime(2022, 04, 01), + LastWriteTime = new DateTime(2023, 04, 17), + ShouldBeIncluded = true + } + }; + + await VerifyLogDownloadByDateRange(startDate: null, endDate: null, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_Should_Throw_Exception_When_EndDate_Is_Before_StartDate(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 31); + var endDate = new DateTime(2023, 03, 01); + + // List of test files with expected outcomes + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 02, 27), + LastWriteTime = new DateTime(2023, 04, 05), + ShouldBeIncluded = true + } + }; + + // Run the test with the specified files and date range + var exception = await Record.ExceptionAsync(() => VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc)); + Assert.IsType(exception); + Assert.IsType(exception.InnerException); + + var expectedMessage = + $"End Date '{endDate.ToUniversalTime():yyyy-MM-ddTHH:mm:ss.fffffff} UTC' " + + $"must be greater than Start Date '{startDate.ToUniversalTime():yyyy-MM-ddTHH:mm:ss.fffffff} UTC'"; + + Assert.True(exception.InnerException.Message.Contains(expectedMessage), + userMessage:$"exception.InnerException.Message: {exception.InnerException.Message}{Environment.NewLine}" + + $"but expectedMessage: {expectedMessage}"); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_No_Logs_Should_Be_Selected_When_Neither_Start_Nor_End_Date_Matches(Options options, bool useUtc) + { + // Define request date range + var startDate = new DateTime(2023, 03, 01); + var endDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes (none should be included) + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 02, 27), + LastWriteTime = new DateTime(2023, 02, 28), + ShouldBeIncluded = false + } + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_No_Logs_Should_Be_Selected_When_Only_Start_Date_Is_Specified(Options options, bool useUtc) + { + // Define request date range with only start date + var startDate = new DateTime(2023, 03, 31); + + // List of test files with expected outcomes (none should be included) + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 03, 02), + LastWriteTime = new DateTime(2023, 03, 03), + ShouldBeIncluded = false + } + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate, endDate: null, testFiles, useUtc); + } + + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task Downloading_Logs_No_Logs_Should_Be_Selected_When_Only_End_Date_Is_Specified(Options options, bool useUtc) + { + // Define request date range with only end date + var endDate = new DateTime(2023, 03, 01); + + // List of test files with expected outcomes (none should be included) + var testFiles = new List + { + new() + { + CreationTime = new DateTime(2023, 03, 05), + LastWriteTime = new DateTime(2023, 03, 25), + ShouldBeIncluded = false + } + }; + + // Run the test with the specified files and date range + await VerifyLogDownloadByDateRange(startDate: null, endDate, testFiles, useUtc); + } + + private async Task VerifyLogDownloadByDateRange(DateTime? startDate, DateTime? endDate, List testFiles, bool useUtc, [CallerMemberName] string caller = null) + { + var path = RavenTestHelper.NewDataPath(caller, 0, forceCreateDir: true); + try + { + using var server = GetNewServer(new ServerCreationOptions + { + CustomSettings = new Dictionary + { + { RavenConfiguration.GetKey(x => x.Logs.Path), path }, + { RavenConfiguration.GetKey(x => x.Logs.UseUtcTime), useUtc.ToString() }, + } + }); + + // Create test files as specified in the testFiles list + foreach (var testFile in testFiles) + { + Assert.NotNull(testFile); + Assert.True(string.IsNullOrWhiteSpace(testFile.FileName)); + + testFile.FileName = $"{testFile.CreationTime:yyyy-MM-dd}.000.log"; + CreateTestFile(path, testFile, useUtc); + } + + // Initialize the document store and execute the download logs command + using (var store = GetDocumentStore(new Options { Server = server })) + using (var commands = store.Commands()) + { + var command = new DownloadLogsCommand(startDate, endDate); + await commands.RequestExecutor.ExecuteAsync(command, commands.Context); + + // Ensure that the command returns some result + Assert.True(command.Result.Length > 0); + var zipBytes = command.Result; + + // Read the result as a zip archive + using (var msZip = new MemoryStream(zipBytes)) + using (var archive = new ZipArchive(msZip, ZipArchiveMode.Read, false)) + { + var entries = archive.Entries.Select(entry => entry.Name).ToList(); + + // Check each file in testFiles to see if it's correctly included or excluded + foreach (var file in testFiles) + { + if (file.ShouldBeIncluded) + Assert.True(entries.Contains(file.FileName), $"Archive does not contain {file.FileName}{Environment.NewLine}{BuildDebugInfo()}"); + else + Assert.False(entries.Contains(file.FileName), $"Archive contain {file.FileName} but it shouldn't{Environment.NewLine}{BuildDebugInfo()}"); + + continue; + + string BuildDebugInfo() + { + var sb = new StringBuilder(); + sb.AppendLine("Debug info:"); + + sb.Append("Request from '"); + sb.Append(startDate.HasValue ? startDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"); + sb.Append("' to '"); + sb.Append(endDate.HasValue ? endDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"); + sb.AppendLine("'"); + sb.AppendLine(); + + sb.AppendLine("Files in folder: "); + sb.Append("Path: "); + sb.AppendLine(path); + + string[] files = Directory.GetFiles(path); + for (int index = 0; index < files.Length; index++) + { + string pathToFile = files[index]; + string fileName = Path.GetFileName(pathToFile); + sb.AppendLine( + $" {index + 1}) " + + $"FileName: {fileName}, " + + $"CreationTime: {LoggingSource.LogInfo.GetLogFileCreationTime(pathToFile, DateTimeKind.Utc)} 'UTC', " + + $"LastWriteTime: {File.GetLastWriteTimeUtc(pathToFile)} 'UTC', "); + } + sb.AppendLine(); + + sb.AppendLine("Test files:"); + for (int index = 0; index < testFiles.Count; index++) + { + var testFile = testFiles[index]; + sb.AppendLine( + $" {index + 1}) " + + $"FileName: {testFile.FileName}, " + + $"CreationTime: {testFile.CreationTime.ToUniversalTime()} 'UTC', " + + $"LastWriteTime: {testFile.LastWriteTime.ToUniversalTime()} 'UTC', " + + $"ShouldBeIncluded: {testFile.ShouldBeIncluded}"); + } + sb.AppendLine(); + + sb.AppendLine("Archive files:"); + for (int index = 0; index < archive.Entries.Count; index++) + { + ZipArchiveEntry entry = archive.Entries[index]; + sb.AppendLine( + $" {index + 1}) " + + $"FullName: {entry.FullName}, " + + $"LastWriteTime: {entry.LastWriteTime.ToUniversalTime()} 'UTC'"); + } + + return sb.ToString(); + } + } + + if (testFiles.Any(x => x.ShouldBeIncluded)) + return; + + Assert.Single(archive.Entries); + Assert.True(archive.Entries[0].Name == "No logs matched the date range.txt"); + + // Assert that the file content is as expected + await using (var entryStream = archive.Entries[0].Open()) + using (var streamReader = new StreamReader(entryStream)) + { + string content = await streamReader.ReadToEndAsync(); + var formattedStartUtc = startDate.HasValue ? startDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"; + var formattedEndUtc = endDate.HasValue ? endDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"; + + Assert.Equal($"No log files were found that matched the specified date range from '{formattedStartUtc}' to '{formattedEndUtc}'.", content); + } + } + } + } + finally + { + Directory.Delete(path, recursive: true); + } + } + + private static void CreateTestFile(string path, TestFile testFile, bool useUtc) + { + string filePath = Path.Combine(path, testFile.FileName); + var logEntryTime = useUtc + ? testFile.CreationTime.ToUniversalTime() + : testFile.CreationTime; + + File.WriteAllText(filePath, contents: $""" + Time, Thread, Level, Source, Logger, Message, Exception + {logEntryTime.GetDefaultRavenFormat()}, 1, Operations, Server, Raven.Server.Program + """); + + File.SetLastWriteTime(filePath, testFile.LastWriteTime); + } + + private class TestFile + { + protected internal string FileName; + protected internal DateTime CreationTime; + protected internal DateTime LastWriteTime; + protected internal bool ShouldBeIncluded; + } + private class MyDummyWebSocket : WebSocket { private bool _close; From f8faef996418421c1adce0695e0844421762a7ec Mon Sep 17 00:00:00 2001 From: Lev Skuditsky Date: Mon, 15 Apr 2024 15:46:32 +0300 Subject: [PATCH 05/27] RavenDB-21718: Implementing the storage of the log file's creation date in its name. --- .../Handlers/Admin/AdminLogsHandler.cs | 8 +- src/Sparrow/Logging/LoggingSource.cs | 332 ++++++------ .../SparrowTests/LoggingSourceTests.cs | 473 ++++++++++-------- test/SlowTests/Tests/TestsInheritanceTests.cs | 2 +- 4 files changed, 418 insertions(+), 397 deletions(-) diff --git a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs index 22c5f7248a46..c440f8e9efee 100644 --- a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs +++ b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs @@ -130,13 +130,13 @@ public async Task Download() foreach (var filePath in Directory.GetFiles(ServerStore.Configuration.Logs.Path.FullPath)) { var fileName = Path.GetFileName(filePath); - if (fileName.EndsWith(LoggingSource.LogInfo.LogExtension, StringComparison.OrdinalIgnoreCase) == false && - fileName.EndsWith(LoggingSource.LogInfo.FullCompressExtension, StringComparison.OrdinalIgnoreCase) == false) + if (fileName.EndsWith(LoggingSource.LogExtension, StringComparison.OrdinalIgnoreCase) == false && + fileName.EndsWith(LoggingSource.FullCompressExtension, StringComparison.OrdinalIgnoreCase) == false) continue; // Skip this file if either the last write time or the creation time could not be determined - if (LoggingSource.LogInfo.TryGetLastWriteTimeUtc(filePath, out var logLastWriteTimeUtc) == false || - LoggingSource.LogInfo.TryGetCreationTimeUtc(filePath, out var logCreationTimeUtc) == false) + if (LoggingSource.TryGetLastWriteTimeUtc(filePath, out var logLastWriteTimeUtc) == false || + LoggingSource.TryGetCreationTimeUtc(filePath, out var logCreationTimeUtc) == false) continue; bool isWithinDateRange = diff --git a/src/Sparrow/Logging/LoggingSource.cs b/src/Sparrow/Logging/LoggingSource.cs index b07c163c0df5..2bec161763f8 100644 --- a/src/Sparrow/Logging/LoggingSource.cs +++ b/src/Sparrow/Logging/LoggingSource.cs @@ -7,7 +7,6 @@ using System.IO.Compression; using System.Linq; using System.Net.WebSockets; -using System.Runtime.InteropServices; using System.Text; using System.Threading; using System.Threading.Tasks; @@ -28,6 +27,11 @@ public sealed class LoggingSource public static bool UseUtcTime; public long MaxFileSizeInBytes = 1024 * 1024 * 128; + private const string DateTimeWithMinutesFormat = "yyyy-MM-dd-HH-mm"; // current format + private const string DateOnlyFormat = "yyyy-MM-dd"; // for backward compatibility + internal const string LogExtension = ".log"; + internal const string AdditionalCompressExtension = ".gz"; + internal const string FullCompressExtension = LogExtension + AdditionalCompressExtension; internal static long LocalToUtcOffsetInTicks; @@ -264,12 +268,12 @@ public void EndLogging() private bool TryGetNewStreamAndApplyRetentionPolicies(long maxFileSize, out FileStream fileStream) { - string[] logFiles; - string[] logGzFiles; + string[] allLogFiles; try { - logFiles = Directory.GetFiles(_path, "*.log"); - logGzFiles = Directory.GetFiles(_path, "*.log.gz"); + var logFiles = Directory.GetFiles(_path, $"*{LogExtension}"); + var logGzFiles = Directory.GetFiles(_path, $"*{FullCompressExtension}"); + allLogFiles = logFiles.Concat(logGzFiles).ToArray(); } catch (Exception) { @@ -277,185 +281,123 @@ private bool TryGetNewStreamAndApplyRetentionPolicies(long maxFileSize, out File fileStream = null; return false; } - Array.Sort(logFiles); - Array.Sort(logGzFiles); - if (DateTime.Today != _today) - { - _today = DateTime.Today; - _dateString = LogInfo.DateToLogFormat(DateTime.Today); - } - - if (_logNumber < 0) - _logNumber = Math.Max(LastLogNumberForToday(logFiles), LastLogNumberForToday(logGzFiles)); + _today = DateTime.Today; + (_logNumber, _dateString) = GetLastLogNumberAndDateStringForToday(allLogFiles); UpdateLocalDateTimeOffset(); - string fileName; + string filePath; while (true) { - fileName = Path.Combine(_path, LogInfo.GetNewFileName(_dateString, _logNumber)); - if (File.Exists(fileName)) + var fileName = $"{_dateString}.{_logNumber:000}{LogExtension}"; + filePath = Path.Combine(_path, fileName); + if (File.Exists(filePath)) { - if(new FileInfo(fileName).Length < maxFileSize) - break; + var currentFileSize = new FileInfo(filePath).Length; + if (currentFileSize < maxFileSize) + break; // we didn't reach the size limit yet } - else if (File.Exists(LogInfo.AddCompressExtension(fileName)) == false) + else if (File.Exists($"{filePath}{AdditionalCompressExtension}") == false) { - break; + break; // check if there is compressed file with the same name } _logNumber++; } + // If compression for log files is enabled, we apply retention rules to logs inside the compressLoggingThread if (Compressing == false) - { - CleanupOldLogFiles(logFiles); - LimitLogSize(logFiles); - } + ApplyRetentionRulesToLogs(allLogFiles); - fileStream = SafeFileStream.Create(fileName, FileMode.Append, FileAccess.Write, FileShare.Read, 32 * 1024, false); + fileStream = SafeFileStream.Create(filePath, FileMode.Append, FileAccess.Write, FileShare.Read, 32 * 1024, false); fileStream.Write(_headerRow, 0, _headerRow.Length); return true; } - private void LimitLogSize(string[] logFiles) + private (string FullName, long Size) GetFileInfoSafe(string fileName) { - var logFilesInfo = logFiles.Select(f => new LogInfo(f)).ToArray(); - var totalLogSize = logFilesInfo.Sum(i => i.Size); - - long retentionSizeMinusCurrentFile = RetentionSize - MaxFileSizeInBytes; - foreach (var log in logFilesInfo) + var fileInfo = new FileInfo(fileName); + long fileSize = 0; + try { - if (totalLogSize > retentionSizeMinusCurrentFile) - { - try - { - File.Delete(log.FullName); - } - catch - { - // Something went wrong we will try again later - continue; - } - totalLogSize -= log.Size; - } - else - { - return; - } + fileSize = fileInfo.Length; } - } - - internal class LogInfo - { - public const string LogExtension = ".log"; - public const string AdditionalCompressExtension = ".gz"; - public const string FullCompressExtension = LogExtension + AdditionalCompressExtension; - private const string DateFormat = "yyyy-MM-dd"; - private static readonly int DateFormatLength = DateFormat.Length; - - public readonly string FullName; - public readonly long Size; - - public LogInfo(string fileName) + catch { - var fileInfo = new FileInfo(fileName); - FullName = fileInfo.FullName; - try - { - Size = fileInfo.Length; - } - catch - { - //Many things can happen - } + // Many things can happen } - public static bool TryGetLastWriteTimeUtc(string fileName, out DateTime dateTimeUtc) => - TryGetFileTimeInternal(fileName, File.GetLastWriteTimeUtc, out dateTimeUtc); + return (fileInfo.FullName, fileSize); + } - public static bool TryGetLastWriteTimeLocal(string fileName, out DateTime dateTimeLocal) => - TryGetFileTimeInternal(fileName, File.GetLastWriteTime, out dateTimeLocal); + internal static bool TryGetLastWriteTimeUtc(string filePath, out DateTime dateTimeUtc) => + TryGetFileTimeInternal(filePath, File.GetLastWriteTimeUtc, out dateTimeUtc); - public static bool TryGetCreationTimeUtc(string fileName, out DateTime dateTimeUtc) => - TryGetFileTimeInternal(fileName, fn => GetLogFileCreationTime(fn, DateTimeKind.Utc), out dateTimeUtc); + internal static bool TryGetLastWriteTimeLocal(string filePath, out DateTime dateTimeLocal) => + TryGetFileTimeInternal(filePath, File.GetLastWriteTime, out dateTimeLocal); - public static bool TryGetCreationTimeLocal(string fileName, out DateTime dateTimeLocal) => - TryGetFileTimeInternal(fileName, fn => GetLogFileCreationTime(fn, DateTimeKind.Local), out dateTimeLocal); + internal static bool TryGetCreationTimeUtc(string filePath, out DateTime dateTimeUtc) => + TryGetFileTimeInternal(filePath, fp => GetLogFileCreationTime(fp, DateTimeKind.Utc), out dateTimeUtc); - private static bool TryGetFileTimeInternal(string fileName, Func fileTimeGetter, out DateTime dateTime) - { - dateTime = default; - try - { - if (File.Exists(fileName) == false) - return false; + internal static bool TryGetCreationTimeLocal(string filePath, out DateTime dateTimeLocal) => + TryGetFileTimeInternal(filePath, fp => GetLogFileCreationTime(fp, DateTimeKind.Local), out dateTimeLocal); - dateTime = fileTimeGetter(fileName); - return true; - } - catch - { - // ignored - } + private static bool TryGetFileTimeInternal(string filePath, Func fileTimeGetter, out DateTime dateTime) + { + dateTime = default; + try + { + if (filePath.Contains(Path.DirectorySeparatorChar) && File.Exists(filePath) == false) + return false; - return false; + dateTime = fileTimeGetter(filePath); + return true; } - - protected internal static DateTime GetLogFileCreationTime(string fileName, DateTimeKind timeKind) + catch { - using var sr = new StreamReader(fileName); - sr.ReadLine(); - - var line = sr.ReadLine(); - if (line == null) - throw new InvalidOperationException("Log file is empty or does not contain a second line."); + // ignored + } - var commaIndex = line.IndexOf(','); - if (commaIndex <= 0) - throw new InvalidOperationException("Second line of log file does not contain a valid timestamp."); + return false; + } - var timestamp = line.Substring(0, commaIndex).Trim(); - if (DateTime.TryParse(timestamp, CultureInfo.InvariantCulture, DateTimeStyles.AssumeUniversal, out var dateTime) == false) - throw new InvalidOperationException("Unable to parse timestamp from the log file."); + internal static DateTime GetLogFileCreationTime(string filePathOrName, DateTimeKind timeKind) + { + var fileName = filePathOrName.Contains(Path.DirectorySeparatorChar) ? Path.GetFileName(filePathOrName) : filePathOrName; + var timestamp = fileName.Substring(0, fileName.IndexOf('.')); - return timeKind switch - { - DateTimeKind.Utc => UseUtcTime ? dateTime : dateTime.ToUniversalTime(), - DateTimeKind.Local => UseUtcTime ? dateTime.ToLocalTime() : dateTime, - _ => throw new ArgumentOutOfRangeException(nameof(timeKind), timeKind, null) - }; - } + if (DateTime.TryParseExact(timestamp, DateTimeWithMinutesFormat, CultureInfo.InvariantCulture, DateTimeStyles.AssumeLocal, out var dateTime) == false && + DateTime.TryParseExact(timestamp, DateOnlyFormat, CultureInfo.InvariantCulture, DateTimeStyles.AssumeLocal, out dateTime) == false) // backward compatibility + throw new InvalidOperationException($"Could not parse the log file name '{fileName}'"); - public static bool TryGetNumber(string fileName, out int n) + return timeKind switch { - n = -1; - int end = fileName.LastIndexOf(LogExtension, fileName.Length - 1, StringComparison.Ordinal); - if (end == -1) - return false; - - var start = fileName.LastIndexOf('.', end - 1); - if (start == -1) - return false; - start++; - - var logNumber = fileName.Substring(start, end - start); - return int.TryParse(logNumber, out n); - } + DateTimeKind.Utc => dateTime.ToUniversalTime(), + DateTimeKind.Local => dateTime, + _ => throw new ArgumentOutOfRangeException(nameof(timeKind), timeKind, null) + }; + } - public static string DateToLogFormat(DateTime dateTime) - { - return dateTime.ToString(DateFormat, CultureInfo.InvariantCulture); - } + internal static bool TryGetLogFileNumber(string filePathOrName, out int n) + { + n = -1; + var fileName = filePathOrName.Contains(Path.DirectorySeparatorChar) ? Path.GetFileName(filePathOrName) : filePathOrName; - public static string GetNewFileName(string dateString, int n) - { - return dateString + "." + n.ToString("000", CultureInfo.InvariantCulture) + LogExtension; - } - public static string AddCompressExtension(string dateString) - { - return dateString + AdditionalCompressExtension; - } + var firstDotIndex = fileName.IndexOf('.'); + if (firstDotIndex == -1) + return false; + + var secondDotIndex = fileName.IndexOf('.', firstDotIndex + 1); + if (secondDotIndex == -1) + return false; + + var betweenDots = fileName.Substring(firstDotIndex + 1, secondDotIndex - firstDotIndex - 1); + return int.TryParse(betweenDots, out n); + } + + internal static string DateToLogFormat(DateTime dateTime) + { + return dateTime.ToString(DateTimeWithMinutesFormat, CultureInfo.InvariantCulture); } private void UpdateLocalDateTimeOffset() @@ -468,34 +410,53 @@ private void UpdateLocalDateTimeOffset() Interlocked.Exchange(ref LocalToUtcOffsetInTicks, offset); } - private int LastLogNumberForToday(string[] files) + private static (int LogNumber, string DateString) GetLastLogNumberAndDateStringForToday(IEnumerable allLogFiles) { - for (int i = files.Length - 1; i >= 0; i--) + var now = DateTime.Now; + var todayPrefix = now.ToString(DateOnlyFormat); + + var todayLogs = allLogFiles + .Select(Path.GetFileName) + .Where(fileName => fileName.StartsWith(todayPrefix)) + .OrderBy(fileName => fileName) + .ToArray(); + + for (int i = todayLogs.Length - 1; i >= 0; i--) { - if(LogInfo.TryGetCreationTimeLocal(files[i], out var fileDate) == false || fileDate.Date.Equals(_today) == false) + if (TryGetCreationTimeLocal(todayLogs[i], out DateTime logDateTime) == false || + TryGetLogFileNumber(todayLogs[i], out var logNumber) == false) continue; - - if (LogInfo.TryGetNumber(files[i], out var n)) - return n; + + return (logNumber, DateToLogFormat(logDateTime)); } - - return 0; + + return (0, DateToLogFormat(now)); } - private void CleanupOldLogFiles(string[] logFiles) + private void ApplyRetentionRulesToLogs(string[] logFiles) { - if (RetentionTime == TimeSpan.MaxValue) + if (logFiles == null || logFiles.Length == 0) return; - foreach (var logFile in logFiles) + if (RetentionTime != TimeSpan.MaxValue) + logFiles = CleanupOldLogFiles(logFiles); + + LimitTotalLogSize(logFiles); + } + + private string[] CleanupOldLogFiles(string[] logFiles) + { + for (int i = 0; i < logFiles.Length; i++) { - if (LogInfo.TryGetLastWriteTimeLocal(logFile, out var logDateTime) == false - || DateTime.Now - logDateTime <= RetentionTime) + var logFile = logFiles[i]; + if (TryGetLastWriteTimeLocal(logFile, out var logDateTime) == false || + DateTime.Now - logDateTime <= RetentionTime) continue; try { File.Delete(logFile); + logFiles[i] = null; } catch (Exception) { @@ -503,6 +464,39 @@ private void CleanupOldLogFiles(string[] logFiles) // maybe something is currently reading the file? } } + + return logFiles.Where(file => file != null).ToArray(); + } + + private void LimitTotalLogSize(string[] logFiles) + { + if (logFiles == null) + return; + + var logFilesInfo = logFiles.Select(GetFileInfoSafe).ToArray(); + var totalLogSize = logFilesInfo.Sum(i => i.Size); + + long retentionSizeMinusCurrentFile = RetentionSize - MaxFileSizeInBytes; + foreach (var log in logFilesInfo) + { + if (totalLogSize > retentionSizeMinusCurrentFile) + { + try + { + File.Delete(log.FullName); + } + catch + { + // Something went wrong we will try again later + continue; + } + totalLogSize -= log.Size; + } + else + { + return; + } + } } private static void CleanupAlreadyCompressedLogFiles(string[] sortedLogFiles, string[] sortedLogGzFiles) @@ -533,9 +527,9 @@ private class LogComparer : IComparer public int Compare(string x, string y) { string xFileName = Path.GetFileName(x); - var xJustFileName = xFileName.Substring(0, xFileName.LastIndexOf(".log", StringComparison.Ordinal)); + var xJustFileName = xFileName.Substring(0, xFileName.LastIndexOf(LogExtension, StringComparison.Ordinal)); var yFileName = Path.GetFileName(y); - var yJustFileName = yFileName.Substring(0, yFileName.LastIndexOf(".log", StringComparison.Ordinal)); + var yJustFileName = yFileName.Substring(0, yFileName.LastIndexOf(LogExtension, StringComparison.Ordinal)); return string.CompareOrdinal(xJustFileName, yJustFileName); } } @@ -798,8 +792,8 @@ private void BackgroundLoggerCompress() string[] logGzFiles; try { - logFiles = Directory.GetFiles(_path, "*.log"); - logGzFiles = Directory.GetFiles(_path, "*.log.gz"); + logFiles = Directory.GetFiles(_path, $"*{LogExtension}"); + logGzFiles = Directory.GetFiles(_path, $"*{FullCompressExtension}"); } catch (Exception) { @@ -808,7 +802,7 @@ private void BackgroundLoggerCompress() } if (logFiles.Length <= 1) - //There is only one log file in the middle of writing + // There is only one log file in the middle of writing continue; Array.Sort(logFiles); @@ -818,21 +812,21 @@ private void BackgroundLoggerCompress() { var logFile = logFiles[i]; if (Array.BinarySearch(logGzFiles, logFile) > 0) - continue; + continue; // Already compressed try { - var newZippedFile = Path.Combine(_path, Path.GetFileNameWithoutExtension(logFile) + ".log.gz"); + var newZippedFilePath = Path.Combine(_path, Path.GetFileNameWithoutExtension(logFile) + FullCompressExtension); using (var logStream = SafeFileStream.Create(logFile, FileMode.Open, FileAccess.Read)) { - //If there is compressed file with the same name (probably due to a failure) it will be overwritten - using (var newFileStream = SafeFileStream.Create(newZippedFile, FileMode.Create, FileAccess.Write)) + // If there is compressed file with the same name (probably due to a failure) it will be overwritten + using (var newFileStream = SafeFileStream.Create(newZippedFilePath, FileMode.Create, FileAccess.Write)) using (var compressionStream = new GZipStream(newFileStream, CompressionMode.Compress)) { logStream.CopyTo(compressionStream); } } - File.SetLastWriteTime(newZippedFile, File.GetLastWriteTime(logFile)); + File.SetLastWriteTime(newZippedFilePath, File.GetLastWriteTime(logFile)); } catch (Exception) { @@ -851,10 +845,8 @@ private void BackgroundLoggerCompress() } } - Array.Sort(logGzFiles); CleanupAlreadyCompressedLogFiles(logFiles, logGzFiles); - CleanupOldLogFiles(logGzFiles); - LimitLogSize(logGzFiles); + ApplyRetentionRulesToLogs(logGzFiles); } catch (OperationCanceledException) { diff --git a/test/SlowTests/SparrowTests/LoggingSourceTests.cs b/test/SlowTests/SparrowTests/LoggingSourceTests.cs index 90a93683be29..1c8fa429ef78 100644 --- a/test/SlowTests/SparrowTests/LoggingSourceTests.cs +++ b/test/SlowTests/SparrowTests/LoggingSourceTests.cs @@ -31,10 +31,10 @@ public LoggingSourceTests(ITestOutputHelper output) : base(output) { } - [Theory] - [InlineData(true)] - [InlineData(false)] - public async Task LoggingSource_WhileRetentionByTimeInHours_ShouldKeepRetentionPolicy(bool compressing) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhileRetentionByTimeInHours_ShouldKeepRetentionPolicy(Options options, bool compressing) { const int fileSize = Constants.Size.Kilobyte; @@ -52,7 +52,7 @@ public async Task LoggingSource_WhileRetentionByTimeInHours_ShouldKeepRetentionP for (int i = 0; i < artificialLogsCount; i++) { var lastModified = now - TimeSpan.FromHours(i); - var fileName = Path.Combine(path, $"{LoggingSource.LogInfo.DateToLogFormat(lastModified)}.00{artificialLogsCount - i}.log"); + var fileName = Path.Combine(path, $"{LoggingSource.DateToLogFormat(lastModified)}.00{artificialLogsCount - i}.log"); toCheckLogFiles.Add((fileName, lastModified > retentionTime)); await using (File.Create(fileName)) { } @@ -131,14 +131,16 @@ string CreateErrorMessage() private static bool DoesContainFilesThatShouldNotBeFound(string[] exitFiles, List<(string fileName, bool shouldExist)> toCheckLogFiles, bool compressing) { return exitFiles.Any(f => toCheckLogFiles - .Any(tc => tc.shouldExist == false && (tc.fileName.Equals(f) || compressing && (tc.fileName + ".gz").Equals(f)))); + .Any(tc => tc.shouldExist == false && (tc.fileName.Equals(f) || compressing && (tc.fileName + LoggingSource.AdditionalCompressExtension).Equals(f)))); } - [Theory] - [InlineData("log")] - [InlineData("log.gz")] - public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForToday_ShouldResetNumberToZero(string extension) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForToday_ShouldResetNumberToZero(Options options, bool compressing) { + string extension = compressing ? LoggingSource.FullCompressExtension : LoggingSource.LogExtension; + var testName = GetTestName(); var path = NewDataPath(forceCreateDir: true); path = Path.Combine(path, Guid.NewGuid().ToString("N")); @@ -148,7 +150,7 @@ public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForTod var retentionTimeConfiguration = TimeSpan.FromDays(3); var yesterday = DateTime.Now - TimeSpan.FromDays(1); - var yesterdayLog = Path.Combine(path, $"{LoggingSource.LogInfo.DateToLogFormat(yesterday)}.010.{extension}"); + var yesterdayLog = Path.Combine(path, $"{LoggingSource.DateToLogFormat(yesterday)}.010{extension}"); await File.Create(yesterdayLog).DisposeAsync(); File.SetCreationTime(yesterdayLog, yesterday); @@ -167,20 +169,22 @@ public async Task LoggingSource_WhenExistFileFromYesterdayAndCreateNewFileForTod { var afterEndFiles = Directory.GetFiles(path); todayLog = afterEndFiles.FirstOrDefault(f => - LoggingSource.LogInfo.TryGetCreationTimeLocal(f, out var date) && date.Date.Equals(DateTime.Today)); + LoggingSource.TryGetCreationTimeLocal(f, out var date) && date.Date.Equals(DateTime.Today)); return todayLog != null; }, true, 10_000, 1_000); - Assert.True(LoggingSource.LogInfo.TryGetNumber(todayLog, out var n) && n == 0); + Assert.True(LoggingSource.TryGetLogFileNumber(todayLog, out var n) && n == 0); loggingSource.EndLogging(); } - [Theory] - [InlineData("log")] - [InlineData("log.gz")] - public async Task LoggingSource_WhenExistFileFromToday_ShouldIncrementNumberByOne(string extension) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhenExistFileFromThisMinute_ShouldIncrementNumberByOne(Options options, bool compressing) { + string extension = compressing ? LoggingSource.FullCompressExtension : LoggingSource.LogExtension; + const int fileSize = Constants.Size.Kilobyte; var testName = GetTestName(); @@ -192,11 +196,10 @@ public async Task LoggingSource_WhenExistFileFromToday_ShouldIncrementNumberByOn var retentionTimeConfiguration = TimeSpan.FromDays(3); var now = DateTime.Now; - var existLog = Path.Combine(path, $"{LoggingSource.LogInfo.DateToLogFormat(now)}.010.{extension}"); + var existLog = Path.Combine(path, $"{LoggingSource.DateToLogFormat(now)}.010{extension}"); await using (var file = File.Create(existLog)) - { file.SetLength(fileSize); - } + var loggingSource = new LoggingSource( LogMode.Information, path, @@ -215,10 +218,10 @@ public async Task LoggingSource_WhenExistFileFromToday_ShouldIncrementNumberByOn var strings = Directory.GetFiles(path); return strings.Any(f => { - if (LoggingSource.LogInfo.TryGetLastWriteTimeLocal(f, out var d) == false || d.Date.Equals(DateTime.Today) == false) + if (LoggingSource.TryGetLastWriteTimeLocal(f, out var d) == false || d.Date.Equals(DateTime.Today) == false) return false; - return LoggingSource.LogInfo.TryGetNumber(f, out var n) && n == 11; + return LoggingSource.TryGetLogFileNumber(f, out var n) && n == 11; }); }, true, 10_000, 1_000); Assert.True(result); @@ -226,10 +229,10 @@ public async Task LoggingSource_WhenExistFileFromToday_ShouldIncrementNumberByOn loggingSource.EndLogging(); } - [Theory] - [InlineData(true)] - [InlineData(false)] - public async Task LoggingSource_WhileRetentionByTimeInDays_ShouldKeepRetentionPolicy(bool compressing) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhileRetentionByTimeInDays_ShouldKeepRetentionPolicy(Options options, bool compressing) { const int fileSize = Constants.Size.Kilobyte; @@ -243,7 +246,7 @@ public async Task LoggingSource_WhileRetentionByTimeInDays_ShouldKeepRetentionPo var toCheckLogFiles = new List<(string fileName, bool shouldExist)>(); for (var date = retentionDate - TimeSpan.FromDays(2); date <= retentionDate + TimeSpan.FromDays(2); date += TimeSpan.FromDays(1)) { - var fileName = Path.Combine(path, $"{LoggingSource.LogInfo.DateToLogFormat(date)}.001.log"); + var fileName = Path.Combine(path, $"{LoggingSource.DateToLogFormat(date)}.001{LoggingSource.LogExtension}"); toCheckLogFiles.Add((fileName, date > retentionDate)); await using (File.Create(fileName)) { } @@ -293,7 +296,7 @@ await WaitForValueAsync(async () => Assert.All(toCheckLogFiles, toCheck => { (string fileName, bool shouldExist) = toCheck; - fileName = $"{fileName}{(compressing ? ".gz" : string.Empty)}"; + fileName = $"{fileName}{(compressing ? LoggingSource.AdditionalCompressExtension : string.Empty)}"; var fileInfo = new FileInfo(fileName); if (shouldExist) { @@ -311,10 +314,10 @@ await WaitForValueAsync(async () => } } - [Theory] - [InlineData(true)] - [InlineData(false)] - public async Task LoggingSource_WhileRetentionBySizeOn_ShouldKeepRetentionPolicy(bool compressing) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhileRetentionBySizeOn_ShouldKeepRetentionPolicy(Options options, bool compressing) { const int fileSize = Constants.Size.Kilobyte; const int retentionSize = 10 * Constants.Size.Kilobyte; @@ -329,8 +332,8 @@ public async Task LoggingSource_WhileRetentionBySizeOn_ShouldKeepRetentionPolicy "LoggingSource" + name, retentionTime, retentionSize, - compressing); - loggingSource.MaxFileSizeInBytes = fileSize; + compressing) + { MaxFileSizeInBytes = fileSize }; //This is just to make sure the MaxFileSizeInBytes is get action for the first file loggingSource.SetupLogMode(LogMode.Operations, path, retentionTime, retentionSize, compressing); @@ -390,11 +393,11 @@ private static string TempInfoToInvestigate(LoggingSource loggingSource, string using var file = fileInfo.Open(FileMode.Open, FileAccess.Read, FileShare.ReadWrite); Stream stream; - if (fileInfo.Name.EndsWith(".log.gz")) + if (fileInfo.Name.EndsWith(LoggingSource.FullCompressExtension)) { stream = new GZipStream(file, CompressionMode.Decompress); } - else if (fileInfo.Name.EndsWith(".log")) + else if (fileInfo.Name.EndsWith(LoggingSource.LogExtension)) { stream = file; } @@ -427,10 +430,10 @@ private static string TempInfoToInvestigate(LoggingSource loggingSource, string return ""; } - [Theory] - [InlineData(true)] - [InlineData(false)] - public async Task LoggingSource_WhileLogging_ShouldNotLoseLogFile(bool compressing) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhileLogging_ShouldNotLoseLogFile(Options options, bool compressing) { var name = GetTestName(); @@ -443,8 +446,8 @@ public async Task LoggingSource_WhileLogging_ShouldNotLoseLogFile(bool compressi "LoggingSource" + name, retentionTime, retentionSize, - compressing); - loggingSource.MaxFileSizeInBytes = 1024; + compressing) + { MaxFileSizeInBytes = 1024 }; //This is just to make sure the MaxFileSizeInBytes is get action for the first file loggingSource.SetupLogMode(LogMode.Operations, path, retentionTime, retentionSize, compressing); @@ -465,17 +468,17 @@ public async Task LoggingSource_WhileLogging_ShouldNotLoseLogFile(bool compressi AssertNoFileMissing(afterEndFiles); } - [Theory] - [InlineData(true)] - [InlineData(false)] - public async Task LoggingSource_WhileStopAndStartAgain_ShouldNotOverrideOld(bool compressing) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { true })] + [RavenData(Data = new object[] { false })] + public async Task LoggingSource_WhileStopAndStartAgain_ShouldNotOverrideOld(Options options, bool compressing) { const int taskTimeout = 10000; - var name = GetTestName(); + const long retentionSize = long.MaxValue; + var name = GetTestName(); var path = NewDataPath(forceCreateDir: true); var retentionTime = TimeSpan.MaxValue; - var retentionSize = long.MaxValue; var firstLoggingSource = new LoggingSource( LogMode.Information, @@ -483,8 +486,8 @@ public async Task LoggingSource_WhileStopAndStartAgain_ShouldNotOverrideOld(bool "FirstLoggingSource" + name, retentionTime, retentionSize, - compressing); - firstLoggingSource.MaxFileSizeInBytes = 1024; + compressing) + { MaxFileSizeInBytes = 1024 }; //This is just to make sure the MaxFileSizeInBytes is get action for the first file firstLoggingSource.SetupLogMode(LogMode.Operations, path, retentionTime, retentionSize, compressing); @@ -510,7 +513,7 @@ public async Task LoggingSource_WhileStopAndStartAgain_ShouldNotOverrideOld(bool var restartDateTime = DateTime.Now; Exception anotherThreadException = null; - //To start new LoggingSource the object need to be construct on another thread + // To start new LoggingSource the object need to be constructed on another thread var anotherThread = new Thread(() => { var secondLoggingSource = new LoggingSource( @@ -559,11 +562,12 @@ public async Task LoggingSource_WhileStopAndStartAgain_ShouldNotOverrideOld(bool } } - [Theory] - [InlineData(LogMode.None)] - [InlineData(LogMode.Operations)] - [InlineData(LogMode.Information)] - public async Task Register_WhenLogModeIsOperations_ShouldWriteToLogFileJustAsLogMode(LogMode logMode) + [RavenTheory(RavenTestCategory.Logging)] + + [RavenData(Data = new object[] { LogMode.None })] + [RavenData(Data = new object[] { LogMode.Operations })] + [RavenData(Data = new object[] { LogMode.Information })] + public async Task Register_WhenLogModeIsOperations_ShouldWriteToLogFileJustAsLogMode(Options options, LogMode logMode) { var timeout = TimeSpan.FromSeconds(10); @@ -623,11 +627,11 @@ public async Task Register_WhenLogModeIsOperations_ShouldWriteToLogFileJustAsLog AssertContainsLog(LogMode.Operations, logMode)(afterCloseOperation, logsFileContentAfter); } - [Theory] - [InlineData(LogMode.None)] - [InlineData(LogMode.Operations)] - [InlineData(LogMode.Information)] - public async Task AttachPipeSink_WhenLogModeIsOperations_ShouldWriteToLogFileJustOperations(LogMode logMode) + [RavenTheory(RavenTestCategory.Logging)] + [RavenData(Data = new object[] { LogMode.None })] + [RavenData(Data = new object[] { LogMode.Operations })] + [RavenData(Data = new object[] { LogMode.Information })] + public async Task AttachPipeSink_WhenLogModeIsOperations_ShouldWriteToLogFileJustOperations(Options options, LogMode logMode) { var timeout = TimeSpan.FromSeconds(10); @@ -755,184 +759,184 @@ public async Task Register_WhenLogModeIsNone_ShouldNotWriteToLogFile() [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_Created_And_Modified_Within_Date_Range(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_CreatedAndModifiedWithin_DateRange(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 00:01"; + const string endDate = "31-03-2023 23:59"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 03, 01), - LastWriteTime = new DateTime(2023, 03, 06), + CreationTime = "01-03-2023 00:01", + LastWriteTime = "06-03-2023 07:08", ShouldBeIncluded = true }, new() { - CreationTime = new DateTime(2023, 03, 07), - LastWriteTime = new DateTime(2023, 03, 29), + CreationTime = "07-03-2023 08:09", + LastWriteTime = "29-03-2023 10:11", ShouldBeIncluded = true }, new() { - CreationTime = new DateTime(2023, 03, 30), - LastWriteTime = new DateTime(2023, 03, 31), + CreationTime = "30-03-2023 12:13", + LastWriteTime = "31-03-2023 23:59", ShouldBeIncluded = true }, }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Not_Include_Files_Created_Before_And_Modified_After_Date_Range(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldNotIncludeFiles_CreatedBeforeAndModifiedAfter_DateRange(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 02:03"; + const string endDate = "31-03-2023 11:11"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 02, 01), - LastWriteTime = new DateTime(2023, 02, 27), + CreationTime = "01-02-2023 00:01", + LastWriteTime = "27-02-2023 23:59", ShouldBeIncluded = false }, new() { - CreationTime = new DateTime(2023, 02, 28), - LastWriteTime = new DateTime(2023, 03, 01), + CreationTime = "28-02-2023 23:59", + LastWriteTime = "01-03-2023 02:03", ShouldBeIncluded = false }, new() { - CreationTime = new DateTime(2023, 03, 31), - LastWriteTime = new DateTime(2023, 04, 01), + CreationTime = "31-03-2023 11:11", + LastWriteTime = "01-04-2023 23:59", ShouldBeIncluded = false }, new() { - CreationTime = new DateTime(2023, 04, 02), - LastWriteTime = new DateTime(2023, 04, 07), + CreationTime = "02-04-2023 00:01", + LastWriteTime = "07-04-2023 23:59", ShouldBeIncluded = false } }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_Created_Within_And_Modified_After_Date_Range(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_CreatedWithinAndModifiedAfter_DateRange(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 00:01"; + const string endDate = "31-03-2023 23:59"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 03, 29), - LastWriteTime = new DateTime(2023, 04, 01), + CreationTime = "29-03-2023 11:22", + LastWriteTime = "01-04-2023 22:33", ShouldBeIncluded = true }, }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_Created_Before_And_Modified_Within_Date_Range(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_CreatedBeforeAndModifiedWithin_DateRange(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 00:01"; + const string endDate = "31-03-2023 23:59"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 02, 15), - LastWriteTime = new DateTime(2023, 03, 15), + CreationTime = "15-02-2023 00:01", + LastWriteTime = "15-03-2023 23:59", ShouldBeIncluded = true }, }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_Created_Before_And_Modified_After_Date_Range(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_CreatedBeforeAndModifiedAfter_DateRange(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 00:01"; + const string endDate = "31-03-2023 23:59"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 02, 27), - LastWriteTime = new DateTime(2023, 04, 05), + CreationTime = "27-02-2023 22:22", + LastWriteTime = "05-04-2023 11:05", ShouldBeIncluded = true } }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_With_Creation_And_Modification_Dates_Matching_Exact_Date_Range(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_WithCreationAndModificationDatesMatchingExact_DateRange(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 00:01"; + const string endDate = "31-03-2023 23:59"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 03, 01), - LastWriteTime = new DateTime(2023, 03, 31), + CreationTime = "01-03-2023 00:01", + LastWriteTime = "31-03-2023 23:59", ShouldBeIncluded = true }, }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_When_No_Start_Date_Is_Specified(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_WhenNoStartDateIsSpecified(Options options, bool compressing) { // No start date specified, only end date - var endDate = new DateTime(2023, 03, 31); + const string endDate = "31-03-2023 23:58"; // List of test files with their expected inclusion based on the end date var testFiles = new List @@ -940,41 +944,41 @@ public async Task Downloading_Logs_Should_Include_Files_When_No_Start_Date_Is_Sp // Files modified before the end date should be included new() { - CreationTime = new DateTime(2023, 03, 20), - LastWriteTime = new DateTime(2023, 03, 29), + CreationTime = "20-03-2023 00:01", + LastWriteTime = "29-03-2023 23:59", ShouldBeIncluded = true }, new() { - CreationTime = new DateTime(2023, 03, 30), - LastWriteTime = new DateTime(2023, 03, 31), + CreationTime = "30-03-2023 00:01", + LastWriteTime = "31-03-2023 23:59", ShouldBeIncluded = true }, // Files modified on or after the end date should not be included new() { - CreationTime = new DateTime(2023, 03, 31), - LastWriteTime = new DateTime(2023, 04, 01), + CreationTime = "31-03-2023 23:59", + LastWriteTime = "01-04-2023 23:59", ShouldBeIncluded = false }, new() { - CreationTime = new DateTime(2023, 04, 01), - LastWriteTime = new DateTime(2023, 04, 16), + CreationTime = "01-04-2023 00:01", + LastWriteTime = "16-04-2023 23:59", ShouldBeIncluded = false }, }; - await VerifyLogDownloadByDateRange(startDate: null, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDateStr: null, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_Files_When_No_End_Date_Is_Specified(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeFiles_WhenNoEndDateIsSpecified(Options options, bool compressing) { // Only start date specified, no end date - var startDate = new DateTime(2023, 03, 01); + const string startDate = "01-03-2023 00:01"; // List of test files with their expected inclusion based on the start date var testFiles = new List @@ -982,38 +986,38 @@ public async Task Downloading_Logs_Should_Include_Files_When_No_End_Date_Is_Spec // Files modified before the start date should not be included new() { - CreationTime = new DateTime(2023, 02, 21), - LastWriteTime = new DateTime(2023, 02, 27), + CreationTime = "21-02-2023 00:01", + LastWriteTime = "27-02-2023 23:59", ShouldBeIncluded = false }, new() { - CreationTime = new DateTime(2023, 02, 28), - LastWriteTime = new DateTime(2023, 03, 01), + CreationTime ="28-02-2023 00:01", + LastWriteTime = "01-03-2023 00:00", ShouldBeIncluded = false }, // Files modified after the start date should be included new() { - CreationTime = new DateTime(2023, 03, 01), - LastWriteTime = new DateTime(2023, 03, 02), + CreationTime = "01-03-2023 00:01", + LastWriteTime = "02-03-2023 23:59", ShouldBeIncluded = true }, new() { - CreationTime = new DateTime(2023, 03, 03), - LastWriteTime = new DateTime(2023, 03, 15), + CreationTime = "03-03-2023 00:01", + LastWriteTime = "15-03-2023 23:59", ShouldBeIncluded = true }, }; - await VerifyLogDownloadByDateRange(startDate, endDate: null, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDateStr: null, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Include_All_Files_When_No_Dates_Are_Specified(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldIncludeAllFiles_WhenNoDatesAreSpecified(Options options, bool compressing) { // No start and end dates specified @@ -1023,49 +1027,49 @@ public async Task Downloading_Logs_Should_Include_All_Files_When_No_Dates_Are_Sp // All files should be included regardless of their dates new() { - CreationTime = new DateTime(2020, 03, 01), - LastWriteTime = new DateTime(2021, 03, 31), + CreationTime = "01-03-2020 12:34", + LastWriteTime = "31-03-2021 23:45", ShouldBeIncluded = true }, new() { - CreationTime = new DateTime(2022, 04, 01), - LastWriteTime = new DateTime(2023, 04, 17), + CreationTime = "01-04-2022 21:43", + LastWriteTime = "17-04-2023 23:54", ShouldBeIncluded = true } }; - await VerifyLogDownloadByDateRange(startDate: null, endDate: null, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDateStr: null, endDateStr: null, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_Should_Throw_Exception_When_EndDate_Is_Before_StartDate(Options options, bool useUtc) + public async Task DownloadingLogs_ShouldThrowException_WhenEndDateIsBeforeStartDate(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 31); - var endDate = new DateTime(2023, 03, 01); + const string startDate = "31-03-2023 00:01"; + const string endDate = "01-03-2023 23:59"; // List of test files with expected outcomes var testFiles = new List { new() { - CreationTime = new DateTime(2023, 02, 27), - LastWriteTime = new DateTime(2023, 04, 05), + CreationTime = "27-02-2023 00:01", + LastWriteTime = "05-04-2023 23:59", ShouldBeIncluded = true } }; // Run the test with the specified files and date range - var exception = await Record.ExceptionAsync(() => VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc)); + var exception = await Record.ExceptionAsync(() => VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing)); Assert.IsType(exception); Assert.IsType(exception.InnerException); var expectedMessage = - $"End Date '{endDate.ToUniversalTime():yyyy-MM-ddTHH:mm:ss.fffffff} UTC' " + - $"must be greater than Start Date '{startDate.ToUniversalTime():yyyy-MM-ddTHH:mm:ss.fffffff} UTC'"; + $"End Date '{endDate.ToUniversalTime():yyyy-MM-ddTHH:mm:ss.fffffff} UTC' must be greater than " + + $"Start Date '{startDate.ToUniversalTime():yyyy-MM-ddTHH:mm:ss.fffffff} UTC'"; Assert.True(exception.InnerException.Message.Contains(expectedMessage), userMessage:$"exception.InnerException.Message: {exception.InnerException.Message}{Environment.NewLine}" + @@ -1075,84 +1079,83 @@ public async Task Downloading_Logs_Should_Throw_Exception_When_EndDate_Is_Before [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_No_Logs_Should_Be_Selected_When_Neither_Start_Nor_End_Date_Matches(Options options, bool useUtc) + public async Task DownloadingLogs_NoLogsShouldBeSelected_WhenNeitherStartNorEndDateMatches(Options options, bool compressing) { // Define request date range - var startDate = new DateTime(2023, 03, 01); - var endDate = new DateTime(2023, 03, 31); + const string startDate = "01-03-2023 00:01"; + const string endDate = "31-03-2023 23:59"; // List of test files with expected outcomes (none should be included) var testFiles = new List { new() { - CreationTime = new DateTime(2023, 02, 27), - LastWriteTime = new DateTime(2023, 02, 28), + CreationTime = "27-02-2023 00:01", + LastWriteTime = "28-02-2023 23:59", ShouldBeIncluded = false } }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDate, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_No_Logs_Should_Be_Selected_When_Only_Start_Date_Is_Specified(Options options, bool useUtc) + public async Task DownloadingLogs_NoLogsShouldBeSelected_WhenOnlyStartDateIsSpecified(Options options, bool compressing) { // Define request date range with only start date - var startDate = new DateTime(2023, 03, 31); + const string startDate = "31-03-2023 00:01"; // List of test files with expected outcomes (none should be included) var testFiles = new List { new() { - CreationTime = new DateTime(2023, 03, 02), - LastWriteTime = new DateTime(2023, 03, 03), + CreationTime = "02-03-2023 00:01", + LastWriteTime = "03-03-2023 23:59", ShouldBeIncluded = false } }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate, endDate: null, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDate, endDateStr: null, testFiles, compressing); } [RavenTheory(RavenTestCategory.Logging)] [RavenData(Data = new object[] { true })] [RavenData(Data = new object[] { false })] - public async Task Downloading_Logs_No_Logs_Should_Be_Selected_When_Only_End_Date_Is_Specified(Options options, bool useUtc) + public async Task DownloadingLogs_NoLogsShouldBeSelected_WhenOnlyEndDateIsSpecified(Options options, bool compressing) { // Define request date range with only end date - var endDate = new DateTime(2023, 03, 01); + const string endDate = "01-03-2023 00:01"; // List of test files with expected outcomes (none should be included) var testFiles = new List { new() { - CreationTime = new DateTime(2023, 03, 05), - LastWriteTime = new DateTime(2023, 03, 25), + CreationTime = "05-03-2023 00:01", + LastWriteTime = "25-03-2023 23:59", ShouldBeIncluded = false } }; // Run the test with the specified files and date range - await VerifyLogDownloadByDateRange(startDate: null, endDate, testFiles, useUtc); + await VerifyLogDownloadByDateRange(startDateStr: null, endDate, testFiles, compressing); } - private async Task VerifyLogDownloadByDateRange(DateTime? startDate, DateTime? endDate, List testFiles, bool useUtc, [CallerMemberName] string caller = null) + private async Task VerifyLogDownloadByDateRange(string startDateStr, string endDateStr, List testFiles, bool compressing, [CallerMemberName] string caller = null) { - var path = RavenTestHelper.NewDataPath(caller, 0, forceCreateDir: true); + var path = RavenTestHelper.NewDataPath(caller, serverPort: 0, forceCreateDir: true); try { using var server = GetNewServer(new ServerCreationOptions { CustomSettings = new Dictionary { - { RavenConfiguration.GetKey(x => x.Logs.Path), path }, - { RavenConfiguration.GetKey(x => x.Logs.UseUtcTime), useUtc.ToString() }, + { RavenConfiguration.GetKey(x => x.Logs.Path), path } } }); @@ -1162,14 +1165,19 @@ private async Task VerifyLogDownloadByDateRange(DateTime? startDate, DateTime? e Assert.NotNull(testFile); Assert.True(string.IsNullOrWhiteSpace(testFile.FileName)); - testFile.FileName = $"{testFile.CreationTime:yyyy-MM-dd}.000.log"; - CreateTestFile(path, testFile, useUtc); + var extension = compressing ? LoggingSource.FullCompressExtension : LoggingSource.LogExtension; + testFile.FileName = $"{LoggingSource.DateToLogFormat(testFile.CreationTime.ToDateTime())}.000{extension}"; + + CreateTestFile(path, testFile); } // Initialize the document store and execute the download logs command using (var store = GetDocumentStore(new Options { Server = server })) using (var commands = store.Commands()) { + DateTime? startDate = string.IsNullOrWhiteSpace(startDateStr) ? null : startDateStr.ToDateTime(); + DateTime? endDate = string.IsNullOrWhiteSpace(endDateStr) ? null : endDateStr.ToDateTime(); + var command = new DownloadLogsCommand(startDate, endDate); await commands.RequestExecutor.ExecuteAsync(command, commands.Context); @@ -1199,9 +1207,9 @@ string BuildDebugInfo() sb.AppendLine("Debug info:"); sb.Append("Request from '"); - sb.Append(startDate.HasValue ? startDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"); + sb.Append(startDateStr.ToDebugDate()); sb.Append("' to '"); - sb.Append(endDate.HasValue ? endDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"); + sb.Append(endDateStr.ToDebugDate()); sb.AppendLine("'"); sb.AppendLine(); @@ -1217,7 +1225,7 @@ string BuildDebugInfo() sb.AppendLine( $" {index + 1}) " + $"FileName: {fileName}, " + - $"CreationTime: {LoggingSource.LogInfo.GetLogFileCreationTime(pathToFile, DateTimeKind.Utc)} 'UTC', " + + $"CreationTime: {LoggingSource.GetLogFileCreationTime(pathToFile, DateTimeKind.Utc)} 'UTC', " + $"LastWriteTime: {File.GetLastWriteTimeUtc(pathToFile)} 'UTC', "); } sb.AppendLine(); @@ -1229,8 +1237,8 @@ string BuildDebugInfo() sb.AppendLine( $" {index + 1}) " + $"FileName: {testFile.FileName}, " + - $"CreationTime: {testFile.CreationTime.ToUniversalTime()} 'UTC', " + - $"LastWriteTime: {testFile.LastWriteTime.ToUniversalTime()} 'UTC', " + + $"CreationTime: {testFile.CreationTime.ToDateTime().ToUniversalTime()} 'UTC', " + + $"LastWriteTime: {testFile.LastWriteTime.ToDateTime().ToUniversalTime()} 'UTC', " + $"ShouldBeIncluded: {testFile.ShouldBeIncluded}"); } sb.AppendLine(); @@ -1260,10 +1268,8 @@ string BuildDebugInfo() using (var streamReader = new StreamReader(entryStream)) { string content = await streamReader.ReadToEndAsync(); - var formattedStartUtc = startDate.HasValue ? startDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"; - var formattedEndUtc = endDate.HasValue ? endDate.Value.ToUniversalTime().ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'") : "not specified"; - Assert.Equal($"No log files were found that matched the specified date range from '{formattedStartUtc}' to '{formattedEndUtc}'.", content); + Assert.Equal($"No log files were found that matched the specified date range from '{startDateStr.ToDebugDate()}' to '{endDateStr.ToDebugDate()}'.", content); } } } @@ -1274,27 +1280,25 @@ string BuildDebugInfo() } } - private static void CreateTestFile(string path, TestFile testFile, bool useUtc) + private static void CreateTestFile(string path, TestFile testFile) { string filePath = Path.Combine(path, testFile.FileName); - var logEntryTime = useUtc - ? testFile.CreationTime.ToUniversalTime() - : testFile.CreationTime; + var logEntryTime = testFile.CreationTime.ToDateTime(); File.WriteAllText(filePath, contents: $""" Time, Thread, Level, Source, Logger, Message, Exception {logEntryTime.GetDefaultRavenFormat()}, 1, Operations, Server, Raven.Server.Program """); - File.SetLastWriteTime(filePath, testFile.LastWriteTime); + File.SetLastWriteTime(filePath, testFile.LastWriteTime.ToDateTime()); } private class TestFile { - protected internal string FileName; - protected internal DateTime CreationTime; - protected internal DateTime LastWriteTime; - protected internal bool ShouldBeIncluded; + internal string FileName; + internal string CreationTime; + internal string LastWriteTime; + internal bool ShouldBeIncluded; } private class MyDummyWebSocket : WebSocket @@ -1338,82 +1342,107 @@ public override Task SendAsync(ArraySegment buffer, WebSocketMessageType m private static string GetTestName([CallerMemberName] string memberName = "") => memberName; - private void AssertNoFileMissing(string[] files) + private void AssertNoFileMissing(string[] logFiles) { - Assert.NotEmpty(files); + Assert.NotEmpty(logFiles); var exceptions = new List(); - var list = GetLogMetadataOrderedByDateThenByNumber(files, exceptions); + var logMetadataList = GetLogMetadataOrderedByDateThenByNumber(logFiles, exceptions); - for (var i = 1; i < list.Length; i++) + for (var i = 1; i < logMetadataList.Length; i++) { - var previous = list[i - 1]; - var current = list[i]; - if (previous.Date == current.Date && previous.Number + 1 != current.Number) + var previousLogMetadata = logMetadataList[i - 1]; + var currentLogMetadata = logMetadataList[i]; + + // If the dates or numbers of the current and previous logs are not sequential, skip to the next iteration + if (previousLogMetadata.CreationTime != currentLogMetadata.CreationTime || previousLogMetadata.Number + 1 == currentLogMetadata.Number) + continue; + + // If the numbers of the current and previous logs are the same + if (previousLogMetadata.Number == currentLogMetadata.Number) { - if (previous.Number == current.Number - && ((Path.GetExtension(previous.FileName) == ".gz" && Path.GetExtension(current.FileName) == ".log") || (Path.GetExtension(previous.FileName) == ".log" && Path.GetExtension(current.FileName) == ".gz"))) - continue; + var previousLogExtension = Path.GetExtension(previousLogMetadata.FilePath); + var currentLogExtension = Path.GetExtension(currentLogMetadata.FilePath); - exceptions.Add(new Exception($"Log between {previous.FileName} and {current.FileName} is missing")); + // Check if one file is a log and the other is a compressed log + bool isOneLogAndOneCompressed = + (previousLogExtension == LoggingSource.AdditionalCompressExtension && currentLogExtension == LoggingSource.LogExtension) || + (previousLogExtension == LoggingSource.LogExtension && currentLogExtension == LoggingSource.AdditionalCompressExtension); + + // If the condition is met, skip the current iteration + if (isOneLogAndOneCompressed) + continue; } + + // If none of the above conditions are met, add an exception indicating a missing log file + exceptions.Add(new Exception($"Log between {previousLogMetadata.FilePath} and {currentLogMetadata.FilePath} is missing")); } if (exceptions.Any()) { - var allLogs = JustFileNamesAsString(files); - throw new AggregateException($"All logs - {allLogs}", exceptions); + var allLogFilesAsString = JustFileNamesAsString(logFiles); + throw new AggregateException($"All logs:{Environment.NewLine}{allLogFilesAsString}", exceptions); } } private static string JustFileNamesAsString(string[] files) { var justFileNames = files.Select(Path.GetFileName); - var logsAroundError = string.Join(',', justFileNames); + var logsAroundError = string.Join($", {Environment.NewLine}", justFileNames); return logsAroundError; } - private LogMetaData[] GetLogMetadataOrderedByDateThenByNumber(string[] files, List exceptions) + private static LogMetaData[] GetLogMetadataOrderedByDateThenByNumber(string[] filePaths, List exceptions) { - var list = files.Select(f => + return filePaths.Select(filePath => { - var withoutExtension = f.Substring(0, f.IndexOf("log", StringComparison.Ordinal) - ".".Length); - var snum = Path.GetExtension(withoutExtension).Substring(1); - if (int.TryParse(snum, out var num) == false) + if (LoggingSource.TryGetLogFileNumber(filePath, out var number) == false) { - exceptions.Add(new Exception($"incremented number of {f} can't be parsed to int")); + exceptions.Add(new Exception($"Unable to get log number from {filePath}")); return null; } - var withoutLogNumber = Path.GetFileNameWithoutExtension(withoutExtension); - var strLogDateTime = withoutLogNumber.Substring(withoutLogNumber.Length - "yyyy-MM-dd".Length, "yyyy-MM-dd".Length); - if (DateTime.TryParse(strLogDateTime, out var logDateTime) == false) - { - exceptions.Add(new Exception($"{f} can't be parsed to date format")); - return null; - } + if (LoggingSource.TryGetCreationTimeLocal(filePath, out var creationTime) || + LoggingSource.TryGetCreationTimeLocal($"{filePath}{LoggingSource.AdditionalCompressExtension}", out creationTime)) + return new LogMetaData + { + FilePath = filePath, + CreationTime = creationTime, + Number = number + }; + + exceptions.Add(new Exception($"Unable to get creation time from {filePath}")); + return null; - return new LogMetaData - { - FileName = f, - Date = logDateTime, - Number = num - }; }) - .Where(f => f != null) - .OrderBy(f => f.Date) - .ThenBy(f => f.Number) + .Where(logMetaData => logMetaData != null) + .OrderBy(logMetaData => logMetaData.CreationTime) + .ThenBy(logMetaData => logMetaData.Number) .ToArray(); - - return list; } private class LogMetaData { - public string FileName { set; get; } - public DateTime Date { set; get; } + public string FilePath { set; get; } + public DateTime CreationTime { set; get; } public int Number { set; get; } } } + + internal static class LoggingSourceTestExtensions + { + internal static DateTime ToDateTime(this string date, string format = "dd-MM-yyyy HH:mm") => + DateTime.ParseExact(date, format, CultureInfo.InvariantCulture); + + internal static DateTime ToUniversalTime(this string date, string format = "dd-MM-yyyy HH:mm") => + date.ToDateTime(format).ToUniversalTime(); + + internal static string ToDebugDate(this string date, string format = "dd-MM-yyyy HH:mm") => + date == null + ? "not specified" + : date + .ToUniversalTime(format) + .ToString("yyyy-MM-ddTHH:mm:ss.fffffff 'UTC'", CultureInfo.InvariantCulture); + } } diff --git a/test/SlowTests/Tests/TestsInheritanceTests.cs b/test/SlowTests/Tests/TestsInheritanceTests.cs index d2c933a250d0..c7ab55f7d90a 100644 --- a/test/SlowTests/Tests/TestsInheritanceTests.cs +++ b/test/SlowTests/Tests/TestsInheritanceTests.cs @@ -88,7 +88,7 @@ where Filter(method) select method; var array = types.ToArray(); - const int numberToTolerate = 6431; + const int numberToTolerate = 6421; if (array.Length == numberToTolerate) return; From bbbb3dd1fdcc39c1d89376300e93e904aff29749 Mon Sep 17 00:00:00 2001 From: Lev Skuditsky Date: Wed, 17 Apr 2024 17:33:46 +0300 Subject: [PATCH 06/27] RavenDB-21718: PR comments --- .../Documents/Handlers/Admin/AdminLogsHandler.cs | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs index c440f8e9efee..734e4012a84d 100644 --- a/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs +++ b/src/Raven.Server/Documents/Handlers/Admin/AdminLogsHandler.cs @@ -127,6 +127,8 @@ public async Task Download() { using (var archive = new ZipArchive(stream, ZipArchiveMode.Create, true)) { + bool isEmptyArchive = true; + foreach (var filePath in Directory.GetFiles(ServerStore.Configuration.Logs.Path.FullPath)) { var fileName = Path.GetFileName(filePath); @@ -160,6 +162,8 @@ public async Task Download() { await fs.CopyToAsync(entryStream); } + + isEmptyArchive = false; } } catch (Exception e) @@ -167,14 +171,10 @@ public async Task Download() await DebugInfoPackageUtils.WriteExceptionAsZipEntryAsync(e, archive, fileName); } } - } - // Add an informational file to the archive if no log files match the specified date range, - // ensuring the user receives a non-empty archive with an explanation. - using (var archive = new ZipArchive(stream, ZipArchiveMode.Update, true)) - { - // Check if any file was added to the zip - if (archive.Entries.Count == 0) + // Add an informational file to the archive if no log files match the specified date range, + // ensuring the user receives a non-empty archive with an explanation. + if (isEmptyArchive) { const string infoFileName = "No logs matched the date range.txt"; From a2f0618c9745d732059b738ce779dadd9d053a36 Mon Sep 17 00:00:00 2001 From: Lev Skuditsky Date: Tue, 30 Apr 2024 16:27:49 +0300 Subject: [PATCH 07/27] RavenDB-21718: Sort files before ApplyRetentionRulesToLogs --- src/Sparrow/Logging/LoggingSource.cs | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/Sparrow/Logging/LoggingSource.cs b/src/Sparrow/Logging/LoggingSource.cs index 2bec161763f8..349aa62211ef 100644 --- a/src/Sparrow/Logging/LoggingSource.cs +++ b/src/Sparrow/Logging/LoggingSource.cs @@ -307,7 +307,10 @@ private bool TryGetNewStreamAndApplyRetentionPolicies(long maxFileSize, out File // If compression for log files is enabled, we apply retention rules to logs inside the compressLoggingThread if (Compressing == false) + { + Array.Sort(allLogFiles); ApplyRetentionRulesToLogs(allLogFiles); + } fileStream = SafeFileStream.Create(filePath, FileMode.Append, FileAccess.Write, FileShare.Read, 32 * 1024, false); fileStream.Write(_headerRow, 0, _headerRow.Length); From 8d4393113b330d376f89540db55b1ef5825991a3 Mon Sep 17 00:00:00 2001 From: Grisha Kotler Date: Fri, 19 Apr 2024 13:09:17 +0300 Subject: [PATCH 08/27] RavenDB-22305 - Missing DirtyMemory from the memory notification --- .../MemoryUsageNotificationSender.cs | 2 +- .../Handlers/Debugging/MemoryDebugHandler.cs | 7 ++-- .../Documents/TransactionOperationsMerger.cs | 2 +- .../Monitoring/MetricsProvider.cs | 3 +- .../Objects/Server/1.6/ServerDirtyMemory.cs | 3 +- .../OutOfMemoryNotifications.cs | 2 +- src/Raven.Server/Utils/Cli/RavenCli.cs | 6 ++-- .../LowMemory/MemoryInformation.cs | 12 +++---- src/Sparrow/LowMemory/DirtyMemoryState.cs | 2 +- .../LowMemory/LowMemoryNotification.cs | 34 ++++++------------- src/Sparrow/LowMemory/MemoryInfoResult.cs | 1 - src/Sparrow/Utils/MemoryUtils.cs | 4 +-- .../TestMetrics/TestResourceSnapshotWriter.cs | 9 ++--- 13 files changed, 35 insertions(+), 52 deletions(-) diff --git a/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs b/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs index 5feca3b6ac5c..1d211744e6a2 100644 --- a/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs +++ b/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs @@ -57,7 +57,7 @@ protected override AbstractClusterDashboardNotification CreateNotification() EncryptionBuffersInUse = encryptionBuffers.CurrentlyInUseSize, EncryptionBuffersPool = encryptionBuffers.TotalPoolSize, MemoryMapped = totalMapping, - DirtyMemory = dirtyMemoryState.TotalDirtyInBytes, + DirtyMemory = dirtyMemoryState.TotalDirty.GetValue(SizeUnit.Bytes), AvailableMemory = memoryInfo.AvailableMemory.GetValue(SizeUnit.Bytes), AvailableMemoryForProcessing = memoryInfo.AvailableMemoryForProcessing.GetValue(SizeUnit.Bytes), TotalSwapUsage = memoryInfo.TotalSwapUsage.GetValue(SizeUnit.Bytes) diff --git a/src/Raven.Server/Documents/Handlers/Debugging/MemoryDebugHandler.cs b/src/Raven.Server/Documents/Handlers/Debugging/MemoryDebugHandler.cs index 61e9f2598e48..dadf4a86e490 100644 --- a/src/Raven.Server/Documents/Handlers/Debugging/MemoryDebugHandler.cs +++ b/src/Raven.Server/Documents/Handlers/Debugging/MemoryDebugHandler.cs @@ -9,13 +9,11 @@ using Raven.Server.Routing; using Raven.Server.Utils; using Raven.Server.Web; -using Sparrow; using Sparrow.Json; using Sparrow.Json.Parsing; using Sparrow.LowMemory; using Sparrow.Platform; using Sparrow.Platform.Posix; -using Sparrow.Server; using Sparrow.Server.Platform.Win32; using Sparrow.Utils; using Voron.Impl; @@ -331,10 +329,9 @@ private static void WriteMemoryStats(AsyncBlittableJsonTextWriter writer, JsonOp [nameof(MemoryInfo.EncryptionBuffersPool)] = Size.Humane(encryptionBuffers.TotalPoolSize), [nameof(MemoryInfo.EncryptionLockedMemory)] = Size.Humane(Sodium.LockedBytes), [nameof(MemoryInfo.MemoryMapped)] = Size.Humane(totalMapping), - [nameof(MemoryInfo.ScratchDirtyMemory)] = memInfo.TotalScratchDirtyMemory.ToString(), [nameof(MemoryInfo.IsHighDirty)] = dirtyMemoryState.IsHighDirty, - [nameof(MemoryInfo.DirtyMemory)] = Size.Humane(dirtyMemoryState.TotalDirtyInBytes), - [nameof(MemoryInfo.AvailableMemory)] = Size.Humane(memInfo.AvailableMemory.GetValue(SizeUnit.Bytes)), + [nameof(MemoryInfo.DirtyMemory)] = dirtyMemoryState.TotalDirty.ToString(), + [nameof(MemoryInfo.AvailableMemory)] = memInfo.AvailableMemory.ToString(), [nameof(MemoryInfo.AvailableMemoryForProcessing)] = memInfo.AvailableMemoryForProcessing.ToString(), }; if (memInfo.Remarks != null) diff --git a/src/Raven.Server/Documents/TransactionOperationsMerger.cs b/src/Raven.Server/Documents/TransactionOperationsMerger.cs index 9e3715eb4115..94756343915e 100644 --- a/src/Raven.Server/Documents/TransactionOperationsMerger.cs +++ b/src/Raven.Server/Documents/TransactionOperationsMerger.cs @@ -882,7 +882,7 @@ private PendingOperations ExecutePendingOperationsInTransaction( $"Operation was cancelled by the transaction merger for transaction #{llt.Id} due to high dirty memory in scratch files." + $" This might be caused by a slow IO storage. Current memory usage: " + $"Total Physical Memory: {MemoryInformation.TotalPhysicalMemory}, " + - $"Total Scratch Allocated Memory: {new Size(dirtyMemoryState.TotalDirtyInBytes, SizeUnit.Bytes)} " + + $"Total Scratch Allocated Memory: {dirtyMemoryState.TotalDirty} " + $"(which is above {_parent.Configuration.Memory.TemporaryDirtyMemoryAllowedPercentage * 100}%)"); } diff --git a/src/Raven.Server/Monitoring/MetricsProvider.cs b/src/Raven.Server/Monitoring/MetricsProvider.cs index 8359d02dfbdf..b8ee18ab325d 100644 --- a/src/Raven.Server/Monitoring/MetricsProvider.cs +++ b/src/Raven.Server/Monitoring/MetricsProvider.cs @@ -154,8 +154,7 @@ private MemoryMetrics GetMemoryMetrics() result.TotalSwapUsageInMb = memoryInfoResult.TotalSwapUsage.GetValue(SizeUnit.Megabytes); result.WorkingSetSwapUsageInMb = memoryInfoResult.WorkingSetSwapUsage.GetValue(SizeUnit.Megabytes); - var totalDirtyInBytes = MemoryInformation.GetDirtyMemoryState().TotalDirtyInBytes; - result.TotalDirtyInMb = new Size(totalDirtyInBytes, SizeUnit.Bytes).GetValue(SizeUnit.Megabytes); + result.TotalDirtyInMb = MemoryInformation.GetDirtyMemoryState().TotalDirty.GetValue(SizeUnit.Megabytes); return result; } diff --git a/src/Raven.Server/Monitoring/Snmp/Objects/Server/1.6/ServerDirtyMemory.cs b/src/Raven.Server/Monitoring/Snmp/Objects/Server/1.6/ServerDirtyMemory.cs index 63195b4bda12..59c2a4921776 100644 --- a/src/Raven.Server/Monitoring/Snmp/Objects/Server/1.6/ServerDirtyMemory.cs +++ b/src/Raven.Server/Monitoring/Snmp/Objects/Server/1.6/ServerDirtyMemory.cs @@ -13,8 +13,7 @@ public ServerDirtyMemory() : base(SnmpOids.Server.DirtyMemory) protected override Gauge32 GetData() { - var totalDirtyInBytes = MemoryInformation.GetDirtyMemoryState().TotalDirtyInBytes; - return new Gauge32(new Size(totalDirtyInBytes, SizeUnit.Bytes).GetValue(SizeUnit.Megabytes)); + return new Gauge32(MemoryInformation.GetDirtyMemoryState().TotalDirty.GetValue(SizeUnit.Megabytes)); } } } diff --git a/src/Raven.Server/NotificationCenter/OutOfMemoryNotifications.cs b/src/Raven.Server/NotificationCenter/OutOfMemoryNotifications.cs index caaa8b8e65b2..2bb11704a3e0 100644 --- a/src/Raven.Server/NotificationCenter/OutOfMemoryNotifications.cs +++ b/src/Raven.Server/NotificationCenter/OutOfMemoryNotifications.cs @@ -76,7 +76,7 @@ private static MessageDetails OutOfMemoryDetails(Exception exception) return new MessageDetails { - Message = $"{MemoryUtils.GetExtendedMemoryInfo(memoryInfo)} {Environment.NewLine}" + + Message = $"{MemoryUtils.GetExtendedMemoryInfo(memoryInfo, MemoryInformation.GetDirtyMemoryState())} {Environment.NewLine}" + $"Error: {exception}" }; } diff --git a/src/Raven.Server/Utils/Cli/RavenCli.cs b/src/Raven.Server/Utils/Cli/RavenCli.cs index 405039c3b3b5..bf1c5dd15860 100644 --- a/src/Raven.Server/Utils/Cli/RavenCli.cs +++ b/src/Raven.Server/Utils/Cli/RavenCli.cs @@ -584,13 +584,15 @@ private static bool CommandInfo(List args, RavenCli cli) public static string GetInfoText() { var memoryInfo = MemoryInformation.GetMemoryInformationUsingOneTimeSmapsReader(); + var dirtyMemoryState = MemoryInformation.GetDirtyMemoryState(); + using (var currentProcess = Process.GetCurrentProcess()) { return $" Build {ServerVersion.Build}, Version {ServerVersion.Version}, SemVer {ServerVersion.FullVersion}, Commit {ServerVersion.CommitHash}" + Environment.NewLine + $" PID {currentProcess.Id}, {IntPtr.Size * 8} bits, {ProcessorInfo.ProcessorCount} Cores, Arch: {RuntimeInformation.OSArchitecture}" + Environment.NewLine + - $" {memoryInfo.TotalPhysicalMemory} Physical Memory, {memoryInfo.AvailableMemory} Available Memory, {memoryInfo.AvailableMemoryForProcessing} Calculated Available Memory, {memoryInfo.TotalScratchDirtyMemory} Scratch Dirty Memory" + + $" {memoryInfo.TotalPhysicalMemory} Physical Memory, {memoryInfo.AvailableMemory} Available Memory, {memoryInfo.AvailableMemoryForProcessing} Calculated Available Memory, {dirtyMemoryState.TotalDirty} Scratch Dirty Memory" + Environment.NewLine + $" {RuntimeSettings.Describe()}" + Environment.NewLine + @@ -1118,7 +1120,7 @@ public static ( SizeClient.Humane(MemoryInformation.GetWorkingSetInBytes()), SizeClient.Humane(AbstractLowMemoryMonitor.GetUnmanagedAllocationsInBytes()), SizeClient.Humane(AbstractLowMemoryMonitor.GetManagedMemoryInBytes()), - SizeClient.Humane(MemoryInformation.GetTotalScratchAllocatedMemory()), + SizeClient.Humane(MemoryInformation.GetTotalScratchAllocatedMemoryInBytes()), SizeClient.Humane(totalMemoryMapped)); } diff --git a/src/Sparrow.Server/LowMemory/MemoryInformation.cs b/src/Sparrow.Server/LowMemory/MemoryInformation.cs index debe5476984e..801a99e7386b 100644 --- a/src/Sparrow.Server/LowMemory/MemoryInformation.cs +++ b/src/Sparrow.Server/LowMemory/MemoryInformation.cs @@ -179,7 +179,7 @@ private static void ThrowInsufficientMemory(MemoryInfoResult memInfo) LowMemoryNotification.Instance.SimulateLowMemoryNotification(); throw new EarlyOutOfMemoryException($"The amount of available memory to commit on the system is low. " + - MemoryUtils.GetExtendedMemoryInfo(memInfo), memInfo); + MemoryUtils.GetExtendedMemoryInfo(memInfo, GetDirtyMemoryState()), memInfo); } @@ -423,7 +423,7 @@ internal static MemoryInfoResult GetMemoryInfo(SmapsReader smapsReader = null, b } } - public static long GetTotalScratchAllocatedMemory() + public static long GetTotalScratchAllocatedMemoryInBytes() { long totalScratchAllocated = 0; foreach (var scratchGetAllocated in DirtyMemoryObjects) @@ -740,13 +740,13 @@ public static long GetWorkingSetInBytes() public static DirtyMemoryState GetDirtyMemoryState() { - var totalScratchMemory = GetTotalScratchAllocatedMemory(); + var totalScratchMemory = new Size(GetTotalScratchAllocatedMemoryInBytes(), SizeUnit.Bytes); return new DirtyMemoryState { - IsHighDirty = totalScratchMemory > TotalPhysicalMemory.GetValue(SizeUnit.Bytes) * - LowMemoryNotification.Instance.TemporaryDirtyMemoryAllowedPercentage, - TotalDirtyInBytes = totalScratchMemory + IsHighDirty = totalScratchMemory > + TotalPhysicalMemory * LowMemoryNotification.Instance.TemporaryDirtyMemoryAllowedPercentage, + TotalDirty = totalScratchMemory }; } } diff --git a/src/Sparrow/LowMemory/DirtyMemoryState.cs b/src/Sparrow/LowMemory/DirtyMemoryState.cs index 6cb17f201c1f..0b241fa4ce20 100644 --- a/src/Sparrow/LowMemory/DirtyMemoryState.cs +++ b/src/Sparrow/LowMemory/DirtyMemoryState.cs @@ -4,6 +4,6 @@ public class DirtyMemoryState { public bool IsHighDirty; - public long TotalDirtyInBytes; + public Size TotalDirty; } } diff --git a/src/Sparrow/LowMemory/LowMemoryNotification.cs b/src/Sparrow/LowMemory/LowMemoryNotification.cs index c3c7d25206be..144b41fce9aa 100644 --- a/src/Sparrow/LowMemory/LowMemoryNotification.cs +++ b/src/Sparrow/LowMemory/LowMemoryNotification.cs @@ -64,7 +64,7 @@ private void RunLowMemoryHandlers(bool isLowMemory, MemoryInfoResult memoryInfo, { _lastLoggedLowMemory = now; _logger.Operations($"Running {_lowMemoryHandlers.Count} low memory handlers with severity: {lowMemorySeverity}. " + - $"{MemoryUtils.GetExtendedMemoryInfo(memoryInfo)}"); + $"{MemoryUtils.GetExtendedMemoryInfo(memoryInfo, _lowMemoryMonitor.GetDirtyMemoryState())}"); } #if NET7_0_OR_GREATER @@ -313,14 +313,9 @@ private void SimulateLowMemory() if (_lowMemoryMonitor != null) { memInfoForLog = _lowMemoryMonitor.GetMemoryInfoOnce(); - var availableMemForLog = memInfoForLog.AvailableMemoryForProcessing.GetValue(SizeUnit.Bytes); AddLowMemEvent(LowMemoryState ? LowMemReason.LowMemStateSimulation : LowMemReason.BackToNormalSimulation, - availableMemForLog, - -2, - memInfoForLog.TotalScratchDirtyMemory.GetValue(SizeUnit.Bytes), - memInfoForLog.TotalPhysicalMemory.GetValue(SizeUnit.Bytes), - memInfoForLog.CurrentCommitCharge.GetValue(SizeUnit.Bytes)); + memInfoForLog, totalUnmanaged: -2); } if (_logger.IsInfoEnabled) @@ -362,12 +357,7 @@ internal int CheckMemoryStatus(AbstractLowMemoryMonitor monitor) _logger.Info("Low memory detected, will try to reduce memory usage..."); } - AddLowMemEvent(LowMemReason.LowMemOnTimeoutChk, - memoryInfo.AvailableMemory.GetValue(SizeUnit.Bytes), - totalUnmanagedAllocations, - memoryInfo.TotalScratchDirtyMemory.GetValue(SizeUnit.Bytes), - memoryInfo.TotalPhysicalMemory.GetValue(SizeUnit.Bytes), - memoryInfo.CurrentCommitCharge.GetValue(SizeUnit.Bytes)); + AddLowMemEvent(LowMemReason.LowMemOnTimeoutChk, memoryInfo, totalUnmanagedAllocations); } catch (OutOfMemoryException) { @@ -392,12 +382,8 @@ internal int CheckMemoryStatus(AbstractLowMemoryMonitor monitor) { if (_logger.IsInfoEnabled) _logger.Info("Back to normal memory usage detected"); - AddLowMemEvent(LowMemReason.BackToNormal, - memoryInfo.AvailableMemory.GetValue(SizeUnit.Bytes), - totalUnmanagedAllocations, - memoryInfo.TotalScratchDirtyMemory.GetValue(SizeUnit.Bytes), - memoryInfo.TotalPhysicalMemory.GetValue(SizeUnit.Bytes), - memoryInfo.CurrentCommitCharge.GetValue(SizeUnit.Bytes)); + + AddLowMemEvent(LowMemReason.BackToNormal, memoryInfo, totalUnmanagedAllocations); } LowMemoryState = false; RunLowMemoryHandlers(false, memoryInfo, isLowMemory); @@ -454,17 +440,17 @@ private LowMemorySeverity IsAvailableMemoryBelowThreshold(MemoryInfoResult memIn return LowMemorySeverity.None; } - private void AddLowMemEvent(LowMemReason reason, long availableMem, long totalUnmanaged, long totalScratchDirty, long physicalMem, long currentcommitCharge) + private void AddLowMemEvent(LowMemReason reason, MemoryInfoResult memoryInfo, long totalUnmanaged) { var lowMemEventDetails = new LowMemEventDetails { Reason = reason, - FreeMem = availableMem, + FreeMem = memoryInfo.AvailableMemoryForProcessing.GetValue(SizeUnit.Bytes), TotalUnmanaged = totalUnmanaged, - TotalScratchDirty = totalScratchDirty, - PhysicalMem = physicalMem, + TotalScratchDirty = _lowMemoryMonitor.GetDirtyMemoryState().TotalDirty.GetValue(SizeUnit.Bytes), + PhysicalMem = memoryInfo.TotalPhysicalMemory.GetValue(SizeUnit.Bytes), LowMemThreshold = LowMemoryThreshold.GetValue(SizeUnit.Bytes), - CurrentCommitCharge = currentcommitCharge, + CurrentCommitCharge = memoryInfo.CurrentCommitCharge.GetValue(SizeUnit.Bytes), Time = DateTime.UtcNow }; diff --git a/src/Sparrow/LowMemory/MemoryInfoResult.cs b/src/Sparrow/LowMemory/MemoryInfoResult.cs index fb668eb966e0..3f1d608d47fb 100644 --- a/src/Sparrow/LowMemory/MemoryInfoResult.cs +++ b/src/Sparrow/LowMemory/MemoryInfoResult.cs @@ -29,7 +29,6 @@ public class MemoryUsageLowHigh public Size AvailableMemory; public Size AvailableMemoryForProcessing; public Size SharedCleanMemory; - public Size TotalScratchDirtyMemory; public Size TotalSwapSize; public Size TotalSwapUsage; diff --git a/src/Sparrow/Utils/MemoryUtils.cs b/src/Sparrow/Utils/MemoryUtils.cs index eb4914db469f..8b32281680aa 100644 --- a/src/Sparrow/Utils/MemoryUtils.cs +++ b/src/Sparrow/Utils/MemoryUtils.cs @@ -11,7 +11,7 @@ public static class MemoryUtils private static readonly InvertedComparer InvertedComparerInstance = new InvertedComparer(); private const int MinAllocatedThresholdInBytes = 10 * 1024 * 1024; - public static string GetExtendedMemoryInfo(MemoryInfoResult memoryInfo) + public static string GetExtendedMemoryInfo(MemoryInfoResult memoryInfo, DirtyMemoryState dirtyState) { try { @@ -19,7 +19,7 @@ public static string GetExtendedMemoryInfo(MemoryInfoResult memoryInfo) TryAppend(() => sb.Append("Commit charge: ").Append(memoryInfo.CurrentCommitCharge).Append(" / ").Append(memoryInfo.TotalCommittableMemory).Append(", ")); TryAppend(() => sb.Append("Memory: ").Append(memoryInfo.TotalPhysicalMemory - memoryInfo.AvailableMemory).Append(" / ").Append(memoryInfo.TotalPhysicalMemory).Append(", ")); TryAppend(() => sb.Append("Available memory for processing: ").Append(memoryInfo.AvailableMemoryForProcessing).Append(", ")); - TryAppend(() => sb.Append("Dirty memory: ").Append(memoryInfo.TotalScratchDirtyMemory).Append(", ")); + TryAppend(() => sb.Append("Dirty memory: ").Append(dirtyState.TotalDirty).Append(", ")); TryAppend(() => sb.Append("Managed memory: ").Append(new Size(AbstractLowMemoryMonitor.GetManagedMemoryInBytes(), SizeUnit.Bytes)).Append(", ")); TryAppend(() => sb.Append("Unmanaged allocations: ").Append(new Size(AbstractLowMemoryMonitor.GetUnmanagedAllocationsInBytes(), SizeUnit.Bytes)).Append(", ")); TryAppend(() => sb.Append("Lucene managed: ").Append(new Size(NativeMemory.TotalLuceneManagedAllocationsForTermCache, SizeUnit.Bytes)).Append(", ")); diff --git a/test/Tests.Infrastructure/TestMetrics/TestResourceSnapshotWriter.cs b/test/Tests.Infrastructure/TestMetrics/TestResourceSnapshotWriter.cs index 33eed912faa5..d604b61561ee 100644 --- a/test/Tests.Infrastructure/TestMetrics/TestResourceSnapshotWriter.cs +++ b/test/Tests.Infrastructure/TestMetrics/TestResourceSnapshotWriter.cs @@ -79,12 +79,13 @@ private TestResourceSnapshot GetTestResourceSnapshot(TestStage testStage, IAssem var cpuUsage = _metricCacher.GetCpuUsage(); var memoryInfo = _metricCacher.GetMemoryInfoExtended(); var tcpConnections = TcpStatisticsProvider.GetConnections(); + var dirtyMemoryState = MemoryInformation.GetDirtyMemoryState(); var snapshot = new TestResourceSnapshot { - TotalScratchAllocatedMemory = new Size(MemoryInformation.GetTotalScratchAllocatedMemory(), SizeUnit.Bytes).GetValue(SizeUnit.Megabytes), - TotalDirtyMemory = new Size(MemoryInformation.GetDirtyMemoryState().TotalDirtyInBytes, SizeUnit.Bytes).GetValue(SizeUnit.Megabytes), - IsHighDirty = MemoryInformation.GetDirtyMemoryState().IsHighDirty, + TotalScratchAllocatedMemory = new Size(MemoryInformation.GetTotalScratchAllocatedMemoryInBytes(), SizeUnit.Bytes).GetValue(SizeUnit.Megabytes), + TotalDirtyMemory = dirtyMemoryState.TotalDirty.GetValue(SizeUnit.Megabytes), + IsHighDirty = dirtyMemoryState.IsHighDirty, TestStage = testStage, Timestamp = timeStamp.ToString("o"), AssemblyName = assemblyName, @@ -96,7 +97,7 @@ private TestResourceSnapshot GetTestResourceSnapshot(TestStage testStage, IAssem AvailableMemoryInMb = memoryInfo.AvailableMemory.GetValue(SizeUnit.Megabytes), CurrentCommitChargeInMb = memoryInfo.CurrentCommitCharge.GetValue(SizeUnit.Megabytes), SharedCleanMemoryInMb = memoryInfo.SharedCleanMemory.GetValue(SizeUnit.Megabytes), - TotalScratchDirtyMemory = memoryInfo.TotalScratchDirtyMemory.GetValue(SizeUnit.Megabytes), + TotalScratchDirtyMemory = MemoryInformation.GetDirtyMemoryState().TotalDirty.GetValue(SizeUnit.Megabytes), CurrentIpv4Connections = tcpConnections.CurrentIpv4, CurrentIpv6Connections = tcpConnections.CurrentIpv6 }; From d10ec7315391deae6b12b94fb18cfe2993892025 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Thu, 25 Apr 2024 10:22:03 +0200 Subject: [PATCH 09/27] RavenDB-22313 Checking cancellation token during the load phase of Elasticsearch, Kafka and RabbitMQ ETLs. This should prevent the long running disposals of those tasks. --- .../Documents/ETL/Providers/Elasticsearch/ElasticSearchEtl.cs | 2 ++ .../Documents/ETL/Providers/Queue/Kafka/KafkaEtl.cs | 2 ++ .../Documents/ETL/Providers/Queue/RabbitMq/RabbitMqEtl.cs | 2 ++ 3 files changed, 6 insertions(+) diff --git a/src/Raven.Server/Documents/ETL/Providers/Elasticsearch/ElasticSearchEtl.cs b/src/Raven.Server/Documents/ETL/Providers/Elasticsearch/ElasticSearchEtl.cs index 467003f6d583..9932420feee1 100644 --- a/src/Raven.Server/Documents/ETL/Providers/Elasticsearch/ElasticSearchEtl.cs +++ b/src/Raven.Server/Documents/ETL/Providers/Elasticsearch/ElasticSearchEtl.cs @@ -109,6 +109,8 @@ protected override int LoadInternal(IEnumerable r EnsureIndexExistsAndValidateIfNeeded(indexName, index); + CancellationToken.ThrowIfCancellationRequested(); + if (index.InsertOnlyMode == false) count += DeleteByQueryOnIndexIdProperty(index); diff --git a/src/Raven.Server/Documents/ETL/Providers/Queue/Kafka/KafkaEtl.cs b/src/Raven.Server/Documents/ETL/Providers/Queue/Kafka/KafkaEtl.cs index 68da0749d2ac..7001b3a718e6 100644 --- a/src/Raven.Server/Documents/ETL/Providers/Queue/Kafka/KafkaEtl.cs +++ b/src/Raven.Server/Documents/ETL/Providers/Queue/Kafka/KafkaEtl.cs @@ -159,6 +159,8 @@ void ReportHandler(DeliveryReport report) { foreach (var queueItem in topic.Items) { + CancellationToken.ThrowIfCancellationRequested(); + var cloudEvent = CreateCloudEvent(queueItem); var kafkaMessage = cloudEvent.ToKafkaMessage(ContentMode.Binary, formatter); diff --git a/src/Raven.Server/Documents/ETL/Providers/Queue/RabbitMq/RabbitMqEtl.cs b/src/Raven.Server/Documents/ETL/Providers/Queue/RabbitMq/RabbitMqEtl.cs index d3b47a00162d..50d700cdc06e 100644 --- a/src/Raven.Server/Documents/ETL/Providers/Queue/RabbitMq/RabbitMqEtl.cs +++ b/src/Raven.Server/Documents/ETL/Providers/Queue/RabbitMq/RabbitMqEtl.cs @@ -67,6 +67,8 @@ protected override int PublishMessages(List> itemsP foreach (var queueItem in exchange.Items) { + CancellationToken.ThrowIfCancellationRequested(); + var properties = producer.CreateBasicProperties(); properties.Headers = new Dictionary(); From 2d85a5e3ecce46738313798fe4f7fbbf53b2a401 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Thu, 25 Apr 2024 15:04:09 +0200 Subject: [PATCH 10/27] RavenDB-21768 Making sure that we'll wait for a task which is using the context before returning the context to the pool --- .../Documents/Operations/Operation.cs | 42 ++++++++++++------- 1 file changed, 28 insertions(+), 14 deletions(-) diff --git a/src/Raven.Client/Documents/Operations/Operation.cs b/src/Raven.Client/Documents/Operations/Operation.cs index 91a07df9673e..6454710454ac 100644 --- a/src/Raven.Client/Documents/Operations/Operation.cs +++ b/src/Raven.Client/Documents/Operations/Operation.cs @@ -338,29 +338,43 @@ public async Task WaitForCompletionAsync(CancellationToken tok { var result = await InitializeResult().ConfigureAwait(false); - _ = Task.Factory.StartNew(Initialize); + var initTask = Task.Factory.StartNew(Initialize); try { + try + { #if NET6_0_OR_GREATER - await result.WaitAsync(token).ConfigureAwait(false); - await _afterOperationCompleted.WaitAsync(token).ConfigureAwait(false); + await result.WaitAsync(token).ConfigureAwait(false); + await _afterOperationCompleted.WaitAsync(token).ConfigureAwait(false); #else - await result.WithCancellation(token).ConfigureAwait(false); - await _afterOperationCompleted.WithCancellation(token).ConfigureAwait(false); + await result.WithCancellation(token).ConfigureAwait(false); + await _afterOperationCompleted.WithCancellation(token).ConfigureAwait(false); #endif + } + catch (TaskCanceledException e) when (token.IsCancellationRequested) + { + await StopProcessingUnderLock().ConfigureAwait(false); + throw new TimeoutException($"Did not get a reply for operation '{_id}'.", e); + } + catch (Exception ex) + { + await StopProcessingUnderLock(ex).ConfigureAwait(false); + } + + return (TResult)await result.ConfigureAwait(false); // already done waiting but in failure we want the exception itself and not AggregateException } - catch (TaskCanceledException e) when (token.IsCancellationRequested) - { - await StopProcessingUnderLock().ConfigureAwait(false); - throw new TimeoutException($"Did not get a reply for operation '{_id}'.", e); - } - catch (Exception ex) + finally { - await StopProcessingUnderLock(ex).ConfigureAwait(false); + try + { + await initTask.ConfigureAwait(false); + } + catch + { + // ignored + } } - - return (TResult)await result.ConfigureAwait(false); // already done waiting but in failure we want the exception itself and not AggregateException } } From 9a64400e2b3c4aa568a3a4872d47fa5e2732b138 Mon Sep 17 00:00:00 2001 From: danielle9897 Date: Wed, 1 May 2024 13:21:18 +0300 Subject: [PATCH 11/27] RavenDB-20246 Identities View: Explain better the meaning of the Document ID Prefix --- .../database/identities/identities.ts | 27 +++++++++--- .../views/database/identities/identities.html | 41 ++++++++++++------- 2 files changed, 48 insertions(+), 20 deletions(-) diff --git a/src/Raven.Studio/typescript/viewmodels/database/identities/identities.ts b/src/Raven.Studio/typescript/viewmodels/database/identities/identities.ts index ad626f9262d9..dffb0a07d532 100644 --- a/src/Raven.Studio/typescript/viewmodels/database/identities/identities.ts +++ b/src/Raven.Studio/typescript/viewmodels/database/identities/identities.ts @@ -21,7 +21,8 @@ class identity { currentValue = ko.observable(); warnAboutSmallerValue: KnockoutComputed; - nextDocumentText: KnockoutComputed; + textForEditIdentity: KnockoutComputed; + textForNewIdentity: KnockoutComputed; identitySeparator = ko.observable(); static readonly defaultIdentitySeparator = "/"; @@ -59,11 +60,27 @@ class identity { return prefix; }); - this.nextDocumentText = ko.pureComputed(() => { - return `The effective identity separator defined in configuration is: ${genUtils.escapeHtml(this.identitySeparator())}
- The next document that will be created with Prefix: "${genUtils.escapeHtml(this.prefixWithPipe())}" - will have ID: "${genUtils.escapeHtml(this.prefixWithoutPipe())}${this.identitySeparator()}${this.value() + 1}"`; + this.textForEditIdentity = ko.pureComputed(() => { + return `
    +
  • The next document that will be created using a pipe symbol, e.g.: ${genUtils.escapeHtml(this.prefixWithPipe())}, + will have ID: ${genUtils.escapeHtml(this.prefixWithoutPipe())}${this.identitySeparator()}${this.value() + 1} +
    • +
  • ${separatorText}
    • +
`; }); + + this.textForNewIdentity = ko.pureComputed(() => { + return `
    +
  • When setting "Prefix" & "Value", the next document created using a pipe symbol, i.e.: <Prefix>|
    + will be assigned an ID structured as <Prefix>${genUtils.escapeHtml(this.identitySeparator())}<Value + 1> +
    • +
  • ${separatorText}
    • +
`; + }); + + const separatorText = + `In the resulting ID, the Prefix and Value parts are separated by the effective separator character defined in your configuration, + which is: ${genUtils.escapeHtml(this.identitySeparator())}`; this.warnAboutSmallerValue = ko.pureComputed(() => { return this.value() < this.currentValue(); diff --git a/src/Raven.Studio/wwwroot/App/views/database/identities/identities.html b/src/Raven.Studio/wwwroot/App/views/database/identities/identities.html index d1ccb3fadecd..12bd6592a3e2 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/identities/identities.html +++ b/src/Raven.Studio/wwwroot/App/views/database/identities/identities.html @@ -11,7 +11,7 @@
- Identities tutorial + Identities tutorial
@@ -33,30 +33,41 @@

Prefix
+ id="prefix" placeholder="Enter the collection for which to set an identity value, e.g. 'orders'">

+ id="value" placeholder="Enter a number that will be the latest identity value for this collection">
-
- -
-
-
-
+
+
+ +
+
+
+
+
+
+ + + New value is smaller than current. Please verify documents with higher identity value do not exist. + +
+
-
-
- - - New value is smaller than current. Please verify documents with higher identity value do not exist. - +
+
+
+
+ +
+
+
From c994924e4e5fe5989230e3f2d4e28a4163bebb98 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Mon, 6 May 2024 11:57:14 +0200 Subject: [PATCH 12/27] RavenDB-22275 Updated Raven.Client to .NET 8 --- src/Raven.Client/Raven.Client.csproj | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Raven.Client/Raven.Client.csproj b/src/Raven.Client/Raven.Client.csproj index b76fe2c37acc..7ca7a371bb8e 100644 --- a/src/Raven.Client/Raven.Client.csproj +++ b/src/Raven.Client/Raven.Client.csproj @@ -3,7 +3,7 @@ RavenDB Client is the client library for accessing RavenDB Hibernating Rhinos - net7.0;net6.0;net5.0;netcoreapp3.1;netstandard2.1;netstandard2.0 + net8.0;net7.0;net6.0;net5.0;netcoreapp3.1;netstandard2.1;netstandard2.0 $(DefineConstants);PORTABLE true Raven.Client From 99e34ac31e5c237f6534f425787e36ef419deae5 Mon Sep 17 00:00:00 2001 From: Damian Olszewski Date: Mon, 6 May 2024 12:04:55 +0200 Subject: [PATCH 13/27] RavenDB-22320 Add thumbprint only if primary cert exists --- .../typescript/viewmodels/manage/certificates.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/Raven.Studio/typescript/viewmodels/manage/certificates.ts b/src/Raven.Studio/typescript/viewmodels/manage/certificates.ts index 65d689c6a4b7..4e2c82a9a0d3 100644 --- a/src/Raven.Studio/typescript/viewmodels/manage/certificates.ts +++ b/src/Raven.Studio/typescript/viewmodels/manage/certificates.ts @@ -660,7 +660,10 @@ class certificates extends viewModelBase { secondaryCertificates.forEach(cert => { const thumbprint = cert.CollectionPrimaryKey; const primaryCert = mergedCertificates.find(x => x.Thumbprint === thumbprint); - primaryCert.Thumbprints.push(cert.Thumbprint); + + if (primaryCert) { + primaryCert.Thumbprints.push(cert.Thumbprint); + } }); const orderedCertificates = this.sortByDefaultInternal(mergedCertificates); From af5198f359c1bec13c76b210270c927d3083ee5c Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Mon, 6 May 2024 15:25:17 +0200 Subject: [PATCH 14/27] RavenDB-22330 / RavenDB-13830 / RavenDB-10621 / RavenDB-21987 Skipping the test which causes SO on 32 bits --- test/SlowTests/Issues/RavenDB_10621.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/SlowTests/Issues/RavenDB_10621.cs b/test/SlowTests/Issues/RavenDB_10621.cs index 95c8499b5beb..3ccb52b30875 100644 --- a/test/SlowTests/Issues/RavenDB_10621.cs +++ b/test/SlowTests/Issues/RavenDB_10621.cs @@ -3,6 +3,7 @@ using FastTests; using Raven.Client.Documents.Indexes; using Raven.Client.Documents.Operations.Indexes; +using Tests.Infrastructure; using Xunit; using Xunit.Abstractions; @@ -14,7 +15,7 @@ public RavenDB_10621(ITestOutputHelper output) : base(output) { } - [Fact] + [MultiplatformFact(RavenArchitecture.X64)] public void ShouldNotErrorIndexOnInvalidProgramException() { // this test has been added initially to workaround the following issue: https://github.com/dotnet/coreclr/issues/14672 From dd2c114c04845599c97cb05a187578019e166c96 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Tue, 7 May 2024 08:09:55 +0200 Subject: [PATCH 15/27] RavenDB-22330 Fixing AllTestsShouldUseRavenFactOrRavenTheoryAttributes test --- test/SlowTests/Tests/TestsInheritanceTests.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/SlowTests/Tests/TestsInheritanceTests.cs b/test/SlowTests/Tests/TestsInheritanceTests.cs index c7ab55f7d90a..75aac93cdfd5 100644 --- a/test/SlowTests/Tests/TestsInheritanceTests.cs +++ b/test/SlowTests/Tests/TestsInheritanceTests.cs @@ -88,7 +88,7 @@ where Filter(method) select method; var array = types.ToArray(); - const int numberToTolerate = 6421; + const int numberToTolerate = 6420; if (array.Length == numberToTolerate) return; From edfc0cca7d7b90ee9efa45e8ceb368f93928aafc Mon Sep 17 00:00:00 2001 From: Damian Olszewski Date: Mon, 6 May 2024 15:36:13 +0200 Subject: [PATCH 16/27] RavenDB-20986 Show warning when no responsible nodes available --- .../tasks/editElasticSearchEtlTask.html | 2 +- .../tasks/editExternalReplicationTask.html | 2 +- .../database/tasks/editKafkaEtlTask.html | 2 +- .../views/database/tasks/editOlapEtlTask.html | 2 +- .../tasks/editPeriodicBackupTask.html | 2 +- .../database/tasks/editRabbitMqEtlTask.html | 2 +- .../database/tasks/editRavenEtlTask.html | 2 +- .../tasks/editReplicationHubTask.html | 2 +- .../tasks/editReplicationSinkTask.html | 2 +- .../views/database/tasks/editSqlEtlTask.html | 2 +- .../database/tasks/editSubscriptionTask.html | 2 +- .../views/manage/editServerWideBackup.html | 2 +- .../editServerWideExternalReplication.html | 2 +- .../partial/taskResponsibleNodeSection.html | 66 ++++++++++++------- .../taskResponsibleNodeSection_ForBackup.html | 63 +++++++++++------- .../resources/addNewNodeToDatabaseGroup.html | 2 +- 16 files changed, 95 insertions(+), 62 deletions(-) diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editElasticSearchEtlTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editElasticSearchEtlTask.html index c0435b09f106..e3205130fb29 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editElasticSearchEtlTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editElasticSearchEtlTask.html @@ -53,7 +53,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editExternalReplicationTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editExternalReplicationTask.html index dc4b8a689cf4..6daf7810a5bd 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editExternalReplicationTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editExternalReplicationTask.html @@ -75,7 +75,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editKafkaEtlTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editKafkaEtlTask.html index 7df78178e7be..dfdd5e016361 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editKafkaEtlTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editKafkaEtlTask.html @@ -51,7 +51,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editOlapEtlTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editOlapEtlTask.html index 57b95d441e38..80998f1ba3fb 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editOlapEtlTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editOlapEtlTask.html @@ -53,7 +53,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editPeriodicBackupTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editPeriodicBackupTask.html index 90db2b979c0c..f59c85000519 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editPeriodicBackupTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editPeriodicBackupTask.html @@ -98,7 +98,7 @@
- +
diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editRabbitMqEtlTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editRabbitMqEtlTask.html index 85e7b7adf5d2..81d20e641dbb 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editRabbitMqEtlTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editRabbitMqEtlTask.html @@ -51,7 +51,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editRavenEtlTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editRavenEtlTask.html index 6a445384912c..ef8cbab175a5 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editRavenEtlTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editRavenEtlTask.html @@ -51,7 +51,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationHubTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationHubTask.html index b28611f0d952..9d65da718775 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationHubTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationHubTask.html @@ -58,7 +58,7 @@

- +

diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationSinkTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationSinkTask.html index 59592b71e693..5b60fb8c710d 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationSinkTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editReplicationSinkTask.html @@ -54,7 +54,7 @@

- +
diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editSqlEtlTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editSqlEtlTask.html index 031a8261d861..f3d01420b16f 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editSqlEtlTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editSqlEtlTask.html @@ -53,7 +53,7 @@

- +
diff --git a/src/Raven.Studio/wwwroot/App/views/database/tasks/editSubscriptionTask.html b/src/Raven.Studio/wwwroot/App/views/database/tasks/editSubscriptionTask.html index 251ff705f1bb..d41cad13372b 100644 --- a/src/Raven.Studio/wwwroot/App/views/database/tasks/editSubscriptionTask.html +++ b/src/Raven.Studio/wwwroot/App/views/database/tasks/editSubscriptionTask.html @@ -102,7 +102,7 @@

- +
diff --git a/src/Raven.Studio/wwwroot/App/views/manage/editServerWideBackup.html b/src/Raven.Studio/wwwroot/App/views/manage/editServerWideBackup.html index 9ff3115fee7b..66760b34775a 100644 --- a/src/Raven.Studio/wwwroot/App/views/manage/editServerWideBackup.html +++ b/src/Raven.Studio/wwwroot/App/views/manage/editServerWideBackup.html @@ -98,7 +98,7 @@
- +
diff --git a/src/Raven.Studio/wwwroot/App/views/manage/editServerWideExternalReplication.html b/src/Raven.Studio/wwwroot/App/views/manage/editServerWideExternalReplication.html index ff98d486e6d2..2d08722aabed 100644 --- a/src/Raven.Studio/wwwroot/App/views/manage/editServerWideExternalReplication.html +++ b/src/Raven.Studio/wwwroot/App/views/manage/editServerWideExternalReplication.html @@ -62,7 +62,7 @@
- +
diff --git a/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection.html b/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection.html index e9599bb34b51..0ebe6907c8ba 100644 --- a/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection.html +++ b/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection.html @@ -1,32 +1,48 @@ -
-
-
- -
-
- -
    -
    • -
- +
+
+ +
+
+ + + + + Currently, the responsible node cannot be selected because there are no nodes available. + +
-
-
- -
- - + +
+
+
+ +
+
+ +
    +
    • +
+
-
-
-
- -
+
+
+ +
+ + +
+
+
+
+
+ +
+
diff --git a/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection_ForBackup.html b/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection_ForBackup.html index 1ea673b170ce..f407a7800b5c 100644 --- a/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection_ForBackup.html +++ b/src/Raven.Studio/wwwroot/App/views/partial/taskResponsibleNodeSection_ForBackup.html @@ -1,30 +1,47 @@ -
-
- -
-
- -
    -
    • -
- +
+
+
+
+
+ + + + + Currently, the responsible node cannot be selected because there are no nodes available. + +
-
-
-
- - + +
+
+ +
+
+ +
    +
    • +
+ +
+
+
+
+
+ + +
+
-
-
-
-
+
+
+
+
-
+
diff --git a/src/Raven.Studio/wwwroot/App/views/resources/addNewNodeToDatabaseGroup.html b/src/Raven.Studio/wwwroot/App/views/resources/addNewNodeToDatabaseGroup.html index 2e83a5921f00..05dfe5143cad 100644 --- a/src/Raven.Studio/wwwroot/App/views/resources/addNewNodeToDatabaseGroup.html +++ b/src/Raven.Studio/wwwroot/App/views/resources/addNewNodeToDatabaseGroup.html @@ -33,7 +33,7 @@

Add a new node to the database group

- +
From 72ce8557cbfe204e3f1b8fe95dceb22e84d01f2e Mon Sep 17 00:00:00 2001 From: Karmel Indych Date: Thu, 2 May 2024 08:09:41 +0300 Subject: [PATCH 17/27] RavenDB-22329 avoid deadlock in LoggingSource --- src/Sparrow/Logging/LoggingSource.cs | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/src/Sparrow/Logging/LoggingSource.cs b/src/Sparrow/Logging/LoggingSource.cs index 349aa62211ef..699cc2e3e5fa 100644 --- a/src/Sparrow/Logging/LoggingSource.cs +++ b/src/Sparrow/Logging/LoggingSource.cs @@ -196,14 +196,16 @@ public void SetupLogMode(LogMode logMode, string path, TimeSpan? retentionTime, public void SetupLogMode(LogMode logMode, string path, TimeSpan retentionTime, long retentionSize, bool compress) { + if (_loggingThread?.ManagedThreadId == Thread.CurrentThread.ManagedThreadId) + { + Task.Run(() => SetupLogMode(logMode, path, retentionTime, retentionSize, compress)); + return; + } + lock (this) { var copyLoggingThread = _loggingThread; - if (copyLoggingThread?.ManagedThreadId == Thread.CurrentThread.ManagedThreadId) - { - Task.Run(() => SetupLogMode(logMode, path, retentionTime, retentionSize, compress)); - return; - } + (bool info, bool operation) old = (_isInfoEnabled, _isOperationsEnabled); (_isInfoEnabled, _isOperationsEnabled) = CalculateIsLogEnabled(logMode); if (_isInfoEnabled == old.info && _isOperationsEnabled == old.operation && LogMode == logMode && path == _path && retentionTime == RetentionTime && compress == Compressing) @@ -645,7 +647,6 @@ private void BackgroundLogger() try { Interlocked.Increment(ref _generation); - var threadStatesToRemove = new FastStack>(); while (_keepLogging) { try From e122a905a773a9e2f16f4458bc953709ee3f789f Mon Sep 17 00:00:00 2001 From: Karmel Indych Date: Tue, 7 May 2024 13:02:21 +0300 Subject: [PATCH 18/27] RavenDB-22329 add tokens for let's encypt setup tests --- .../Commercial/SetupWizard/LetsEncryptSetupUtils.cs | 7 +++---- test/SlowTests/Tools/SetupSecuredClusterUsingRvn.cs | 13 ++++++++----- 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/src/Raven.Server/Commercial/SetupWizard/LetsEncryptSetupUtils.cs b/src/Raven.Server/Commercial/SetupWizard/LetsEncryptSetupUtils.cs index fca729d4d890..130c2d1cbadd 100644 --- a/src/Raven.Server/Commercial/SetupWizard/LetsEncryptSetupUtils.cs +++ b/src/Raven.Server/Commercial/SetupWizard/LetsEncryptSetupUtils.cs @@ -54,7 +54,7 @@ public static async Task Setup(SetupInfo setupInfo, SetupProgressAndRes try { var content = new StringContent(serializeObject, Encoding.UTF8, "application/json"); - var response = await ApiHttpClient.Instance.PostAsync($"/api/v1/dns-n-cert/claim", content, CancellationToken.None).ConfigureAwait(false); + var response = await ApiHttpClient.Instance.PostAsync($"/api/v1/dns-n-cert/claim", content, token).ConfigureAwait(false); response.EnsureSuccessStatusCode(); progress?.AddInfo($"Successfully claimed this domain: {setupInfo.Domain}."); } @@ -67,7 +67,7 @@ await RavenDnsRecordHelper.UpdateDnsRecordsTask(new UpdateDnsRecordParameters Challenge = challengeResult.Challenge, SetupInfo = setupInfo, Progress = progress, - Token = CancellationToken.None, + Token = token, RegisterTcpDnsRecords = registerTcpDnsRecords }); progress?.AddInfo($"Updating DNS record(s) and challenge(s) in {setupInfo.Domain.ToLower()}.{setupInfo.RootDomain.ToLower()}."); @@ -92,8 +92,7 @@ await CertificateUtils.CompleteAuthorizationAndGetCertificate(new CompleteAuthor SetupInfo = setupInfo, Client = acmeClient, ChallengeResult = challengeResult, - Token = CancellationToken.None - + Token = token }); progress.Processed++; diff --git a/test/SlowTests/Tools/SetupSecuredClusterUsingRvn.cs b/test/SlowTests/Tools/SetupSecuredClusterUsingRvn.cs index fd8d6867dc3b..ccdd6050e5a9 100644 --- a/test/SlowTests/Tools/SetupSecuredClusterUsingRvn.cs +++ b/test/SlowTests/Tools/SetupSecuredClusterUsingRvn.cs @@ -35,6 +35,7 @@ public SetupSecuredClusterUsingRvn(ITestOutputHelper output) : base(output) public async Task Should_Create_Secured_Cluster_Generating_Self_Singed_Cert_And_Setup_Zip_File_From_Rvn_Three_Nodes() { DoNotReuseServerAndUseStagingLetsEncrypt(); + using var cts = new CancellationTokenSource(TimeSpan.FromMinutes(5)); var license = Environment.GetEnvironmentVariable("RAVEN_LICENSE"); Assert.True(license != null, nameof(license) + " != null"); @@ -72,7 +73,7 @@ public async Task Should_Create_Secured_Cluster_Generating_Self_Singed_Cert_And_ { Output.WriteLine(tuple.Exception.Message); } - }), CancellationToken.None); + }), cts.Token); var settingsJsonObject = SetupManager.ExtractCertificatesAndSettingsJsonFromZip(zipBytes, "A", @@ -220,6 +221,7 @@ private void DoNotReuseServerAndUseStagingLetsEncrypt() public async Task Should_Create_Secured_Cluster_Generating_Self_Singed_Cert_And_Setup_Zip_File_From_Rvn_One_Node() { DoNotReuseServerAndUseStagingLetsEncrypt(); + using var cts = new CancellationTokenSource(TimeSpan.FromMinutes(5)); var license = Environment.GetEnvironmentVariable("RAVEN_LICENSE"); Assert.True(license != null, nameof(license) + " != null"); @@ -256,7 +258,7 @@ public async Task Should_Create_Secured_Cluster_Generating_Self_Singed_Cert_And_ { Output.WriteLine(tuple.Exception.Message); } - }), CancellationToken.None); + }), cts.Token); var settingsJsonObject = SetupManager.ExtractCertificatesAndSettingsJsonFromZip(zipBytes, "A", @@ -324,6 +326,7 @@ public async Task Should_Create_Secured_Cluster_Generating_Self_Singed_Cert_And_ public async Task Should_Create_Secured_Cluster_From_Rvn_Using_Lets_Encrypt_Mode_One_Node() { DoNotReuseServerAndUseStagingLetsEncrypt(); + using var cts = new CancellationTokenSource(TimeSpan.FromMinutes(5)); var license = Environment.GetEnvironmentVariable("RAVEN_LICENSE"); Assert.True(license != null, nameof(license) + " != null"); @@ -334,7 +337,6 @@ public async Task Should_Create_Secured_Cluster_From_Rvn_Using_Lets_Encrypt_Mode const string publicTcpServerUrl1 = $"tcp://a.{domain}.{rootDomain}:38879"; const string tcpServerUrl1 = "tcp://127.0.0.1:38879"; - var setupInfo = new SetupInfo { Environment = StudioConfiguration.StudioEnvironment.None, @@ -369,7 +371,7 @@ public async Task Should_Create_Secured_Cluster_From_Rvn_Using_Lets_Encrypt_Mode }, false, StagingAcmeClientUrl, - CancellationToken.None); + cts.Token); X509Certificate2 serverCert; X509Certificate2 clientCert; @@ -454,6 +456,7 @@ public async Task Should_Create_Secured_Cluster_From_Rvn_Using_Lets_Encrypt_Mode public async Task Should_Create_Secured_Cluster_From_Rvn_Using_Lets_Encrypt_Mode_Three_Nodes() { DoNotReuseServerAndUseStagingLetsEncrypt(); + using var cts = new CancellationTokenSource(TimeSpan.FromMinutes(5)); var license = Environment.GetEnvironmentVariable("RAVEN_LICENSE"); Assert.True(license != null, nameof(license) + " != null"); @@ -506,7 +509,7 @@ public async Task Should_Create_Secured_Cluster_From_Rvn_Using_Lets_Encrypt_Mode }, false, StagingAcmeClientUrl, - CancellationToken.None); + cts.Token); X509Certificate2 serverCert; X509Certificate2 clientCert; From bf326e34b99f80b0bc1a39a2b758746ceb61c4dc Mon Sep 17 00:00:00 2001 From: Karmel Indych Date: Tue, 7 May 2024 17:58:39 +0300 Subject: [PATCH 19/27] RavenDB-22225 avoid opening write tx in the same test thread --- test/RachisTests/BasicTests.cs | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/test/RachisTests/BasicTests.cs b/test/RachisTests/BasicTests.cs index 75e800f84805..f4aaee35d0d2 100644 --- a/test/RachisTests/BasicTests.cs +++ b/test/RachisTests/BasicTests.cs @@ -6,6 +6,7 @@ using Raven.Server.ServerWide.Context; using Sparrow.Json; using Sparrow.Server; +using Sparrow.Utils; using Tests.Infrastructure; using Xunit; using Xunit.Abstractions; @@ -63,9 +64,13 @@ public async Task RavenDB_13659() var leader = await CreateNetworkAndGetLeader(1); var mre = new AsyncManualResetEvent(); var tcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var currentThread = NativeMemory.CurrentThreadStats.ManagedThreadId; leader.Timeout.Start(() => { + if (currentThread == NativeMemory.CurrentThreadStats.ManagedThreadId) + throw new InvalidOperationException("Can't use same thread as the xUnit test"); + mre.Set(); try { From be39fb96d21d8d39516b0059924d5ad247efbfb6 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Tue, 30 Apr 2024 10:04:25 +0200 Subject: [PATCH 20/27] RavenDB-22257 Failing scenario reproduced in a test (in Release mode, in Debug it throws earlier because of a debug check of duplicated tx Id) --- src/Voron/Impl/LowLevelTransaction.cs | 8 +++ src/Voron/StorageEnvironment.cs | 2 + test/SlowTests/Voron/Issues/RavenDB_22257.cs | 74 ++++++++++++++++++++ 3 files changed, 84 insertions(+) create mode 100644 test/SlowTests/Voron/Issues/RavenDB_22257.cs diff --git a/src/Voron/Impl/LowLevelTransaction.cs b/src/Voron/Impl/LowLevelTransaction.cs index 666f7cd3ffb9..74a50e9e2249 100644 --- a/src/Voron/Impl/LowLevelTransaction.cs +++ b/src/Voron/Impl/LowLevelTransaction.cs @@ -1547,6 +1547,7 @@ internal class TestingStuff internal Action ActionToCallDuringEnsurePagerStateReference; internal Action ActionToCallJustBeforeWritingToJournal; internal Action ActionToCallDuringBeginAsyncCommitAndStartNewTransaction; + internal Action ActionToCallOnTransactionAfterCommit; public TestingStuff(LowLevelTransaction tx) { @@ -1579,6 +1580,13 @@ internal IDisposable CallDuringBeginAsyncCommitAndStartNewTransaction(Action act return new DisposableAction(() => ActionToCallDuringBeginAsyncCommitAndStartNewTransaction = null); } + internal IDisposable CallOnTransactionAfterCommit(Action action) + { + ActionToCallOnTransactionAfterCommit = action; + + return new DisposableAction(() => ActionToCallOnTransactionAfterCommit = null); + } + internal HashSet GetPagerStates() { return _tx._pagerStates; diff --git a/src/Voron/StorageEnvironment.cs b/src/Voron/StorageEnvironment.cs index 9b0762da230d..4d10b2e053ea 100644 --- a/src/Voron/StorageEnvironment.cs +++ b/src/Voron/StorageEnvironment.cs @@ -912,6 +912,8 @@ public void Dispose() public event Action AfterCommitWhenNewTransactionsPrevented; internal void TransactionAfterCommit(LowLevelTransaction tx) { + tx._forTestingPurposes?.ActionToCallOnTransactionAfterCommit?.Invoke(); + if (ActiveTransactions.Contains(tx) == false) { if (tx.Committed && tx.FlushedToJournal) diff --git a/test/SlowTests/Voron/Issues/RavenDB_22257.cs b/test/SlowTests/Voron/Issues/RavenDB_22257.cs new file mode 100644 index 000000000000..4eebbbc8c578 --- /dev/null +++ b/test/SlowTests/Voron/Issues/RavenDB_22257.cs @@ -0,0 +1,74 @@ +using System; +using FastTests.Voron; +using Tests.Infrastructure; +using Voron; +using Voron.Impl; +using Xunit; +using Xunit.Abstractions; + +namespace SlowTests.Voron.Issues; + +public class RavenDB_22257 : StorageTest +{ + public RavenDB_22257(ITestOutputHelper output) : base(output) + { + } + + protected override void Configure(StorageEnvironmentOptions options) + { + base.Configure(options); + + options.ManualFlushing = true; + } + + [RavenFact(RavenTestCategory.Voron)] + public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() + { + RequireFileBasedPager(); + + using (var txw1 = Env.NewLowLevelTransaction(new TransactionPersistentContext(), TransactionFlags.ReadWrite)) + { + LowLevelTransaction txw2 = null; + + txw1.ModifyPage(0); + + try + { + txw1.ForTestingPurposesOnly().CallOnTransactionAfterCommit(() => + { + // here we pretend to be running as of a different thread + + txw1.Dispose(); // dispose of the already running transaction will release the write transaction lock, so we'll be able to create a new write transaction + + txw2 = Env.NewLowLevelTransaction(new TransactionPersistentContext(), TransactionFlags.ReadWrite); + + txw2.ModifyPage(0); + }); + + // both commits below will fail BUT they managed to write to the journal file already + + var notFoundInActiveTransactionsEx = Assert.Throws(txw1.Commit); + + Assert.Equal("The transaction with ID '2' got committed and flushed but it wasn't found in the ActiveTransactions. (Debug details: tx id of ActiveTransactionNode - 2", notFoundInActiveTransactionsEx.Message); + + var duplicatedKeyEx = Assert.Throws(txw2.Commit); + + Assert.Equal("An item with the same key has already been added. Key: 2 (Parameter 'key')", duplicatedKeyEx.Message); + } + finally + { + txw2?.Dispose(); + } + } + + // during the recovery will encounter two committed transactions with the same ID + + RestartDatabase(); + + using (var txw = Env.WriteTransaction()) + { + txw.CreateTree("foo"); + txw.Commit(); + } + } +} From 998e5d9fd17ded5fa0258b742734a35efce98395 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Tue, 7 May 2024 13:43:22 +0200 Subject: [PATCH 21/27] RavenDB-22257 Prevent from disposing a write transaction from a different thread. Fixing such usage in the cluster followe code. --- src/Raven.Server/Rachis/Follower.cs | 5 +-- src/Voron/Impl/LowLevelTransaction.cs | 10 ++++++ test/SlowTests/Voron/Issues/RavenDB_22257.cs | 32 ++++++++++++++++++-- 3 files changed, 42 insertions(+), 5 deletions(-) diff --git a/src/Raven.Server/Rachis/Follower.cs b/src/Raven.Server/Rachis/Follower.cs index ad80c1afab37..8ae617be5604 100644 --- a/src/Raven.Server/Rachis/Follower.cs +++ b/src/Raven.Server/Rachis/Follower.cs @@ -484,7 +484,7 @@ private void NegotiateWithLeader(ClusterOperationContext context, LogLengthNegot { KeepAliveAndExecuteAction(() => { - onFullSnapshotInstalledTask = ReadAndCommitSnapshot(context, snapshot, cts.Token); + onFullSnapshotInstalledTask = ReadAndCommitSnapshot(snapshot, cts.Token); }, cts, "ReadAndCommitSnapshot"); } @@ -555,10 +555,11 @@ private void WaitForTaskCompletion(Task task, string debug) } } - private Task ReadAndCommitSnapshot(ClusterOperationContext context, InstallSnapshot snapshot, CancellationToken token) + private Task ReadAndCommitSnapshot(InstallSnapshot snapshot, CancellationToken token) { Task onFullSnapshotInstalledTask = null; + using (_engine.ContextPool.AllocateOperationContext(out ClusterOperationContext context)) using (context.OpenWriteTransaction()) { var lastTerm = _engine.GetTermFor(context, snapshot.LastIncludedIndex); diff --git a/src/Voron/Impl/LowLevelTransaction.cs b/src/Voron/Impl/LowLevelTransaction.cs index 74a50e9e2249..66fd74730904 100644 --- a/src/Voron/Impl/LowLevelTransaction.cs +++ b/src/Voron/Impl/LowLevelTransaction.cs @@ -4,6 +4,7 @@ using System.IO; using System.Runtime.CompilerServices; using System.Runtime.ExceptionServices; +using System.Threading; using System.Threading.Tasks; using Sparrow; using Sparrow.Platform; @@ -934,6 +935,9 @@ public void Dispose() if (_txState.HasFlag(TxState.Disposed)) return; + if (Flags == TransactionFlags.ReadWrite && NativeMemory.CurrentThreadStats != CurrentTransactionHolder) + ThrowDisposeOfTxMustBeCalledOnTheSameThreadThatCreatedIt(); + try { if (!Committed && !RolledBack && Flags == TransactionFlags.ReadWrite) @@ -1322,6 +1326,12 @@ private static void ThrowAlreadyCommitted() throw new InvalidOperationException("Cannot commit already committed transaction."); } + private void ThrowDisposeOfTxMustBeCalledOnTheSameThreadThatCreatedIt() + { + throw new InvalidOperationException($"Dispose of the transaction must be called from the same thread that created it. " + + $"Transaction {Id} (Flags: {Flags}) was created by {CurrentTransactionHolder.Name}, thread Id: {CurrentTransactionHolder.ManagedThreadId}. " + + $"The dispose was called from {NativeMemory.CurrentThreadStats.Name}, thread Id: {NativeMemory.CurrentThreadStats.ManagedThreadId}"); + } public void Rollback() { diff --git a/test/SlowTests/Voron/Issues/RavenDB_22257.cs b/test/SlowTests/Voron/Issues/RavenDB_22257.cs index 4eebbbc8c578..90a62256564e 100644 --- a/test/SlowTests/Voron/Issues/RavenDB_22257.cs +++ b/test/SlowTests/Voron/Issues/RavenDB_22257.cs @@ -1,4 +1,5 @@ using System; +using System.Threading; using FastTests.Voron; using Tests.Infrastructure; using Voron; @@ -36,15 +37,33 @@ public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() { txw1.ForTestingPurposesOnly().CallOnTransactionAfterCommit(() => { + /* // here we pretend to be running as of a different thread - txw1.Dispose(); // dispose of the already running transaction will release the write transaction lock, so we'll be able to create a new write transaction + */ + + InvalidOperationException ex = null; + + Thread newTransactionThread = new Thread(() => + { + ex = Assert.Throws(() => + { + txw1.Dispose(); // this is supposed to throw because we're attempting to dispose write tx from a different thread + + txw2 = Env.NewLowLevelTransaction(new TransactionPersistentContext(), TransactionFlags.ReadWrite); - txw2 = Env.NewLowLevelTransaction(new TransactionPersistentContext(), TransactionFlags.ReadWrite); + txw2.ModifyPage(0); + }); + }); - txw2.ModifyPage(0); + newTransactionThread.Start(); + + newTransactionThread.Join(); + + Assert.StartsWith("Dispose of the transaction must be called from the same thread that created it. Transaction 2 (Flags: ReadWrite) was created by", ex.Message); }); + /* // both commits below will fail BUT they managed to write to the journal file already var notFoundInActiveTransactionsEx = Assert.Throws(txw1.Commit); @@ -54,6 +73,11 @@ public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() var duplicatedKeyEx = Assert.Throws(txw2.Commit); Assert.Equal("An item with the same key has already been added. Key: 2 (Parameter 'key')", duplicatedKeyEx.Message); + */ + + txw1.Commit(); + + Assert.Null(txw2); } finally { @@ -61,7 +85,9 @@ public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() } } + /* // during the recovery will encounter two committed transactions with the same ID + */ RestartDatabase(); From cd45d88320bf11d2a0bff5143454b44dd11fd600 Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Tue, 7 May 2024 14:02:44 +0200 Subject: [PATCH 22/27] RavenDB-22257 Fixing tests which created and disposed write transactions from different threads --- .../PostingLists/PostingListLeafPageTests.cs | 45 +++++++------------ 1 file changed, 17 insertions(+), 28 deletions(-) diff --git a/test/FastTests/Voron/PostingLists/PostingListLeafPageTests.cs b/test/FastTests/Voron/PostingLists/PostingListLeafPageTests.cs index 9a2cad5cf64f..72c0fa6700a2 100644 --- a/test/FastTests/Voron/PostingLists/PostingListLeafPageTests.cs +++ b/test/FastTests/Voron/PostingLists/PostingListLeafPageTests.cs @@ -1,30 +1,18 @@ using System; using System.Collections.Generic; -using Sparrow.Server; using Voron; using Voron.Data.PostingLists; using Voron.Global; -using Voron.Impl; using Xunit; using Xunit.Abstractions; namespace FastTests.Voron.PostingLists { - public unsafe class PostingListLeafPageTests : NoDisposalNeeded + public unsafe class PostingListLeafPageTests : StorageTest { - private readonly Transaction _tx; - private readonly StorageEnvironment _env; - private ByteStringContext.InternalScope _releaseStr; - private readonly byte* _pagePtr; - private readonly LowLevelTransaction _llt; public PostingListLeafPageTests(ITestOutputHelper output) : base(output) - { - _env = new StorageEnvironment(StorageEnvironmentOptions.CreateMemoryOnly()); - _tx = _env.WriteTransaction(); - _llt = _tx.LowLevelTransaction; - _releaseStr = _tx.Allocator.Allocate(Constants.Storage.PageSize, out var bs); - _pagePtr = bs.Ptr; + { } [Theory] @@ -35,6 +23,11 @@ public PostingListLeafPageTests(ITestOutputHelper output) : base(output) [InlineData(4096 + 257)] // with compressed x 16 (so will recompress) public void CanAddAndRead(int size) { + using var _tx = Env.WriteTransaction(); + var _llt = _tx.LowLevelTransaction; + using var _ = _tx.Allocator.Allocate(Constants.Storage.PageSize, out var bs); + var _pagePtr = bs.Ptr; + var leaf = new PostingListLeafPage(new Page(_pagePtr)); PostingListLeafPage.InitLeaf(leaf.Header); var list = new List(); @@ -71,6 +64,11 @@ public void CanAddAndRead(int size) [InlineData(4096 + 257)] // with compressed x 16 (so will recompress) public void CanAddAndRemove(int size) { + using var _tx = Env.WriteTransaction(); + var _llt = _tx.LowLevelTransaction; + using var _ = _tx.Allocator.Allocate(Constants.Storage.PageSize, out var bs); + var _pagePtr = bs.Ptr; + var leaf = new PostingListLeafPage(new Page(_pagePtr)); PostingListLeafPage.InitLeaf(leaf.Header); var buf = new int[] {12, 18}; @@ -118,6 +116,11 @@ public void CanAddAndRemove(int size) [InlineData(4096 + 257)] // with compressed x 16 (so will recompress) public void CanHandleDuplicateValues(int size) { + using var _tx = Env.WriteTransaction(); + var _llt = _tx.LowLevelTransaction; + using var _ = _tx.Allocator.Allocate(Constants.Storage.PageSize, out var bs); + var _pagePtr = bs.Ptr; + var leaf = new PostingListLeafPage(new Page(_pagePtr)); PostingListLeafPage.InitLeaf(leaf.Header); var list = new List(); @@ -154,19 +157,5 @@ public void CanHandleDuplicateValues(int size) Assert.Equal(list, leaf.GetDebugOutput()); } - - public override void Dispose() - { - try - { - _releaseStr.Dispose(); - _tx?.Dispose(); - _env?.Dispose(); - } - finally - { - base.Dispose(); - } - } } } From d3117aaac9a5e6461d4136f5844b38d2791d79ad Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Mon, 29 Apr 2024 11:41:16 +0200 Subject: [PATCH 23/27] RavenDB-22322 Fixing version after the latest 5.4.118 release. We want to have .200 due to bump to .NET 8 --- src/CommonAssemblyInfo.cs | 6 +++--- src/Raven.Client/Properties/VersionInfo.cs | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/CommonAssemblyInfo.cs b/src/CommonAssemblyInfo.cs index 75fa5d0aa107..8f485848c479 100644 --- a/src/CommonAssemblyInfo.cs +++ b/src/CommonAssemblyInfo.cs @@ -5,9 +5,9 @@ [assembly: AssemblyCopyright("© Hibernating Rhinos 2009 - 2024 All rights reserved.")] -[assembly: AssemblyVersion("5.4.119")] -[assembly: AssemblyFileVersion("5.4.119.54")] -[assembly: AssemblyInformationalVersion("5.4.119")] +[assembly: AssemblyVersion("5.4.200")] +[assembly: AssemblyFileVersion("5.4.200.54")] +[assembly: AssemblyInformationalVersion("5.4.200")] #if DEBUG [assembly: AssemblyConfiguration("Debug")] diff --git a/src/Raven.Client/Properties/VersionInfo.cs b/src/Raven.Client/Properties/VersionInfo.cs index ad0676bf2b51..d321ab91fc91 100644 --- a/src/Raven.Client/Properties/VersionInfo.cs +++ b/src/Raven.Client/Properties/VersionInfo.cs @@ -4,7 +4,7 @@ using Raven.Client.Extensions; using Raven.Client.Properties; -[assembly: RavenVersion(Build = "54", CommitHash = "a377982", Version = "5.4", FullVersion = "5.4.119-custom-54", ReleaseDateString = "2024-04-29")] +[assembly: RavenVersion(Build = "54", CommitHash = "a377982", Version = "5.4", FullVersion = "5.4.200-custom-54", ReleaseDateString = "2024-04-29")] namespace Raven.Client.Properties { From 9684dcbebd0272d0322a7c792e28ec5e9a55545d Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Mon, 29 Apr 2024 11:44:26 +0200 Subject: [PATCH 24/27] RavenDB-22322 Use 'release/v5.4' instead of 'v5.4' branch to push "Bump version in $remoteFilePath to $newVersion" commit --- scripts/version.ps1 | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/scripts/version.ps1 b/scripts/version.ps1 index 7bd58c0439e9..d8cdbdf62422 100644 --- a/scripts/version.ps1 +++ b/scripts/version.ps1 @@ -96,7 +96,7 @@ function BumpVersion ($projectDir, $versionPrefix, $buildType, $dryRun = $False) $repo = @{ "Owner" = "ravendb" "Name" = "ravendb" - "Branch" = "v5.4" + "Branch" = "release/v5.4" } $remoteFilePath = 'src/CommonAssemblyInfo.cs' From a44cc3fa6fa25f5c024a4d5d482ec9e86cf8bfc1 Mon Sep 17 00:00:00 2001 From: Federico Lois Date: Wed, 8 May 2024 14:22:57 -0300 Subject: [PATCH 25/27] RavenDB-22348: ReadBigEndianInt64 is missing advance pointer --- src/Voron/ValueReader.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/Voron/ValueReader.cs b/src/Voron/ValueReader.cs index 3d242405cc94..f1b2b80a2b2b 100644 --- a/src/Voron/ValueReader.cs +++ b/src/Voron/ValueReader.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.IO; using System.Runtime.CompilerServices; using Sparrow; @@ -124,6 +124,7 @@ public long ReadBigEndianInt64() throw new EndOfStreamException(); var val = *(long*) (_val + _pos); + _pos += sizeof(long); return Bits.SwapBytes(val); } From 3894f2909305381ff070a640a1240a6dfb709703 Mon Sep 17 00:00:00 2001 From: Damian Olszewski Date: Wed, 8 May 2024 08:54:50 +0200 Subject: [PATCH 26/27] RavenDB-19844 Add Lucene Unmanaged Allocations to memory usage widget --- .../Cluster/Notifications/MemoryUsageNotificationSender.cs | 3 ++- .../Dashboard/Cluster/Notifications/MemoryUsagePayload.cs | 2 ++ .../typescript/models/resources/widgets/memoryUsage.ts | 3 ++- .../App/views/resources/widgets/memoryUsageWidget.html | 4 ++++ 4 files changed, 10 insertions(+), 2 deletions(-) diff --git a/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs b/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs index 1d211744e6a2..12ee140cbc52 100644 --- a/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs +++ b/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsageNotificationSender.cs @@ -60,7 +60,8 @@ protected override AbstractClusterDashboardNotification CreateNotification() DirtyMemory = dirtyMemoryState.TotalDirty.GetValue(SizeUnit.Bytes), AvailableMemory = memoryInfo.AvailableMemory.GetValue(SizeUnit.Bytes), AvailableMemoryForProcessing = memoryInfo.AvailableMemoryForProcessing.GetValue(SizeUnit.Bytes), - TotalSwapUsage = memoryInfo.TotalSwapUsage.GetValue(SizeUnit.Bytes) + TotalSwapUsage = memoryInfo.TotalSwapUsage.GetValue(SizeUnit.Bytes), + LuceneUnmanagedAllocations = NativeMemory.TotalLuceneUnmanagedAllocationsForSorting }; } } diff --git a/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsagePayload.cs b/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsagePayload.cs index bd85a551fdb1..b543f438372b 100644 --- a/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsagePayload.cs +++ b/src/Raven.Server/Dashboard/Cluster/Notifications/MemoryUsagePayload.cs @@ -26,6 +26,7 @@ public class MemoryUsagePayload : AbstractClusterDashboardNotification public long AvailableMemory { get; set; } public long AvailableMemoryForProcessing { get; set; } public long TotalSwapUsage { get; set; } + public long LuceneUnmanagedAllocations { get; set; } public override ClusterDashboardNotificationType Type => ClusterDashboardNotificationType.MemoryUsage; @@ -47,6 +48,7 @@ public override DynamicJsonValue ToJson() json[nameof(AvailableMemory)] = AvailableMemory; json[nameof(AvailableMemoryForProcessing)] = AvailableMemoryForProcessing; json[nameof(TotalSwapUsage)] = TotalSwapUsage; + json[nameof(LuceneUnmanagedAllocations)] = LuceneUnmanagedAllocations; return json; } diff --git a/src/Raven.Studio/typescript/models/resources/widgets/memoryUsage.ts b/src/Raven.Studio/typescript/models/resources/widgets/memoryUsage.ts index eb9744d128a6..0734809ba6c6 100644 --- a/src/Raven.Studio/typescript/models/resources/widgets/memoryUsage.ts +++ b/src/Raven.Studio/typescript/models/resources/widgets/memoryUsage.ts @@ -19,7 +19,8 @@ class memoryUsage extends historyAwareNodeStats x.SystemCommitLimit); totalSwapUsage = this.dataExtractor(x => x.TotalSwapUsage); totalSwap = this.dataExtractor(x => x.PhysicalMemory != null && x.SystemCommitLimit != null ? x.SystemCommitLimit - x.PhysicalMemory : undefined); - + luceneUnmanagedAllocations = this.dataExtractor(x => x.LuceneUnmanagedAllocations); + workingSetFormatted: KnockoutComputed<[string, string]>; machineMemoryUsage: KnockoutComputed; machineMemoryUsagePercentage: KnockoutComputed; diff --git a/src/Raven.Studio/wwwroot/App/views/resources/widgets/memoryUsageWidget.html b/src/Raven.Studio/wwwroot/App/views/resources/widgets/memoryUsageWidget.html index 9028efef3a14..5aad66434380 100644 --- a/src/Raven.Studio/wwwroot/App/views/resources/widgets/memoryUsageWidget.html +++ b/src/Raven.Studio/wwwroot/App/views/resources/widgets/memoryUsageWidget.html @@ -36,6 +36,10 @@

RavenDB Memory usage

Unmanaged Allocations
+
+
Lucene Unmanaged Allocations
+
+
Encryption Buffers in Use
From 8ce3fa9502af4a2c141662d5171376d3eb21b61f Mon Sep 17 00:00:00 2001 From: Arkadiusz Palinski Date: Thu, 9 May 2024 07:26:14 +0200 Subject: [PATCH 27/27] RavenDB-22257 Making the transaction owner check on tx dispose to be Debug only. Removing the usage of await in the scope of a write transaction in the test and making it sync. Added ConfigureAwait(true) to the transaction replay code to in order to try to get to the original thread (that opened the write tx) so the tests for the tx recorder won't fail in debug. --- .../Documents/ReplayTxCommandHelper.cs | 2 +- src/Voron/Impl/LowLevelTransaction.cs | 16 ++++++++++------ test/RachisTests/BasicTests.cs | 11 ++++++----- test/SlowTests/Voron/Issues/RavenDB_22257.cs | 9 ++++++--- 4 files changed, 23 insertions(+), 15 deletions(-) diff --git a/src/Raven.Server/Documents/ReplayTxCommandHelper.cs b/src/Raven.Server/Documents/ReplayTxCommandHelper.cs index bb1061b42264..427c5715d67c 100644 --- a/src/Raven.Server/Documents/ReplayTxCommandHelper.cs +++ b/src/Raven.Server/Documents/ReplayTxCommandHelper.cs @@ -44,7 +44,7 @@ internal static async IAsyncEnumerable ReplayAsync(DocumentDatab await using (var readersItr = readers.GetAsyncEnumerator()) { await ReadStartRecordingDetailsAsync(readersItr, context, peepingTomStream); - while (await readersItr.MoveNextAsync()) + while (await readersItr.MoveNextAsync().ConfigureAwait(true)) { using (readersItr.Current) { diff --git a/src/Voron/Impl/LowLevelTransaction.cs b/src/Voron/Impl/LowLevelTransaction.cs index 66fd74730904..dcb66f3c24ca 100644 --- a/src/Voron/Impl/LowLevelTransaction.cs +++ b/src/Voron/Impl/LowLevelTransaction.cs @@ -935,8 +935,7 @@ public void Dispose() if (_txState.HasFlag(TxState.Disposed)) return; - if (Flags == TransactionFlags.ReadWrite && NativeMemory.CurrentThreadStats != CurrentTransactionHolder) - ThrowDisposeOfTxMustBeCalledOnTheSameThreadThatCreatedIt(); + EnsureDisposeOfWriteTxIsOnTheSameThreadThatCreatedIt(); try { @@ -1326,11 +1325,16 @@ private static void ThrowAlreadyCommitted() throw new InvalidOperationException("Cannot commit already committed transaction."); } - private void ThrowDisposeOfTxMustBeCalledOnTheSameThreadThatCreatedIt() + [Conditional("DEBUG")] + private void EnsureDisposeOfWriteTxIsOnTheSameThreadThatCreatedIt() { - throw new InvalidOperationException($"Dispose of the transaction must be called from the same thread that created it. " + - $"Transaction {Id} (Flags: {Flags}) was created by {CurrentTransactionHolder.Name}, thread Id: {CurrentTransactionHolder.ManagedThreadId}. " + - $"The dispose was called from {NativeMemory.CurrentThreadStats.Name}, thread Id: {NativeMemory.CurrentThreadStats.ManagedThreadId}"); + if (Flags == TransactionFlags.ReadWrite && NativeMemory.CurrentThreadStats != CurrentTransactionHolder) + { + throw new InvalidOperationException($"Dispose of the write transaction must be called from the same thread that created it. " + + $"Transaction {Id} (Flags: {Flags}) was created by {CurrentTransactionHolder.Name}, thread Id: {CurrentTransactionHolder.ManagedThreadId}. " + + $"The dispose was called from {NativeMemory.CurrentThreadStats.Name}, thread Id: {NativeMemory.CurrentThreadStats.ManagedThreadId}. " + + $"Do you have any await call in the scope of the write transaction?"); + } } public void Rollback() diff --git a/test/RachisTests/BasicTests.cs b/test/RachisTests/BasicTests.cs index f4aaee35d0d2..b0a469a7ce72 100644 --- a/test/RachisTests/BasicTests.cs +++ b/test/RachisTests/BasicTests.cs @@ -2,6 +2,7 @@ using System.Threading; using System.Threading.Tasks; using Raven.Client.ServerWide; +using Raven.Client.Util; using Raven.Server.Rachis; using Raven.Server.ServerWide.Context; using Sparrow.Json; @@ -59,10 +60,10 @@ await ActionWithLeader(async l => } [Fact] - public async Task RavenDB_13659() + public void RavenDB_13659() { - var leader = await CreateNetworkAndGetLeader(1); - var mre = new AsyncManualResetEvent(); + var leader = AsyncHelpers.RunSync(() => CreateNetworkAndGetLeader(1)); + var mre = new ManualResetEventSlim(); var tcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); var currentThread = NativeMemory.CurrentThreadStats.ManagedThreadId; @@ -90,12 +91,12 @@ public async Task RavenDB_13659() using (leader.ContextPool.AllocateOperationContext(out ClusterOperationContext context)) using (context.OpenWriteTransaction()) { - await mre.WaitAsync(); + mre.Wait(); leader.SetNewStateInTx(context, RachisState.Follower, null, leader.CurrentTerm, "deadlock"); context.Transaction.Commit(); } - await tcs.Task; + AsyncHelpers.RunSync(() => tcs.Task); } } } diff --git a/test/SlowTests/Voron/Issues/RavenDB_22257.cs b/test/SlowTests/Voron/Issues/RavenDB_22257.cs index 90a62256564e..0a6f4269017c 100644 --- a/test/SlowTests/Voron/Issues/RavenDB_22257.cs +++ b/test/SlowTests/Voron/Issues/RavenDB_22257.cs @@ -21,8 +21,11 @@ protected override void Configure(StorageEnvironmentOptions options) options.ManualFlushing = true; } - +#if DEBUG [RavenFact(RavenTestCategory.Voron)] +#else + [RavenFact(RavenTestCategory.Voron, Skip = "This test relies on Debug only check - LowLevelTransaction.EnsureDisposeOfWriteTxIsOnTheSameThreadThatCreatedIt()")] +#endif public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() { RequireFileBasedPager(); @@ -48,7 +51,7 @@ public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() { ex = Assert.Throws(() => { - txw1.Dispose(); // this is supposed to throw because we're attempting to dispose write tx from a different thread + txw1.Dispose(); // this is supposed to throw in Debug because we're attempting to dispose write tx from a different thread txw2 = Env.NewLowLevelTransaction(new TransactionPersistentContext(), TransactionFlags.ReadWrite); @@ -60,7 +63,7 @@ public void MustNotAllowToHaveTwoWriteTransactionsConcurrently() newTransactionThread.Join(); - Assert.StartsWith("Dispose of the transaction must be called from the same thread that created it. Transaction 2 (Flags: ReadWrite) was created by", ex.Message); + Assert.StartsWith("Dispose of the write transaction must be called from the same thread that created it. Transaction 2 (Flags: ReadWrite) was created by", ex.Message); }); /*