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

[WIP] Logging policy prototype w/ ILogger #6

Draft
wants to merge 2 commits into
base: logging-policy-prototype
Choose a base branch
from
Draft

[WIP] Logging policy prototype w/ ILogger #6

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
7aca4fb
update
m-redding Jun 11, 2024
12d0297
WIP
m-redding Jun 13, 2024
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
3 changes: 2 additions & 1 deletion eng/Packages.Data.props
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -102,8 +102,9 @@
<PackageReference Update="System.Text.Json" Version="4.7.2" />
<PackageReference Update="System.Text.Encodings.Web" Version="4.7.2" />
<PackageReference Update="System.ValueTuple" Version="4.5.0" />
<PackageReference Update="Microsoft.Bcl.AsyncInterfaces" Version="1.1.1" />
<PackageReference Update="Microsoft.Bcl.AsyncInterfaces" Version="8.0.0" />
<PackageReference Update="Microsoft.CSharp" Version="4.7.0" />
<PackageReference Update="Microsoft.Extensions.Logging.Abstractions" Version="8.0.0"/>

<!-- Azure SDK packages -->
<PackageReference Update="Azure.Communication.Identity" Version="1.3.1" />
Expand Down
70 changes: 3 additions & 67 deletions sdk/core/System.ClientModel/src/Internal/ClientModelEventSource.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -28,30 +28,11 @@ internal sealed class ClientModelEventSource : EventSource
private const int ErrorResponseContentTextBlockEvent = 16;
private const int RequestContentTextEvent = 17;
private const int ExceptionResponseEvent = 18;
private const int BackgroundRefreshFailedEvent = 19;
private const int RequestRedirectEvent = 20;
private const int RequestRedirectBlockedEvent = 21;
private const int RequestRedirectCountExceededEvent = 22;
private const int PipelineTransportOptionsNotAppliedEvent = 23;
private const int PipelineTransportOptionsNotAppliedEvent = 23; // TODO

private ClientModelEventSource(string eventSourceName, string[]? traits) : base(eventSourceName, EventSourceSettings.Default, traits) { }
private ClientModelEventSource(string eventSourceName) : base(eventSourceName, EventSourceSettings.Default) { }

public static ClientModelEventSource Create(string eventSourceName, string[]? traits) => new(eventSourceName, traits);

[Event(BackgroundRefreshFailedEvent, Level = EventLevel.Informational, Message = "Background token refresh [{0}] failed with exception {1}")]
public void BackgroundRefreshFailed(string? requestId, string exception)
{
WriteEvent(BackgroundRefreshFailedEvent, requestId, exception);
}

[NonEvent]
public void Request(PipelineRequest request, string? requestId, string? assemblyName, PipelineMessageSanitizer sanitizer)
{
if (IsEnabled(EventLevel.Informational, EventKeywords.None))
{
Request(requestId, request.Method.ToString(), sanitizer.SanitizeUrl(request.Uri!.AbsoluteUri), FormatHeaders(request.Headers, sanitizer), assemblyName);
}
}
public static ClientModelEventSource Create(string eventSourceName) => new(eventSourceName);

[Event(RequestEvent, Level = EventLevel.Informational, Message = "Request [{0}] {1} {2}\r\n{3}client assembly: {4}")]
[UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026", Justification = "WriteEvent is used with primitive types.")]
Expand All @@ -60,22 +41,6 @@ public void Request(string? requestId, string method, string uri, string headers
WriteEvent(RequestEvent, requestId, method, uri, headers, clientAssembly);
}

[NonEvent]
public void RequestContent(string? requestId, byte[] content, Encoding? textEncoding)
{
if (IsEnabled(EventLevel.Verbose, EventKeywords.None))
{
if (textEncoding is not null)
{
RequestContentText(requestId, textEncoding.GetString(content));
}
else
{
RequestContent(requestId, content);
}
}
}

[Event(RequestContentEvent, Level = EventLevel.Verbose, Message = "Request [{0}] content: {1}")]
[UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026", Justification = "WriteEvent is used with an array with primitive type elements.")]
public void RequestContent(string? requestId, byte[] content)
Expand Down Expand Up @@ -259,34 +224,6 @@ public void ExceptionResponse(string? requestId, string exception)
WriteEvent(ExceptionResponseEvent, requestId, exception);
}

[NonEvent]
public void RequestRedirect(PipelineRequest request, string requestId, Uri redirectUri, PipelineResponse response)
{
if (IsEnabled(EventLevel.Verbose, EventKeywords.None))
{
RequestRedirect(requestId, request.Uri!.AbsoluteUri, redirectUri.AbsoluteUri, response.Status);
}
}

[Event(RequestRedirectEvent, Level = EventLevel.Verbose, Message = "Request [{0}] Redirecting from {1} to {2} in response to status code {3}")]
[UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026", Justification = "WriteEvent is used with primitive types.")]
public void RequestRedirect(string? requestId, string from, string to, int status)
{
WriteEvent(RequestRedirectEvent, requestId, from, to, status);
}

[Event(RequestRedirectBlockedEvent, Level = EventLevel.Warning, Message = "Request [{0}] Insecure HTTPS to HTTP redirect from {1} to {2} was blocked.")]
public void RequestRedirectBlocked(string? requestId, string from, string to)
{
WriteEvent(RequestRedirectBlockedEvent, requestId, from, to);
}

[Event(RequestRedirectCountExceededEvent, Level = EventLevel.Warning, Message = "Request [{0}] Exceeded max number of redirects. Redirect from {1} to {2} blocked.")]
public void RequestRedirectCountExceeded(string? requestId, string from, string to)
{
WriteEvent(RequestRedirectCountExceededEvent, requestId, from, to);
}

[NonEvent]
public void PipelineTransportOptionsNotApplied(Type optionsType)
{
Expand All @@ -302,7 +239,6 @@ public void PipelineTransportOptionsNotApplied(string optionsType)
WriteEvent(PipelineTransportOptionsNotAppliedEvent, optionsType);
}

[NonEvent]
private static string FormatHeaders(IEnumerable<KeyValuePair<string, string>> headers, PipelineMessageSanitizer sanitizer)
{
var stringBuilder = new StringBuilder();
Expand Down
78 changes: 78 additions & 0 deletions sdk/core/System.ClientModel/src/Internal/ClientModelLogMessages.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,78 @@
// Copyright (c) Microsoft Corporation. All rights reserved.
// Licensed under the MIT License.

using System;
using System.Collections.Generic;
using System.Text;
using Microsoft.Extensions.Logging;

namespace System.ClientModel.Internal;

internal static partial class ClientModelLogMessages
{
private const int RequestEvent = 1;
private const int RequestContentEvent = 2;
private const int ResponseEvent = 5;
private const int ResponseContentEvent = 6;
private const int ResponseDelayEvent = 7;
private const int ErrorResponseEvent = 8;
private const int ErrorResponseContentEvent = 9;
private const int RequestRetryingEvent = 10;
private const int ResponseContentBlockEvent = 11;
private const int ErrorResponseContentBlockEvent = 12;
private const int ResponseContentTextEvent = 13;
private const int ErrorResponseContentTextEvent = 14;
private const int ResponseContentTextBlockEvent = 15;
private const int ErrorResponseContentTextBlockEvent = 16;
private const int RequestContentTextEvent = 17;
private const int ExceptionResponseEvent = 18;
private const int PipelineTransportOptionsNotAppliedEvent = 23; // TODO

[LoggerMessage(RequestEvent, LogLevel.Information, "Request [{requestId}] {method} {uri}\r\n{headers}client assembly: {assemblyName}", EventName = "Request")]
public static partial void Request(ILogger logger, string requestId, string method, string uri, string headers, string? assemblyName);

// TODO - these are verbose logs in EventSource, should they be trace logs here?
[LoggerMessage(RequestContentEvent, LogLevel.Information, "Request [{requestId}] content: {content}", EventName = "RequestContent")]
public static partial void RequestContent(ILogger logger, string requestId, byte[] content);

// same as above
[LoggerMessage(RequestContentTextEvent, LogLevel.Information, "Request [{requestId}] content: {content}", EventName="RequestContentText")]
public static partial void RequestContentText(ILogger logger, string requestID, string content);

[LoggerMessage(ResponseEvent, LogLevel.Information, "Response [{requestId}] {status} {reasonPhrase} ({seconds:00.0}s)\r\n{headers}", EventName = "Response")]
public static partial void Response(ILogger logger, string requestID, int status, string reasonPhrase, double seconds, string headers);

// same
[LoggerMessage(ResponseContentEvent, LogLevel.Information, "Response [{requestId}] content: {content}", EventName = "ResponseContent")]
public static partial void ResponseContent(ILogger logger, string requestId, byte[] content);

[LoggerMessage(ResponseContentTextEvent, LogLevel.Information, "Response [{requestId}] content: {content}", EventName = "ResponseContentText")]
public static partial void ResponseContentText(ILogger logger, string requestId, string content);

[LoggerMessage(ResponseContentBlockEvent, LogLevel.Information, "Response [{requestId}] content block {blockNumber}: {content}", EventName = "ResponseContentBlock")]
public static partial void ResponseContentBlock(ILogger logger, string requestId, int blockNumber, byte[] content);

[LoggerMessage(ResponseContentTextBlockEvent, LogLevel.Information, "Response [{requestId}] content block {blockNumber}: {content}", EventName = "ResponseContentTextBlock")]
public static partial void ResponseContentTextBlock(ILogger logger, string requestId, int blockNumber, string content);

[LoggerMessage(ErrorResponseEvent, LogLevel.Warning, "Error response [{requestId}] {status} {reasonPhrase} ({seconds:00.0}s)\r\n{headers}", EventName = "ErrorResponse")]
public static partial void ErrorResponse(ILogger logger, string requestId, int status, string reasonPhrase, double seconds, string headers);

[LoggerMessage(ErrorResponseContentEvent, LogLevel.Warning, "Error response [{requestId}] content: {content}", EventName = "ErrorResponseContent")]
public static partial void ErrorResponseContent(ILogger logger, string requestId, byte[] content);

[LoggerMessage(ErrorResponseContentTextEvent, LogLevel.Warning, "Error response [{requestId}] content: {content}", EventName = "ErrorResponseContentText")]
public static partial void ErrorResponseContentText(ILogger logger, string requestId, string content);

[LoggerMessage(ErrorResponseContentBlockEvent, LogLevel.Warning, "Error response [{requestId}] content block {blockNumber}: {content}", EventName = "ErrorResponseContentBlock")]
public static partial void ErrorResponseContentBlock(ILogger logger, string requestId, int blockNumber, byte[] content);

[LoggerMessage(ErrorResponseContentTextBlockEvent, LogLevel.Warning, "Error response [{requestId}] content block {blockNumber}: {content}", EventName = "ErrorResponseContentTextBlock")]
public static partial void ErrorResponseContentTextBlock(ILogger logger, string requestId, int blockNumber, string content);

[LoggerMessage(RequestRetryingEvent, LogLevel.Information, "Request [{requestId}] attempt number {retryCount} took {seconds:00.0}s", EventName = "RequestRetrying")]
public static partial void RequestRetrying(ILogger logger, string requestId, int retryCount, double seconds);

[LoggerMessage(ExceptionResponseEvent, LogLevel.Information, "Request [{requestId}] exception {exception}", EventName = "ExceptionResponse")]
public static partial void ExceptionResponse(ILogger logger, string requestId, string exception);
}
16 changes: 16 additions & 0 deletions sdk/core/System.ClientModel/src/Options/LoggingOptions.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@

using System.Collections.Generic;
using System.Collections.ObjectModel;
using Microsoft.Extensions.Logging;

namespace System.ClientModel.Primitives;

Expand Down Expand Up @@ -48,6 +49,7 @@ public class LoggingOptions
private IList<string> _allowedQueryParameters = new List<string>(s_defaultAllowedQueryParameters);
private string? _clientAssembly;
private string? _requestIdHeaderName;
private ILoggerFactory? _loggerFactory;

/// <summary>
/// Get or sets value indicating whether HTTP pipeline logging is enabled.
Expand All @@ -63,6 +65,20 @@ public bool IsLoggingEnabled
}
}

/// <summary>
/// TODO.
/// </summary>
public ILoggerFactory? LoggerFactory
{
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Opted to do ILoggerFactory over ILogger b/c:

If you're designing a public API that must remain stable over time, keep in mind that you might desire to refactor your internal implementation in the future. Even if a class doesn't create any internal helper types initially, that might change as the code evolves. Using ILoggerFactory accommodates creating new ILogger objects for any new classes without changing the public API.

https://learn.microsoft.com/en-us/dotnet/core/extensions/logging-library-authors#when-to-use-the-iloggerfactory-interface

get => _loggerFactory;
set
{
AssertNotFrozen();

_loggerFactory = value;
}
}

/// <summary>
/// Gets or sets value indicating if request or response content should be logged.
/// </summary>
Expand Down
Loading