From d42026884733ebb972be3cfa1dc3140f801a6104 Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Thu, 1 Aug 2024 17:43:41 -0700 Subject: [PATCH 01/20] allow the sanitizers to clear --- .../AdminTests.cs | 8 +++--- .../Azure.Sdk.Tools.TestProxy/Admin.cs | 25 +++++-------------- .../Common/SanitizerDictionary.cs | 4 +-- 3 files changed, 11 insertions(+), 26 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs index a925c4c9ce3..0553b16bcb5 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs @@ -965,7 +965,7 @@ public async Task RemoveSanitizerErrorsForInvalidIdOnRecording() } [Fact] - public async Task RemoveSanitizerErrorsForInvalidId() + public async Task RemoveSanitizersSilentlyAcceptsInvalidSanitizer() { RecordingHandler testRecordingHandler = new RecordingHandler(Directory.GetCurrentDirectory()); var httpContext = new DefaultHttpContext(); @@ -980,11 +980,9 @@ public async Task RemoveSanitizerErrorsForInvalidId() var testSet = new RemoveSanitizerList() { Sanitizers = new List() { "AZSDK00-1" } }; - var assertion = await Assert.ThrowsAsync( - async () => await controller.RemoveSanitizers(testSet) - ); + await controller.RemoveSanitizers(testSet); - Assert.Equal("Unable to remove 1 sanitizer. Detailed list follows: \nThe requested sanitizer for removal \"AZSDK00-1\" is not active at the session level.", assertion.Message); + Assert.Equal(200, httpContext.Response.StatusCode); } [Fact] diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs index 91f1610af61..60c5874a454 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs @@ -70,7 +70,6 @@ public async Task RemoveSanitizers([FromBody]RemoveSanitizerList sanitizerList) var recordingId = RecordingHandler.GetHeader(Request, "x-recording-id", allowNulls: true); var removedSanitizers = new List(); - var exceptionsList = new List(); if (sanitizerList.Sanitizers.Count == 0) { @@ -78,31 +77,19 @@ public async Task RemoveSanitizers([FromBody]RemoveSanitizerList sanitizerList) } foreach(var sanitizerId in sanitizerList.Sanitizers) { - try + var removedId = await _recordingHandler.UnregisterSanitizer(sanitizerId, recordingId); + if (!string.IsNullOrWhiteSpace(removedId)) { - var removedId = await _recordingHandler.UnregisterSanitizer(sanitizerId, recordingId); removedSanitizers.Add(sanitizerId); } - catch (HttpException ex) { - exceptionsList.Add(ex.Message); - } } - if (exceptionsList.Count > 0) - { - var varExceptionMessage = $"Unable to remove {exceptionsList.Count} sanitizer{(exceptionsList.Count > 1 ? 's' : string.Empty)}. Detailed list follows: \n" - + string.Join("\n", exceptionsList); - throw new HttpException(HttpStatusCode.BadRequest, varExceptionMessage); - } - else - { - var json = JsonSerializer.Serialize(new { Removed = removedSanitizers }); + var json = JsonSerializer.Serialize(new { Removed = removedSanitizers }); - Response.ContentType = "application/json"; - Response.ContentLength = json.Length; + Response.ContentType = "application/json"; + Response.ContentLength = json.Length; - await Response.WriteAsync(json); - } + await Response.WriteAsync(json); } [HttpGet] diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs index de5a49e5ddf..792ebce87c1 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs @@ -892,7 +892,7 @@ public async Task Unregister(string sanitizerId) SessionSanitizerLock.Release(); } - throw new HttpException(System.Net.HttpStatusCode.BadRequest, $"The requested sanitizer for removal \"{sanitizerId}\" is not active at the session level."); + return string.Empty; } /// @@ -918,7 +918,7 @@ public async Task Unregister(string sanitizerId, ModifiableRecordSession session.SanitizerLock.Release(); } - throw new HttpException(System.Net.HttpStatusCode.BadRequest, $"The requested sanitizer for removal \"{sanitizerId}\" is not active on recording/playback with id \"{session.SessionId}\"."); + return string.Empty; } /// From 8d4d2215052252318721b7b85c63333b95158a12 Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Thu, 1 Aug 2024 17:51:36 -0700 Subject: [PATCH 02/20] remove a test that doesn't have a point if we don't error on sanitizer removal --- .../AdminTests.cs | 26 ------------------- 1 file changed, 26 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs index 0553b16bcb5..cbb80b4e769 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/AdminTests.cs @@ -938,32 +938,6 @@ public async Task TestAddSanitizerContinuesWithTwoRequiredParams() Assert.Equal(targetString, actualTargetString); } - [Fact] - public async Task RemoveSanitizerErrorsForInvalidIdOnRecording() - { - RecordingHandler testRecordingHandler = new RecordingHandler(Directory.GetCurrentDirectory()); - var httpContext = new DefaultHttpContext(); - await testRecordingHandler.StartPlaybackAsync("Test.RecordEntries/oauth_request_with_variables.json", httpContext.Response); - var recordingId = httpContext.Response.Headers["x-recording-id"]; - httpContext.Request.Headers["x-recording-id"] = recordingId; - httpContext.Response.Body = new MemoryStream(); - var controller = new Admin(testRecordingHandler, _nullLogger) - { - ControllerContext = new ControllerContext() - { - HttpContext = httpContext - } - }; - - var testSet = new RemoveSanitizerList() { Sanitizers = new List() { "0" } }; - - var assertion = await Assert.ThrowsAsync( - async () => await controller.RemoveSanitizers(testSet) - ); - - Assert.Contains("Unable to remove 1 sanitizer. Detailed list follows: \nThe requested sanitizer for removal \"0\" is not active on recording/playback with id", assertion.Message); - } - [Fact] public async Task RemoveSanitizersSilentlyAcceptsInvalidSanitizer() { From c57ce50c2a7bd9604110c15dda00ddd68ec83eb9 Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Fri, 2 Aug 2024 10:44:09 -0700 Subject: [PATCH 03/20] use a unified lock for all access to a recording. this should enforce the ordering we want --- .../Common/ModifiableRecordSession.cs | 6 ++---- .../Common/SanitizerDictionary.cs | 8 ++++---- .../Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 4 ++-- 3 files changed, 8 insertions(+), 10 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs index 1be776abde9..2e0741361fd 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs @@ -42,8 +42,6 @@ public ModifiableRecordSession(RecordSession session, SanitizerDictionary saniti public List AdditionalTransforms { get; } = new List(); - public SemaphoreSlim SanitizerLock = new SemaphoreSlim(1); - public List AppliedSanitizers { get; set; } = new List(); public List ForRemoval { get; } = new List(); @@ -53,7 +51,7 @@ public ModifiableRecordSession(RecordSession session, SanitizerDictionary saniti public async void ResetExtensions(SanitizerDictionary sanitizerDictionary) { - await SanitizerLock.WaitAsync(); + await Session.EntryLock.WaitAsync(); try { AdditionalTransforms.Clear(); @@ -66,7 +64,7 @@ public async void ResetExtensions(SanitizerDictionary sanitizerDictionary) } finally { - SanitizerLock.Release(); + Session.EntryLock.Release(); } } } diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs index 792ebce87c1..1fdd66e2148 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs @@ -749,7 +749,7 @@ public async Task> GetSanitizers() /// public async Task> GetRegisteredSanitizers(ModifiableRecordSession session) { - await session.SanitizerLock.WaitAsync(); + await session.Session.EntryLock.WaitAsync(); try { var sanitizers = new List(); @@ -770,7 +770,7 @@ public async Task> GetRegisteredSanitizers(ModifiableR } finally { - session.SanitizerLock.Release(); + session.Session.EntryLock.Release(); } } @@ -904,7 +904,7 @@ public async Task Unregister(string sanitizerId) /// public async Task Unregister(string sanitizerId, ModifiableRecordSession session) { - await session.SanitizerLock.WaitAsync(); + await session.Session.EntryLock.WaitAsync(); try { if (session.AppliedSanitizers.Contains(sanitizerId)) @@ -915,7 +915,7 @@ public async Task Unregister(string sanitizerId, ModifiableRecordSession } finally { - session.SanitizerLock.Release(); + session.Session.EntryLock.Release(); } return string.Empty; diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 59f540977da..e2320a93822 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -461,7 +461,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming if (!session.IsSanitized) { // we don't need to re-sanitize with recording-applicable sanitizers every time. just the very first one - await session.SanitizerLock.WaitAsync(); + await session.Session.EntryLock.WaitAsync(); try { if (!session.IsSanitized) @@ -472,7 +472,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming } finally { - session.SanitizerLock.Release(); + session.Session.EntryLock.Release(); } } From cdf3030ec0e05d25ceaf383a0d0472108017c0ee Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sat, 3 Aug 2024 21:35:04 -0700 Subject: [PATCH 04/20] Creating an audit log so we can see raw associated information for important events about a specific recording. --- .../Azure.Sdk.Tools.TestProxy/Audit.cs | 94 +++++++++++++++++++ .../Common/AuditLogItem.cs | 41 ++++++++ .../Common/DebugLogger.cs | 1 + .../Common/ModifiableRecordSession.cs | 6 +- .../Common/SanitizerDictionary.cs | 4 + .../Properties/launchSettings.json | 1 + .../RecordingHandler.cs | 60 +++++++++++- 7 files changed, 204 insertions(+), 3 deletions(-) create mode 100644 tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs create mode 100644 tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs new file mode 100644 index 00000000000..9346a623f78 --- /dev/null +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs @@ -0,0 +1,94 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +using Azure.Sdk.Tools.TestProxy.Common; +using Azure.Sdk.Tools.TestProxy.Common.Exceptions; +using Azure.Sdk.Tools.TestProxy.Store; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.Mvc; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; +using System; +using System.Collections.Generic; +using System.Net; +using System.Text; +using System.Threading.Tasks; + +namespace Azure.Sdk.Tools.TestProxy +{ + [ApiController] + [Route("[controller]/[action]")] + public sealed class Audit : ControllerBase + { + private readonly ILogger _logger; + private readonly RecordingHandler _recordingHandler; + + public Audit(RecordingHandler recordingHandler, ILoggerFactory loggerFactory) + { + _recordingHandler = recordingHandler; + _logger = loggerFactory.CreateLogger(); + } + + [HttpGet] + public async Task GetAuditLogs() + { + + var allAuditSessions = _recordingHandler.RetrieveOngoingAuditLogs(); + allAuditSessions.AddRange(_recordingHandler.AuditSessions.Values); + + StringBuilder stringBuilder = new StringBuilder(); + + foreach (var auditLogQueue in allAuditSessions) { + while (auditLogQueue.TryDequeue(out var logItem)) + { + stringBuilder.Append(logItem.ToCsvString() + Environment.NewLine); + } + } + + Response.ContentType = "text/plain"; + + await Response.WriteAsync(stringBuilder.ToString()); + } + + + [HttpPost] + public async Task Push([FromBody()] IDictionary options = null) + { + DebugLogger.LogAdminRequestDetails(_logger, Request); + + var pathToAssets = RecordingHandler.GetAssetsJsonLocation(StoreResolver.ParseAssetsJsonBody(options), _recordingHandler.ContextDirectory); + + await _recordingHandler.Store.Push(pathToAssets); + } + + [HttpPost] + [AllowEmptyBody] + public async Task Stop([FromBody()] IDictionary variables = null) + { + string id = RecordingHandler.GetHeader(Request, "x-recording-id"); + bool save = true; + EntryRecordMode mode = RecordingHandler.GetRecordMode(Request); + + if (mode != EntryRecordMode.Record && mode != EntryRecordMode.DontRecord) + { + throw new HttpException(HttpStatusCode.BadRequest, "When stopping a recording and providing a \"x-recording-skip\" value, only value \"request-response\" is accepted."); + } + + if (mode == EntryRecordMode.DontRecord) + { + save = false; + } + + DebugLogger.LogAdminRequestDetails(_logger, Request); + + await _recordingHandler.StopRecording(id, variables: variables, saveRecording: save); + } + + public async Task HandleRequest() + { + string id = RecordingHandler.GetHeader(Request, "x-recording-id"); + + await _recordingHandler.HandleRecordRequestAsync(id, Request, Response); + } + } +} diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs new file mode 100644 index 00000000000..4b70ec4d43b --- /dev/null +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs @@ -0,0 +1,41 @@ +using System; +using System.Collections.Concurrent; +using Microsoft.AspNetCore.Mvc.ModelBinding; + +namespace Azure.Sdk.Tools.TestProxy.Common +{ + public class AuditLogItem + { + public string RecordingId { get; set; } + + public DateTime Timestamp { get; set; } + + public string Uri { get; set; } + + public string Verb { get; set; } + + public string Message { get; set; } + + public AuditLogItem(string recordingId, string requestUri, string requestMethod) { + RecordingId = recordingId; + Timestamp = DateTime.UtcNow; + + Uri = requestUri; + Verb = requestMethod; + } + + public string ToCsvString() + { + return $"{RecordingId},{Timestamp.ToString("o")},{Verb},{Uri},{Message}"; + } + + public AuditLogItem(string recordingId, string message) + { + RecordingId = recordingId; + Timestamp = DateTime.UtcNow; + + Message = message; + } + + } +} diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/DebugLogger.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/DebugLogger.cs index a6f41f12a1e..b80a7ed0bf5 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/DebugLogger.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/DebugLogger.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using System.Text.Json; using Microsoft.AspNetCore.Http.Extensions; +using System.Collections.Concurrent; namespace Azure.Sdk.Tools.TestProxy.Common { diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs index 2e0741361fd..61154cd8847 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/ModifiableRecordSession.cs @@ -1,4 +1,5 @@ using System; +using System.Collections.Concurrent; using System.Collections.Generic; using System.Linq; using System.Net.Http; @@ -9,13 +10,13 @@ namespace Azure.Sdk.Tools.TestProxy.Common { public class ModifiableRecordSession { - public RecordMatcher CustomMatcher { get; set;} + public RecordMatcher CustomMatcher { get; set; } public RecordSession Session { get; } public ModifiableRecordSession(SanitizerDictionary sanitizerRegistry, string sessionId) { - lock(sanitizerRegistry.SessionSanitizerLock) + lock (sanitizerRegistry.SessionSanitizerLock) { this.AppliedSanitizers = sanitizerRegistry.SessionSanitizers.ToList(); } @@ -49,6 +50,7 @@ public ModifiableRecordSession(RecordSession session, SanitizerDictionary saniti public int PlaybackResponseTime { get; set; } + public ConcurrentQueue AuditLog { get; set; } = new ConcurrentQueue(); public async void ResetExtensions(SanitizerDictionary sanitizerDictionary) { await Session.EntryLock.WaitAsync(); diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs index 1fdd66e2148..d70d4d315db 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs @@ -850,6 +850,8 @@ public async Task Register(ModifiableRecordSession session, RecordedTest { var strCurrent = IdFactory.GetNextId().ToString(); + session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Starting registration of sanitizerId {strCurrent}")); + await SessionSanitizerLock.WaitAsync(); try { @@ -867,6 +869,7 @@ public async Task Register(ModifiableRecordSession session, RecordedTest SessionSanitizerLock.Release(); } + session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Finished registration of sanitizerId {strCurrent}")); return string.Empty; } @@ -917,6 +920,7 @@ public async Task Unregister(string sanitizerId, ModifiableRecordSession { session.Session.EntryLock.Release(); } + session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Starting unregister of {sanitizerId}.")); return string.Empty; } diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json index 77fea943f32..3d19882983f 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json @@ -2,6 +2,7 @@ "profiles": { "Azure.Sdk.Tools.TestProxy": { "commandName": "Project", + "commandLineArgs": "--storage-location=C:/repo/azure-sdk-for-python", "environmentVariables": { "ASPNETCORE_ENVIRONMENT": "Development", "Logging__LogLevel__Microsoft": "Information" diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index e2320a93822..bf2159bb1de 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -8,6 +8,7 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.Extensions.Primitives; using System; +using System.Collections; using System.Collections.Concurrent; using System.Collections.Generic; using System.IO; @@ -81,6 +82,48 @@ public readonly ConcurrentDictionary InMemorySe public readonly ConcurrentDictionary PlaybackSessions = new ConcurrentDictionary(); + // as sessions are popped off, + public readonly ConcurrentDictionary> AuditSessions + = new ConcurrentDictionary>(); + + + /// + /// This exists to grab any sessions that might be ongoing. I don't have any evidence that sessions are being left behind, but + /// we have to have this to be certain! + /// + /// + public List> RetrieveOngoingAuditLogs() + { + List> results = new List>(); + + if (PlaybackSessions.Keys.Any()) + { + foreach(var value in PlaybackSessions.Values) + { + results.Add(value.AuditLog); + } + } + + if (RecordingSessions.Keys.Any()) + { + foreach (var value in RecordingSessions.Values) + { + results.Add(value.AuditLog); + } + } + + if (InMemorySessions.Keys.Any()) + { + foreach (var value in InMemorySessions.Values) + { + results.Add(value.AuditLog); + } + } + + return results; + } + + public RecordingHandler(string targetDirectory, IAssetsStore store = null, StoreResolver storeResolver = null) { ContextDirectory = targetDirectory; @@ -429,6 +472,11 @@ public void StopPlayback(string recordingId, bool purgeMemoryStore = false) throw new HttpException(HttpStatusCode.BadRequest, $"There is no active playback session under recording id {recordingId}."); } + if (!AuditSessions.TryAdd(recordingId, session.AuditLog)) + { + DebugLogger.LogError($"Unable to save audit log for {recordingId}"); + } + if (!String.IsNullOrEmpty(session.SourceRecordingId) && purgeMemoryStore) { if (!InMemorySessions.TryGetValue(session.SourceRecordingId, out var inMemorySession)) @@ -455,6 +503,9 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming { throw new HttpException(HttpStatusCode.BadRequest, $"There is no active playback session under recording id {recordingId}."); } + + RecordEntry nobodyEntry = RecordingHandler.CreateNoBodyRecordEntry(incomingRequest); + session.AuditLog.Enqueue(new AuditLogItem(recordingId, nobodyEntry.RequestUri, nobodyEntry.RequestMethod.ToString())); var sanitizers = await SanitizerRegistry.GetSanitizers(session); @@ -466,6 +517,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming { if (!session.IsSanitized) { + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"In 'one-time' sanitization for {recordingId}. I am applying {sanitizers.Count} sanitizers.")); await session.Session.Sanitize(sanitizers, false); session.IsSanitized = true; } @@ -473,6 +525,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming finally { session.Session.EntryLock.Release(); + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Finished 'one-time' sanitization for {recordingId}. I applied {sanitizers.Count} sanitizers.")); } } @@ -508,7 +561,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming { outgoingResponse.ContentLength = bodyData.Length; } - + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Beginning body write for {recordingId}.")); await WriteBodyBytes(bodyData, session.PlaybackResponseTime, outgoingResponse); } @@ -526,6 +579,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming if (remove) { + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Now popping entry {match.RequestUri} from entries for {recordingId}.")); await session.Session.Remove(match, shouldLock: false); } } @@ -931,6 +985,9 @@ public async Task UnregisterSanitizer(string sanitizerId, string recordi if (!string.IsNullOrWhiteSpace(recordingId)) { var session = GetActiveSession(recordingId); + + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Starting unregister of {sanitizerId}.")); + return await SanitizerRegistry.Unregister(sanitizerId, session); } @@ -943,6 +1000,7 @@ public async Task RegisterSanitizer(RecordedTestSanitizer sanitizer, str { var session = GetActiveSession(recordingId); + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Starting registration of sanitizer {sanitizer.GetType()}")); return await SanitizerRegistry.Register(session, sanitizer); } From 8bcc5a2392794520999ddcf6ca28c00d9d6d4e8a Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sat, 3 Aug 2024 22:22:49 -0700 Subject: [PATCH 05/20] a couple more audit items! --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 3 +++ 1 file changed, 3 insertions(+) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index bf2159bb1de..28d111c3652 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -416,6 +416,7 @@ public async Task StartPlaybackAsync(string sessionId, HttpResponse outgoingResp DebugLogger.LogTrace($"PLAYBACK START BEGIN {id}."); ModifiableRecordSession session = new ModifiableRecordSession(SanitizerRegistry, id); + session.AuditLog.Enqueue(new AuditLogItem(id, $"Starting playback for path {assetsPath}, which will return recordingId {id}.")); if (mode == RecordingType.InMemory) { @@ -472,6 +473,8 @@ public void StopPlayback(string recordingId, bool purgeMemoryStore = false) throw new HttpException(HttpStatusCode.BadRequest, $"There is no active playback session under recording id {recordingId}."); } + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Stopping playback for {recordingId}.")); + if (!AuditSessions.TryAdd(recordingId, session.AuditLog)) { DebugLogger.LogError($"Unable to save audit log for {recordingId}"); From ff853eaddf6a16cbb18f8a3c18eb0b21148755ca Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sat, 3 Aug 2024 22:52:46 -0700 Subject: [PATCH 06/20] fix the issue with missing audit entry --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 28d111c3652..2a4d05e36ff 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -416,7 +416,7 @@ public async Task StartPlaybackAsync(string sessionId, HttpResponse outgoingResp DebugLogger.LogTrace($"PLAYBACK START BEGIN {id}."); ModifiableRecordSession session = new ModifiableRecordSession(SanitizerRegistry, id); - session.AuditLog.Enqueue(new AuditLogItem(id, $"Starting playback for path {assetsPath}, which will return recordingId {id}.")); + var auditEntry = new AuditLogItem(id, $"Starting playback for path {assetsPath}, which will return recordingId {id}."); if (mode == RecordingType.InMemory) { @@ -443,6 +443,7 @@ public async Task StartPlaybackAsync(string sessionId, HttpResponse outgoingResp { Path = path }; + session.AuditLog.Enqueue(auditEntry); } if (!PlaybackSessions.TryAdd(id, session)) From fb3aed79c08b34f8093fdadc01b64bb1a47b4ec4 Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sat, 3 Aug 2024 23:50:17 -0700 Subject: [PATCH 07/20] still logging the wrong thing --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 2a4d05e36ff..fa440e3c6c0 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -416,7 +416,7 @@ public async Task StartPlaybackAsync(string sessionId, HttpResponse outgoingResp DebugLogger.LogTrace($"PLAYBACK START BEGIN {id}."); ModifiableRecordSession session = new ModifiableRecordSession(SanitizerRegistry, id); - var auditEntry = new AuditLogItem(id, $"Starting playback for path {assetsPath}, which will return recordingId {id}."); + var auditEntry = new AuditLogItem(id, $"Starting playback for path {sessionId}, which will return recordingId {id}."); if (mode == RecordingType.InMemory) { From 0ee3567bd710a7c1b56b804a4433f9fd2fdc798f Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sat, 3 Aug 2024 23:51:47 -0700 Subject: [PATCH 08/20] we need to add a bit more details --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index fa440e3c6c0..0cd0005e575 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -583,7 +583,7 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming if (remove) { - session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Now popping entry {match.RequestUri} from entries for {recordingId}.")); + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Now popping entry {entry.RequestMethod} {match.RequestUri} from entries for {recordingId}.")); await session.Session.Remove(match, shouldLock: false); } } From c1e74354252827f9d122f8e3a9bd1d0ddd36e82f Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sun, 4 Aug 2024 00:11:38 -0700 Subject: [PATCH 09/20] oh my gosh! I was using the session sanitizer lock ACROSS THE BOARD --- .../Azure.Sdk.Tools.TestProxy/Admin.cs | 19 ++------ .../Common/SanitizerDictionary.cs | 28 +++++++++--- .../RecordingHandler.cs | 43 +++++++++++++++++++ 3 files changed, 68 insertions(+), 22 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs index 60c5874a454..c59f518e58e 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs @@ -158,22 +158,11 @@ public async Task AddSanitizers() throw new HttpException(HttpStatusCode.BadRequest, "When bulk adding sanitizers, ensure there is at least one sanitizer added in each batch. Received 0 work items."); } - var registeredSanitizers = new List(); + // we need check if a recording id is present BEFORE the loop, as we want to encapsulate the entire + // sanitizer add operation in a single lock, rather than gathering and releasing a sanitizer lock + // for the session/recording on _each_ sanitizer addition. - // register them all - foreach(var sanitizer in workload) - { - if (recordingId != null) - { - var registeredId = await _recordingHandler.RegisterSanitizer(sanitizer, recordingId); - registeredSanitizers.Add(registeredId); - } - else - { - var registeredId = await _recordingHandler.RegisterSanitizer(sanitizer); - registeredSanitizers.Add(registeredId); - } - } + var registeredSanitizers = await _recordingHandler.RegisterSanitizers(workload, recordingId); if (recordingId != null) { diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs index d70d4d315db..100d2ecf9fe 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs @@ -816,14 +816,19 @@ private bool _register(RecordedTestSanitizer sanitizer, string id) /// /// Ensuring that session level sanitizers can be identified internally /// - /// + /// The sanitizer being registered + /// /// The Id of the newly registered sanitizer. /// - public async Task Register(RecordedTestSanitizer sanitizer) + public async Task Register(RecordedTestSanitizer sanitizer, bool shouldLock = true) { var strCurrent = IdFactory.GetNextId().ToString(); - await SessionSanitizerLock.WaitAsync(); + if (shouldLock) + { + await SessionSanitizerLock.WaitAsync(); + } + try { if (_register(sanitizer, strCurrent)) @@ -834,7 +839,10 @@ public async Task Register(RecordedTestSanitizer sanitizer) } finally { - SessionSanitizerLock.Release(); + if (shouldLock) + { + SessionSanitizerLock.Release(); + } } throw new HttpException(System.Net.HttpStatusCode.InternalServerError, $"Unable to register global sanitizer id \"{strCurrent}\" with value '{JsonSerializer.Serialize(sanitizer)}'"); } @@ -846,13 +854,16 @@ public async Task Register(RecordedTestSanitizer sanitizer) /// /// The Id of the newly registered sanitizer. /// - public async Task Register(ModifiableRecordSession session, RecordedTestSanitizer sanitizer) + public async Task Register(ModifiableRecordSession session, RecordedTestSanitizer sanitizer, bool shouldLock = true) { var strCurrent = IdFactory.GetNextId().ToString(); session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Starting registration of sanitizerId {strCurrent}")); - await SessionSanitizerLock.WaitAsync(); + if(shouldLock) + { + await session.Session.EntryLock.WaitAsync(); + } try { @@ -866,7 +877,10 @@ public async Task Register(ModifiableRecordSession session, RecordedTest } finally { - SessionSanitizerLock.Release(); + if (shouldLock) + { + session.Session.EntryLock.Release(); + } } session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Finished registration of sanitizerId {strCurrent}")); diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 0cd0005e575..7559cd4c49f 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -16,11 +16,13 @@ using System.Net; using System.Net.Http; using System.Net.Security; +using System.Reflection.Metadata.Ecma335; using System.Security.Cryptography.X509Certificates; using System.Text; using System.Text.Json; using System.Threading; using System.Threading.Tasks; +using static System.Collections.Specialized.BitVector32; namespace Azure.Sdk.Tools.TestProxy { @@ -998,6 +1000,47 @@ public async Task UnregisterSanitizer(string sanitizerId, string recordi return await SanitizerRegistry.Unregister(sanitizerId); } + + public async Task> RegisterSanitizers(List sanitizers, string recordingId = null) + { + var registrations = new List(); + + if (!string.IsNullOrWhiteSpace(recordingId)) + { + var session = GetActiveSession(recordingId); + + await session.Session.EntryLock.WaitAsync(); + try + { + foreach (var sanitizer in sanitizers) + { + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Starting registration of sanitizer {sanitizer.GetType()}")); + await SanitizerRegistry.Register(session, sanitizer, shouldLock: false); + } + } + finally + { + session.Session.EntryLock.Release(); + } + } + else + { + await SanitizerRegistry.SessionSanitizerLock.WaitAsync(); + try { + foreach (var sanitizer in sanitizers) + { + registrations.Add(await SanitizerRegistry.Register(sanitizer, shouldLock: false)); + } + } + finally + { + SanitizerRegistry.SessionSanitizerLock.Release(); + } + } + + return registrations; + } + public async Task RegisterSanitizer(RecordedTestSanitizer sanitizer, string recordingId = null) { if (!string.IsNullOrWhiteSpace(recordingId)) From 53bf069ed72d6a66c49b673915bbb779cafe99cb Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sun, 4 Aug 2024 00:18:57 -0700 Subject: [PATCH 10/20] just cleaning up some using --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs | 1 - .../Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs | 2 -- .../Azure.Sdk.Tools.TestProxy/Common/RecordSession.cs | 2 -- .../Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs | 1 - tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 3 --- 5 files changed, 9 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs index 9346a623f78..1df1ec76204 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs @@ -7,7 +7,6 @@ using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Mvc; using Microsoft.Extensions.Logging; -using Microsoft.Extensions.Options; using System; using System.Collections.Generic; using System.Net; diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs index 4b70ec4d43b..f737312221d 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs @@ -1,6 +1,4 @@ using System; -using System.Collections.Concurrent; -using Microsoft.AspNetCore.Mvc.ModelBinding; namespace Azure.Sdk.Tools.TestProxy.Common { diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/RecordSession.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/RecordSession.cs index e7ef8fa41cc..a104e4083ce 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/RecordSession.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/RecordSession.cs @@ -3,8 +3,6 @@ using System; using System.Collections.Generic; -using System.IO; -using System.Linq; using System.Text.Json; using System.Threading; using System.Threading.Tasks; diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs index 100d2ecf9fe..427e46c9b50 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs @@ -2,7 +2,6 @@ using System.Collections.Generic; using System.Linq; using System.Text.Json; -using System.Text.RegularExpressions; using System.Threading; using System.Threading.Tasks; using Azure.Sdk.Tools.TestProxy.Common.Exceptions; diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 7559cd4c49f..9060e6c68c9 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -8,7 +8,6 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.Extensions.Primitives; using System; -using System.Collections; using System.Collections.Concurrent; using System.Collections.Generic; using System.IO; @@ -16,13 +15,11 @@ using System.Net; using System.Net.Http; using System.Net.Security; -using System.Reflection.Metadata.Ecma335; using System.Security.Cryptography.X509Certificates; using System.Text; using System.Text.Json; using System.Threading; using System.Threading.Tasks; -using static System.Collections.Specialized.BitVector32; namespace Azure.Sdk.Tools.TestProxy { From 75334ff841a96bde9b3a9fc10d2d5ae925ee824b Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sun, 4 Aug 2024 19:21:50 -0700 Subject: [PATCH 11/20] ensure that we can't stop playback while streaming a response back --- .../RecordingHandlerTests.cs | 4 +- .../RecordingHandler.cs | 50 ++++++++++++------- 2 files changed, 35 insertions(+), 19 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordingHandlerTests.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordingHandlerTests.cs index 5edb697dea3..633a4a9786b 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordingHandlerTests.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordingHandlerTests.cs @@ -273,7 +273,7 @@ public async Task TestInMemoryPurgesSucessfully() await recordingHandler.StartPlaybackAsync(key, httpContext.Response, Common.RecordingType.InMemory); var playbackSession = httpContext.Response.Headers["x-recording-id"]; - recordingHandler.StopPlayback(playbackSession, true); + await recordingHandler.StopPlayback(playbackSession, true); Assert.True(0 == recordingHandler.InMemorySessions.Count); } @@ -287,7 +287,7 @@ public async Task TestInMemoryDoesntPurgeErroneously() await recordingHandler.StartPlaybackAsync(key, httpContext.Response, Common.RecordingType.InMemory); var playbackSession = httpContext.Response.Headers["x-recording-id"]; - recordingHandler.StopPlayback(playbackSession, false); + await recordingHandler.StopPlayback(playbackSession, false); Assert.True(1 == recordingHandler.InMemorySessions.Count); } diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 9060e6c68c9..9e4edd3c23f 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -462,42 +462,58 @@ public async Task StartPlaybackAsync(string sessionId, HttpResponse outgoingResp DebugLogger.LogTrace($"PLAYBACK START END {id}."); } - public void StopPlayback(string recordingId, bool purgeMemoryStore = false) + public async Task StopPlayback(string recordingId, bool purgeMemoryStore = false) { var id = Guid.NewGuid().ToString(); DebugLogger.LogTrace($"PLAYBACK STOP BEGIN {id}."); - if (!PlaybackSessions.TryRemove(recordingId, out var session)) + + // obtain the playbacksession so we can get grab a lock on it. if there is a streaming response we will HAVE TO WAIT for that to complete + // before we finish + if (!PlaybackSessions.TryGetValue(recordingId, out var session)) { throw new HttpException(HttpStatusCode.BadRequest, $"There is no active playback session under recording id {recordingId}."); } - session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Stopping playback for {recordingId}.")); - - if (!AuditSessions.TryAdd(recordingId, session.AuditLog)) - { - DebugLogger.LogError($"Unable to save audit log for {recordingId}"); - } + await session.Session.EntryLock.WaitAsync(); - if (!String.IsNullOrEmpty(session.SourceRecordingId) && purgeMemoryStore) + try { - if (!InMemorySessions.TryGetValue(session.SourceRecordingId, out var inMemorySession)) + if (!PlaybackSessions.TryRemove(recordingId, out var removedSession)) { - throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to retrieve in-memory session {session.SourceRecordingId}."); + throw new HttpException(HttpStatusCode.BadRequest, $"There is no active playback session under recording id {recordingId}."); } + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Lock obtained, stopping playback for {recordingId}.")); - Interlocked.Add(ref Startup.RequestsRecorded, -1 * inMemorySession.Session.Entries.Count); + if (!AuditSessions.TryAdd(recordingId, session.AuditLog)) + { + DebugLogger.LogError($"Unable to save audit log for {recordingId}"); + } - if (!InMemorySessions.TryRemove(session.SourceRecordingId, out _)) + if (!String.IsNullOrEmpty(session.SourceRecordingId) && purgeMemoryStore) { - throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to remove in-memory session {session.SourceRecordingId}."); + if (!InMemorySessions.TryGetValue(session.SourceRecordingId, out var inMemorySession)) + { + throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to retrieve in-memory session {session.SourceRecordingId}."); + } + + Interlocked.Add(ref Startup.RequestsRecorded, -1 * inMemorySession.Session.Entries.Count); + + if (!InMemorySessions.TryRemove(session.SourceRecordingId, out _)) + { + throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to remove in-memory session {session.SourceRecordingId}."); + } + + GC.Collect(); } - GC.Collect(); + DebugLogger.LogTrace($"PLAYBACK STOP END {id}."); + } + finally + { + session.Session.EntryLock.Release(); } - - DebugLogger.LogTrace($"PLAYBACK STOP END {id}."); } public async Task HandlePlaybackRequest(string recordingId, HttpRequest incomingRequest, HttpResponse outgoingResponse) From 66159a93f175661b69123526a3af3be35dbae899 Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sun, 4 Aug 2024 19:30:04 -0700 Subject: [PATCH 12/20] whoopsy. missed an await --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs index 640af0eb14d..df97f51ec80 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs @@ -55,14 +55,14 @@ public async Task Start() } [HttpPost] - public void Stop() + public async Task Stop() { DebugLogger.LogAdminRequestDetails(_logger, Request); string id = RecordingHandler.GetHeader(Request, "x-recording-id"); bool.TryParse(RecordingHandler.GetHeader(Request, "x-purge-inmemory-recording", true), out var shouldPurgeRecording); - _recordingHandler.StopPlayback(id, purgeMemoryStore: shouldPurgeRecording); + await _recordingHandler.StopPlayback(id, purgeMemoryStore: shouldPurgeRecording); } [HttpPost] From a0f6a71a3fc042598de335eac005549213e2fc06 Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sun, 4 Aug 2024 19:33:33 -0700 Subject: [PATCH 13/20] correct a param --- .../Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs index 427e46c9b50..706dfb742e0 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/SanitizerDictionary.cs @@ -851,6 +851,7 @@ public async Task Register(RecordedTestSanitizer sanitizer, bool shouldL /// /// /// + /// /// The Id of the newly registered sanitizer. /// public async Task Register(ModifiableRecordSession session, RecordedTestSanitizer sanitizer, bool shouldLock = true) From 824573a16cf18e3e3b7910105b7d50b789176007 Mon Sep 17 00:00:00 2001 From: semick-dev Date: Sun, 4 Aug 2024 19:40:21 -0700 Subject: [PATCH 14/20] why is a clean and rebuild not turning up these simple fixes? --- .../Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs index b4a68b67967..aaba7df745c 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs @@ -153,7 +153,7 @@ public async void TestStopPlaybackSimple() var targetRecordingId = httpContext.Response.Headers["x-recording-id"].ToString(); httpContext.Request.Headers["x-recording-id"] = new string[] { targetRecordingId }; - controller.Stop(); + await controller.Stop(); Assert.False(testRecordingHandler.PlaybackSessions.ContainsKey(targetRecordingId)); } @@ -189,7 +189,7 @@ public async void TestStopPlaybackInMemory() await playbackController.Start(); var targetRecordingId = playbackContext.Response.Headers["x-recording-id"].ToString(); playbackContext.Request.Headers["x-recording-id"] = new string[] { targetRecordingId }; - playbackController.Stop(); + await playbackController.Stop(); testRecordingHandler.InMemorySessions.ContainsKey(targetRecordingId); } From fc4b3a69790d6e54fa5ae5e503d47ba832febe8c Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Mon, 5 Aug 2024 11:14:48 -0700 Subject: [PATCH 15/20] reduce the complexity of the cleanup for inmemory sessions --- .../Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 9e4edd3c23f..4e71d5d82b5 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -493,18 +493,13 @@ public async Task StopPlayback(string recordingId, bool purgeMemoryStore = false if (!String.IsNullOrEmpty(session.SourceRecordingId) && purgeMemoryStore) { - if (!InMemorySessions.TryGetValue(session.SourceRecordingId, out var inMemorySession)) + if (!InMemorySessions.TryRemove(session.SourceRecordingId, out var inMemorySession)) { - throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to retrieve in-memory session {session.SourceRecordingId}."); + throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to remove in-memory session {session.SourceRecordingId}."); } Interlocked.Add(ref Startup.RequestsRecorded, -1 * inMemorySession.Session.Entries.Count); - if (!InMemorySessions.TryRemove(session.SourceRecordingId, out _)) - { - throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to remove in-memory session {session.SourceRecordingId}."); - } - GC.Collect(); } From 0a95dd76f05c5be8888f856c488ed3fb11a74ce4 Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Mon, 5 Aug 2024 13:28:02 -0700 Subject: [PATCH 16/20] simply the audit URL. add a couple additional logging items so that we can audit recording --- .../Azure.Sdk.Tools.TestProxy/Audit.cs | 43 +------------------ .../RecordingHandler.cs | 19 ++++++-- 2 files changed, 17 insertions(+), 45 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs index 1df1ec76204..0389ee69409 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs @@ -29,7 +29,7 @@ public Audit(RecordingHandler recordingHandler, ILoggerFactory loggerFactory) } [HttpGet] - public async Task GetAuditLogs() + public async Task Logs() { var allAuditSessions = _recordingHandler.RetrieveOngoingAuditLogs(); @@ -48,46 +48,5 @@ public async Task GetAuditLogs() await Response.WriteAsync(stringBuilder.ToString()); } - - - [HttpPost] - public async Task Push([FromBody()] IDictionary options = null) - { - DebugLogger.LogAdminRequestDetails(_logger, Request); - - var pathToAssets = RecordingHandler.GetAssetsJsonLocation(StoreResolver.ParseAssetsJsonBody(options), _recordingHandler.ContextDirectory); - - await _recordingHandler.Store.Push(pathToAssets); - } - - [HttpPost] - [AllowEmptyBody] - public async Task Stop([FromBody()] IDictionary variables = null) - { - string id = RecordingHandler.GetHeader(Request, "x-recording-id"); - bool save = true; - EntryRecordMode mode = RecordingHandler.GetRecordMode(Request); - - if (mode != EntryRecordMode.Record && mode != EntryRecordMode.DontRecord) - { - throw new HttpException(HttpStatusCode.BadRequest, "When stopping a recording and providing a \"x-recording-skip\" value, only value \"request-response\" is accepted."); - } - - if (mode == EntryRecordMode.DontRecord) - { - save = false; - } - - DebugLogger.LogAdminRequestDetails(_logger, Request); - - await _recordingHandler.StopRecording(id, variables: variables, saveRecording: save); - } - - public async Task HandleRequest() - { - string id = RecordingHandler.GetHeader(Request, "x-recording-id"); - - await _recordingHandler.HandleRecordRequestAsync(id, Request, Response); - } } } diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 4e71d5d82b5..8d72bc707d4 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -20,6 +20,7 @@ using System.Text.Json; using System.Threading; using System.Threading.Tasks; +using static System.Collections.Specialized.BitVector32; namespace Azure.Sdk.Tools.TestProxy { @@ -155,6 +156,9 @@ public async Task StopRecording(string sessionId, IDictionary va return; } + + recordingSession.AuditLog.Enqueue(new AuditLogItem(sessionId, $"Stopping recording for {sessionId}.")); + var sanitizers = await SanitizerRegistry.GetSanitizers(recordingSession); await recordingSession.Session.Sanitize(sanitizers); @@ -214,6 +218,7 @@ public async Task StartRecordingAsync(string sessionId, HttpResponse outgoingRes { var id = Guid.NewGuid().ToString(); DebugLogger.LogTrace($"RECORD START BEGIN {id}."); + var auditEntry = new AuditLogItem(id, $"Starting record for path {sessionId}, which will return recordingId {id}."); await RestoreAssetsJson(assetsJson, false); @@ -223,11 +228,14 @@ public async Task StartRecordingAsync(string sessionId, HttpResponse outgoingRes Client = null }; + session.AuditLog.Enqueue(auditEntry); + if (!RecordingSessions.TryAdd(id, session)) { throw new HttpException(HttpStatusCode.InternalServerError, $"Unexpectedly failed to add new recording session under id {id}."); } + DebugLogger.LogTrace($"RECORD START END {id}."); outgoingResponse.Headers.Add("x-recording-id", id); } @@ -239,6 +247,9 @@ public async Task HandleRecordRequestAsync(string recordingId, HttpRequest incom throw new HttpException(HttpStatusCode.BadRequest, $"There is no active recording session under id {recordingId}."); } + RecordEntry noBodyEntry = RecordingHandler.CreateNoBodyRecordEntry(incomingRequest); + session.AuditLog.Enqueue(new AuditLogItem(recordingId, noBodyEntry.RequestUri, noBodyEntry.RequestMethod.ToString())); + var sanitizers = await SanitizerRegistry.GetSanitizers(session); DebugLogger.LogRequestDetails(incomingRequest, sanitizers); @@ -292,8 +303,9 @@ public async Task HandleRecordRequestAsync(string recordingId, HttpRequest incom if (mode != EntryRecordMode.DontRecord) { await session.Session.EntryLock.WaitAsync(); - try + try { + session.AuditLog.Enqueue(new AuditLogItem(recordingId, $"Lock obtained. Adding entry {entry.RequestMethod} {entry.RequestUri} to session {recordingId}.")); session.Session.Entries.Add(entry); } finally @@ -301,6 +313,7 @@ public async Task HandleRecordRequestAsync(string recordingId, HttpRequest incom session.Session.EntryLock.Release(); } + Interlocked.Increment(ref Startup.RequestsRecorded); } @@ -518,8 +531,8 @@ public async Task HandlePlaybackRequest(string recordingId, HttpRequest incoming throw new HttpException(HttpStatusCode.BadRequest, $"There is no active playback session under recording id {recordingId}."); } - RecordEntry nobodyEntry = RecordingHandler.CreateNoBodyRecordEntry(incomingRequest); - session.AuditLog.Enqueue(new AuditLogItem(recordingId, nobodyEntry.RequestUri, nobodyEntry.RequestMethod.ToString())); + RecordEntry noBodyEntry = RecordingHandler.CreateNoBodyRecordEntry(incomingRequest); + session.AuditLog.Enqueue(new AuditLogItem(recordingId, noBodyEntry.RequestUri, noBodyEntry.RequestMethod.ToString())); var sanitizers = await SanitizerRegistry.GetSanitizers(session); From f2729d71a179bc83c73d6a2185547eddeb1e9672 Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Mon, 5 Aug 2024 13:28:38 -0700 Subject: [PATCH 17/20] update launchSettings to not be different from main --- .../Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json index 3d19882983f..964f0eaddb3 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Properties/launchSettings.json @@ -2,7 +2,7 @@ "profiles": { "Azure.Sdk.Tools.TestProxy": { "commandName": "Project", - "commandLineArgs": "--storage-location=C:/repo/azure-sdk-for-python", + "commandLineArgs": "", "environmentVariables": { "ASPNETCORE_ENVIRONMENT": "Development", "Logging__LogLevel__Microsoft": "Information" From 1ae3a9fbbc692c284d4c4dcfc5dfefdc7fcce0d7 Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Mon, 5 Aug 2024 13:29:43 -0700 Subject: [PATCH 18/20] simplify audit controller even further --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs index 0389ee69409..2245d7f213e 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs @@ -19,13 +19,11 @@ namespace Azure.Sdk.Tools.TestProxy [Route("[controller]/[action]")] public sealed class Audit : ControllerBase { - private readonly ILogger _logger; private readonly RecordingHandler _recordingHandler; - public Audit(RecordingHandler recordingHandler, ILoggerFactory loggerFactory) + public Audit(RecordingHandler recordingHandler) { _recordingHandler = recordingHandler; - _logger = loggerFactory.CreateLogger(); } [HttpGet] From 1295de8565a1d2bc09d1c56ca89e5c67a16eb3ef Mon Sep 17 00:00:00 2001 From: Scott Beddall Date: Mon, 5 Aug 2024 13:44:38 -0700 Subject: [PATCH 19/20] add a couple test cases, ensure that we add a recording session to the audit session as well --- .../PlaybackTests.cs | 8 +++++++- .../RecordSessionTests.cs | 6 ++++++ .../Azure.Sdk.Tools.TestProxy.Tests/TestHelpers.cs | 13 +++++++++++++ .../Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 5 ++++- 4 files changed, 30 insertions(+), 2 deletions(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs index aaba7df745c..7b4c6a9094a 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/PlaybackTests.cs @@ -151,10 +151,16 @@ public async void TestStopPlaybackSimple() }; await controller.Start(); var targetRecordingId = httpContext.Response.Headers["x-recording-id"].ToString(); - + httpContext.Request.Headers["x-recording-id"] = new string[] { targetRecordingId }; await controller.Stop(); + var auditSession = testRecordingHandler.AuditSessions[targetRecordingId]; + + Assert.NotNull(auditSession); + var auditResults = TestHelpers.ExhaustQueue(auditSession); + + Assert.Equal(2, auditResults.Count); Assert.False(testRecordingHandler.PlaybackSessions.ContainsKey(targetRecordingId)); } diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordSessionTests.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordSessionTests.cs index c0f902dc12a..5a91981c648 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordSessionTests.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/RecordSessionTests.cs @@ -165,6 +165,12 @@ public async Task CanRoundTripDockerDigest() session.Session.Entries.Add(testEntry); await handler.StopRecording(recordingId); + // ensure that we audited properly + var auditSession = handler.AuditSessions[recordingId]; + var auditItems = TestHelpers.ExhaustQueue(auditSession); + + Assert.Equal(2, auditItems.Count); + // now load it, did we avoid mangling it? var sessionFromDisk = TestHelpers.LoadRecordSession(Path.Combine(testFolder, testName)); var targetEntry = sessionFromDisk.Session.Entries[0]; diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/TestHelpers.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/TestHelpers.cs index 3fdf58d63bb..c8864a23c80 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/TestHelpers.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/TestHelpers.cs @@ -12,6 +12,7 @@ using Xunit; using System.Threading.Tasks; using System.Security.Cryptography; +using System.Collections.Concurrent; namespace Azure.Sdk.Tools.TestProxy.Tests { @@ -35,6 +36,18 @@ public static class TestHelpers { public static readonly string DisableBranchCleanupEnvVar = "DISABLE_INTEGRATION_BRANCH_CLEANUP"; + public static List ExhaustQueue(ConcurrentQueue queue) + { + List results = new List(); + + while (queue.TryDequeue(out var item)) + { + results.Add(item); + } + + return results; + } + public static string GetValueFromCertificateFile(string certName) { var path = Path.Join(Directory.GetCurrentDirectory(), "Test.Certificates", certName); diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 8d72bc707d4..0f941305acb 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -156,8 +156,11 @@ public async Task StopRecording(string sessionId, IDictionary va return; } - recordingSession.AuditLog.Enqueue(new AuditLogItem(sessionId, $"Stopping recording for {sessionId}.")); + if (!AuditSessions.TryAdd(sessionId, recordingSession.AuditLog)) + { + DebugLogger.LogError($"Unable to save audit log for {sessionId}"); + } var sanitizers = await SanitizerRegistry.GetSanitizers(recordingSession); await recordingSession.Session.Sanitize(sanitizers); From d03340ad0c676455e5150d4a164cdffe7d9a40a1 Mon Sep 17 00:00:00 2001 From: Scott Beddall <45376673+scbedd@users.noreply.github.com> Date: Tue, 6 Aug 2024 08:19:14 -0700 Subject: [PATCH 20/20] Update tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs --- tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs | 1 - 1 file changed, 1 deletion(-) diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs index 0f941305acb..e6dc2eb4b9e 100644 --- a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs +++ b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs @@ -82,7 +82,6 @@ public readonly ConcurrentDictionary InMemorySe public readonly ConcurrentDictionary PlaybackSessions = new ConcurrentDictionary(); - // as sessions are popped off, public readonly ConcurrentDictionary> AuditSessions = new ConcurrentDictionary>();