Add proxy audit log and other assorted fixes (#8781)

* Use a unified lock for all access to a recording. sanitizers or recording entries. * Creating an audit log so we can see raw associated information for important events about a specific recording. * obtain a lock before stopping playback, ensuring that ongoing writes in other threads won't be broken --------- Co-authored-by: semick-dev <[email protected]>
Azure · Aug 6, 2024 · 920afb2 · 920afb2
1 parent 3c8f30f
commit 920afb2
Show file tree

Hide file tree

Showing 14 changed files with 306 additions and 57 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
@@ -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 };
-            controller.Stop();
+            await controller.Stop();
+
+            var auditSession = testRecordingHandler.AuditSessions[targetRecordingId];
+
+            Assert.NotNull(auditSession);
+            var auditResults = TestHelpers.ExhaustQueue<AuditLogItem>(auditSession);
 
+            Assert.Equal(2, auditResults.Count);
             Assert.False(testRecordingHandler.PlaybackSessions.ContainsKey(targetRecordingId));
         }
 
@@ -189,7 +195,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);
         }

diff --git 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<AuditLogItem>(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/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.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<T> ExhaustQueue<T>(ConcurrentQueue<T> queue)
+        {
+            List<T> results = new List<T>();
+
+            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/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<string>();
+            // 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/Audit.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Audit.cs
@@ -0,0 +1,50 @@
+// 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 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 RecordingHandler _recordingHandler;
+
+        public Audit(RecordingHandler recordingHandler)
+        {
+            _recordingHandler = recordingHandler;
+        }
+
+        [HttpGet]
+        public async Task Logs()
+        {
+
+            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());
+        }
+    }
+}
diff --git a/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs b/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/AuditLogItem.cs
@@ -0,0 +1,39 @@
+using System;
+
+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
@@ -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
@@ -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();
             }
@@ -42,18 +43,17 @@ public ModifiableRecordSession(RecordSession session, SanitizerDictionary saniti
 
         public List<ResponseTransform> AdditionalTransforms { get; } = new List<ResponseTransform>();
 
-        public SemaphoreSlim SanitizerLock = new SemaphoreSlim(1);
-
         public List<string> AppliedSanitizers { get; set; } = new List<string>();
         public List<string> ForRemoval { get; } = new List<string>();
 
         public string SourceRecordingId { get; set; }
 
         public int PlaybackResponseTime { get; set; }
 
+        public ConcurrentQueue<AuditLogItem> AuditLog { get; set; } = new ConcurrentQueue<AuditLogItem>();
         public async void ResetExtensions(SanitizerDictionary sanitizerDictionary)
         {
-            await SanitizerLock.WaitAsync();
+            await Session.EntryLock.WaitAsync();
             try
             {
                 AdditionalTransforms.Clear();
@@ -66,7 +66,7 @@ public async void ResetExtensions(SanitizerDictionary sanitizerDictionary)
             }
             finally
             {
-                SanitizerLock.Release();
+                Session.EntryLock.Release();
             }
         }
     }

diff --git 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
@@ -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;
@@ -749,7 +748,7 @@ public async Task<List<RecordedTestSanitizer>> GetSanitizers()
         /// <returns></returns>
         public async Task<List<RegisteredSanitizer>> GetRegisteredSanitizers(ModifiableRecordSession session)
         {
-            await session.SanitizerLock.WaitAsync();
+            await session.Session.EntryLock.WaitAsync();
             try
             {
                 var sanitizers = new List<RegisteredSanitizer>();
@@ -770,7 +769,7 @@ public async Task<List<RegisteredSanitizer>> GetRegisteredSanitizers(ModifiableR
             }
             finally
             {
-                session.SanitizerLock.Release();
+                session.Session.EntryLock.Release();
             }
         }
 
@@ -816,14 +815,19 @@ private bool _register(RecordedTestSanitizer sanitizer, string id)
         /// <summary>
         /// Ensuring that session level sanitizers can be identified internally
         /// </summary>
-        /// <param name="sanitizer"></param>
+        /// <param name="sanitizer">The sanitizer being registered</param>
+        /// <param name="shouldLock"></param>
         /// <returns>The Id of the newly registered sanitizer.</returns>
         /// <exception cref="HttpException"></exception>
-        public async Task<string> Register(RecordedTestSanitizer sanitizer)
+        public async Task<string> 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 +838,10 @@ public async Task<string> 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)}'");
         }
@@ -844,13 +851,19 @@ public async Task<string> Register(RecordedTestSanitizer sanitizer)
         /// </summary>
         /// <param name="session"></param>
         /// <param name="sanitizer"></param>
+        /// <param name="shouldLock"></param>
         /// <returns>The Id of the newly registered sanitizer.</returns>
         /// <exception cref="HttpException"></exception>
-        public async Task<string> Register(ModifiableRecordSession session, RecordedTestSanitizer sanitizer)
+        public async Task<string> Register(ModifiableRecordSession session, RecordedTestSanitizer sanitizer, bool shouldLock = true)
         {
             var strCurrent = IdFactory.GetNextId().ToString();
 
-            await SessionSanitizerLock.WaitAsync();
+            session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Starting registration of sanitizerId {strCurrent}"));
+
+            if(shouldLock)
+            {
+                await session.Session.EntryLock.WaitAsync();
+            }
             try
             {
 
@@ -864,9 +877,13 @@ public async Task<string> 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}"));
             return string.Empty;
         }
 
@@ -904,7 +921,7 @@ public async Task<string> Unregister(string sanitizerId)
         /// <exception cref="HttpException"></exception>
         public async Task<string> Unregister(string sanitizerId, ModifiableRecordSession session)
         {
-            await session.SanitizerLock.WaitAsync();
+            await session.Session.EntryLock.WaitAsync();
             try
             {
                 if (session.AppliedSanitizers.Contains(sanitizerId))
@@ -915,8 +932,9 @@ public async Task<string> Unregister(string sanitizerId, ModifiableRecordSession
             }
             finally
             {
-                session.SanitizerLock.Release();
+                session.Session.EntryLock.Release();
             }
+            session.AuditLog.Enqueue(new AuditLogItem(session.SessionId, $"Starting unregister of {sanitizerId}."));
 
             return string.Empty;
         }