Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix admin logging #6812

Merged
merged 3 commits into from
Aug 18, 2023
Merged

Fix admin logging #6812

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
ec56622
Fix admin logging
JoshLove-msft Aug 18, 2023
437881d
commit assert fix for multiplat
scbedd Aug 18, 2023
a076aa6
all \r\n -> Environment.NewLine in AssertLogs
scbedd Aug 18, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
91 changes: 66 additions & 25 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/LoggingTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,11 +1,11 @@
using System.IO;
using System;
using System.IO;
using System.Net.Http;
using System.Text;
using System.Threading.Tasks;
using Azure.Sdk.Tools.TestProxy.Common;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging.Abstractions;
using Xunit;

namespace Azure.Sdk.Tools.TestProxy.Tests
Expand All @@ -30,17 +30,20 @@ public async Task PlaybackLogsSanitizedRequest()
httpContext.Request.Body = TestHelpers.GenerateStreamRequestBody(body);
httpContext.Request.ContentLength = body.Length;

var controller = new Playback(testRecordingHandler, new NullLoggerFactory())
var playback = new Playback(testRecordingHandler, new TestLoggingFactory(logger))
{
ControllerContext = new ControllerContext()
{
HttpContext = httpContext
}
};
await controller.Start();
await playback.Start();

var recordingId = httpContext.Response.Headers["x-recording-id"].ToString();
Assert.NotNull(recordingId);

await AddSanitizerAsync(testRecordingHandler, logger);

Assert.True(testRecordingHandler.PlaybackSessions.ContainsKey(recordingId));
var entry = testRecordingHandler.PlaybackSessions[recordingId].Session.Entries[0];
HttpRequest request = TestHelpers.CreateRequestFromEntry(entry);
Expand All @@ -49,10 +52,7 @@ public async Task PlaybackLogsSanitizedRequest()
HttpResponse response = new DefaultHttpContext().Response;
await testRecordingHandler.HandlePlaybackRequest(recordingId, request, response);

Assert.Single(logger.Logs);
var logEntry = logger.Logs[0].ToString();
Assert.DoesNotContain(@"""Authorization"":[""fake-auth-header""]", logEntry);
Assert.Contains(@"""Authorization"":[""Sanitized""]", logEntry);
AssertLogs(logger);
}
finally
{
Expand All @@ -65,11 +65,14 @@ public async Task RecordingHandlerLogsSanitizedRequests()
{
var logger = new TestLogger();
DebugLogger.Logger = logger;

var session = TestHelpers.LoadRecordSession("Test.RecordEntries/request_with_binary_content.json");
var request = TestHelpers.CreateRequestFromEntry(session.Session.Entries[0]);
var httpContext = new DefaultHttpContext();
var bodyBytes = Encoding.UTF8.GetBytes("{\"hello\":\"world\"}");
var mockClient = new HttpClient(new MockHttpHandler(bodyBytes, "application/json"));
var path = Directory.GetCurrentDirectory();
var recordingHandler = new RecordingHandler(path)
var testRecordingHandler = new RecordingHandler(path)
{
RedirectableClient = mockClient,
RedirectlessClient = mockClient
Expand All @@ -78,38 +81,76 @@ public async Task RecordingHandlerLogsSanitizedRequests()
var relativePath = "recordings/logs";
var fullPathToRecording = Path.Combine(path, relativePath) + ".json";

await recordingHandler.StartRecordingAsync(relativePath, httpContext.Response);
await testRecordingHandler.StartRecordingAsync(relativePath, httpContext.Response);

var recordingId = httpContext.Response.Headers["x-recording-id"].ToString();
await AddSanitizerAsync(testRecordingHandler, logger);

httpContext.Request.ContentType = "application/json";
httpContext.Request.Headers["Authorization"] = "fake-auth-header";
httpContext.Request.ContentLength = 0;
httpContext.Request.Headers["x-recording-id"] = recordingId;
httpContext.Request.Headers["x-recording-upstream-base-uri"] = "http://example.org";
httpContext.Request.Method = "GET";
httpContext.Request.Body = new MemoryStream(CompressionUtilities.CompressBody(bodyBytes, httpContext.Request.Headers));
var recordingId = httpContext.Response.Headers["x-recording-id"].ToString();

await recordingHandler.HandleRecordRequestAsync(recordingId, httpContext.Request, httpContext.Response);
recordingHandler.StopRecording(recordingId);
await testRecordingHandler.HandleRecordRequestAsync(recordingId, request, httpContext.Response);
testRecordingHandler.StopRecording(recordingId);

try
{
Assert.Single(logger.Logs);
var logEntry = logger.Logs[0].ToString();
Assert.DoesNotContain(@"""Authorization"":[""fake-auth-header""]", logEntry);
Assert.Contains(@"""Authorization"":[""Sanitized""]", logEntry);
AssertLogs(logger);
}
finally
{
File.Delete(fullPathToRecording);
DebugLogger.Logger = null;
}
}

private static void AssertLogs(TestLogger logger)
{
Assert.Equal(4, logger.Logs.Count);
Assert.Equal(
$"URI: [ http://127.0.0.1:5000/admin/addsanitizer]{Environment.NewLine}Headers: " +
"[{\"Host\":[\"127.0.0.1:5000\"],\"x-abstraction-identifier\":[\"HeaderRegexSanitizer\"]," +
"\"Content-Length\":[\"92\"]}]" + Environment.NewLine,
logger.Logs[0].ToString());
Assert.Equal(
"Request Body Content{\"key\":\"Location\",\"value\":\"https://fakeazsdktestaccount.table.core.windows.net/Tables\"}",
logger.Logs[1].ToString());
// sanitizer request body is currently duplicated for each key/value pair
Assert.Equal(
"Request Body Content{\"key\":\"Location\",\"value\":\"https://fakeazsdktestaccount.table.core.windows.net/Tables\"}",
logger.Logs[2].ToString());
Assert.Equal("URI: [ https://fakeazsdktestaccount.table.core.windows.net/Tables]" +
Environment.NewLine + "Headers: [{\"Accept\":[\"application/json;odata=minimalmetadata\"],\"Accept-Encoding\":[\"gzip, deflate\"],\"Authorization\":[\"Sanitized\"],\"Connection\":[\"keep-alive\"]," +
"\"Content-Length\":[\"12\"],\"Content-Type\":[\"application/octet-stream\"],\"DataServiceVersion\":[\"3.0\"],\"Date\":[\"Tue, 18 May 2021 23:27:42 GMT\"]," +
"\"User-Agent\":[\"azsdk-python-data-tables/12.0.0b7 Python/3.8.6 (Windows-10-10.0.19041-SP0)\"],\"x-ms-client-request-id\":[\"a4c24b7a-b830-11eb-a05e-10e7c6392c5a\"]," +
"\"x-ms-date\":[\"Tue, 18 May 2021 23:27:42 GMT\"],\"x-ms-version\":[\"2019-02-02\"]}]" + Environment.NewLine,
logger.Logs[3].ToString());
}

private static async Task AddSanitizerAsync(RecordingHandler testRecordingHandler, TestLogger logger)
{
var httpContext = new DefaultHttpContext();
httpContext.Request.Scheme = "http";
httpContext.Request.Host = new HostString("127.0.0.1:5000");
httpContext.Request.Path = "/admin/addsanitizer";
httpContext.Request.Headers["x-abstraction-identifier"] = "HeaderRegexSanitizer";
httpContext.Request.Body =
TestHelpers.GenerateStreamRequestBody(
"{ \"key\": \"Location\", \"value\": \"https://fakeazsdktestaccount.table.core.windows.net/Tables\" }");
httpContext.Request.ContentLength = 92;

var admin = new Admin(testRecordingHandler, new TestLoggingFactory(logger))
{
ControllerContext = new ControllerContext()
{
HttpContext = httpContext
}
};
await admin.AddSanitizer();
}
}



[CollectionDefinition(nameof(LoggingCollection), DisableParallelization = true)]
public class LoggingCollection
{
}
}
}
25 changes: 25 additions & 0 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/TestLogger.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,4 +24,29 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
Logs.Add(state);
}
}

public class TestLoggingFactory : ILoggerFactory
{
private readonly TestLogger _logger;

public TestLoggingFactory(TestLogger logger)
{
_logger = logger;
}

public void Dispose()
{
throw new NotImplementedException();
}

public void AddProvider(ILoggerProvider provider)
{
throw new NotImplementedException();
}

public ILogger CreateLogger(string categoryName)
{
return _logger;
}
}
}
12 changes: 6 additions & 6 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy/Admin.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ public Admin(RecordingHandler recordingHandler, ILoggerFactory loggingFactory)
[HttpPost]
public void Reset()
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);
var recordingId = RecordingHandler.GetHeader(Request, "x-recording-id", allowNulls: true);

_recordingHandler.SetDefaultExtensions(recordingId);
Expand All @@ -39,14 +39,14 @@ public void Reset()
[HttpGet]
public void IsAlive()
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);
Response.StatusCode = 200;
}

[HttpPost]
public async Task AddTransform()
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);
var tName = RecordingHandler.GetHeader(Request, "x-abstraction-identifier");
var recordingId = RecordingHandler.GetHeader(Request, "x-recording-id", allowNulls: true);

Expand All @@ -65,7 +65,7 @@ public async Task AddTransform()
[HttpPost]
public async Task AddSanitizer()
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);
var sName = RecordingHandler.GetHeader(Request, "x-abstraction-identifier");
var recordingId = RecordingHandler.GetHeader(Request, "x-recording-id", allowNulls: true);

Expand All @@ -84,7 +84,7 @@ public async Task AddSanitizer()
[HttpPost]
public async Task SetMatcher()
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);
var mName = RecordingHandler.GetHeader(Request, "x-abstraction-identifier");
var recordingId = RecordingHandler.GetHeader(Request, "x-recording-id", allowNulls: true);

Expand All @@ -104,7 +104,7 @@ public async Task SetMatcher()
[AllowEmptyBody]
public void SetRecordingOptions([FromBody()] IDictionary<string, object> options = null)
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);

var recordingId = RecordingHandler.GetHeader(Request, "x-recording-id", allowNulls: true);

Expand Down
9 changes: 7 additions & 2 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy/Common/DebugLogger.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using System;
using System.Collections.Generic;
using System.Text.Json;
using Microsoft.AspNetCore.Http.Extensions;

namespace Azure.Sdk.Tools.TestProxy.Common
{
Expand Down Expand Up @@ -147,11 +148,15 @@ public static void LogDebug(string details)
/// <param name="loggerInstance">Usually will be the DI-ed individual ILogger instance from a controller. However any valid ILogger instance is fine here.</param>
/// <param name="req">The http request which needs to be detailed.</param>
/// <returns></returns>
public static void LogRequestDetails(ILogger loggerInstance, HttpRequest req)
public static void LogAdminRequestDetails(ILogger loggerInstance, HttpRequest req)
{
if(CheckLogLevel(LogLevel.Debug))
{
loggerInstance.LogDebug(_generateLogLine(req, null));
var headers = Encoding.UTF8.GetString(JsonSerializer.SerializeToUtf8Bytes(req.Headers));
StringBuilder sb = new StringBuilder();
sb.AppendLine("URI: [ " + req.GetDisplayUrl() + "]");
sb.AppendLine("Headers: [" + headers + "]");
loggerInstance.LogDebug(sb.ToString());
}
}

Expand Down
4 changes: 2 additions & 2 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@ public void Stop()
[HttpPost]
public async Task Reset([FromBody()] IDictionary<string, object> options = null)
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);

var pathToAssets = RecordingHandler.GetAssetsJsonLocation(StoreResolver.ParseAssetsJsonBody(options), _recordingHandler.ContextDirectory);

Expand All @@ -73,7 +73,7 @@ public async Task Reset([FromBody()] IDictionary<string, object> options = null)
[HttpPost]
public async Task Restore([FromBody()] IDictionary<string, object> options = null)
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);

var pathToAssets = RecordingHandler.GetAssetsJsonLocation(StoreResolver.ParseAssetsJsonBody(options), _recordingHandler.ContextDirectory);

Expand Down
2 changes: 1 addition & 1 deletion tools/test-proxy/Azure.Sdk.Tools.TestProxy/Record.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ public async Task Start()
[HttpPost]
public async Task Push([FromBody()] IDictionary<string, object> options = null)
{
DebugLogger.LogRequestDetails(_logger, Request);
DebugLogger.LogAdminRequestDetails(_logger, Request);

var pathToAssets = RecordingHandler.GetAssetsJsonLocation(StoreResolver.ParseAssetsJsonBody(options), _recordingHandler.ContextDirectory);

Expand Down