initial draft

eng/Packages.Data.props

@@ -103,6 +103,7 @@
     <PackageReference Update="System.ValueTuple" Version="4.5.0" />
     <PackageReference Update="Microsoft.Bcl.AsyncInterfaces" Version="6.0.0" />
     <PackageReference Update="Microsoft.CSharp" Version="4.7.0" />
+		<PackageReference Update="Microsoft.Extensions.Logging.Abstractions" Version="6.0.0"/>
 
     <!-- Azure SDK packages -->
     <PackageReference Update="Azure.Communication.Identity" Version="1.3.1" />

sdk/core/System.ClientModel/src/Internal/ClientModelLogMessages.cs

@@ -0,0 +1,82 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Collections.Generic;
+using System.Net.NetworkInformation;
+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(ResponseDelayEvent, LogLevel.Warning, "Response [{requestId}] took {seconds:00.0}s", EventName = "ResponseDelay")]
+    public static partial void ResponseDelay(ILogger logger, string requestId, double seconds);
+
+    [LoggerMessage(ExceptionResponseEvent, LogLevel.Information, "Request [{requestId}] exception {exception}", EventName = "ExceptionResponse")]
+    public static partial void ExceptionResponse(ILogger logger, string requestId, string exception);
+}

sdk/core/System.ClientModel/src/Internal/ContentTypeUtilities.cs

@@ -0,0 +1,57 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System.Text;
+
+namespace System.ClientModel.Internal;
+
+/// <summary>
+/// TODO.
+/// </summary>
+internal class ContentTypeUtilities
+{
+    public static bool TryGetTextEncoding(string contentType, out Encoding? encoding)
+    {
+        const string charsetMarker = "; charset=";
+        const string utf8Charset = "utf-8";
+        const string textContentTypePrefix = "text/";
+        const string jsonSuffix = "json";
+        const string appJsonPrefix = "application/json";
+        const string xmlSuffix = "xml";
+        const string urlEncodedSuffix = "-urlencoded";
+
+        // Default is technically US-ASCII, but will default to UTF-8 which is a superset.
+        const string appFormUrlEncoded = "application/x-www-form-urlencoded";
+
+        if (contentType == null)
+        {
+            encoding = null;
+            return false;
+        }
+
+        var charsetIndex = contentType.IndexOf(charsetMarker, StringComparison.OrdinalIgnoreCase);
+        if (charsetIndex != -1)
+        {
+            ReadOnlySpan<char> charset = contentType.AsSpan().Slice(charsetIndex + charsetMarker.Length);
+            if (charset.StartsWith(utf8Charset.AsSpan(), StringComparison.OrdinalIgnoreCase))
+            {
+                encoding = Encoding.UTF8;
+                return true;
+            }
+        }
+
+        if (contentType.StartsWith(textContentTypePrefix, StringComparison.OrdinalIgnoreCase) ||
+            contentType.EndsWith(jsonSuffix, StringComparison.OrdinalIgnoreCase) ||
+            contentType.EndsWith(xmlSuffix, StringComparison.OrdinalIgnoreCase) ||
+            contentType.EndsWith(urlEncodedSuffix, StringComparison.OrdinalIgnoreCase) ||
+            contentType.StartsWith(appJsonPrefix, StringComparison.OrdinalIgnoreCase) ||
+            contentType.StartsWith(appFormUrlEncoded, StringComparison.OrdinalIgnoreCase))
+        {
+            encoding = Encoding.UTF8;
+            return true;
+        }
+
+        encoding = null;
+        return false;
+    }
+}

sdk/core/System.ClientModel/src/Internal/PipelineMessageSanitizer.cs

@@ -0,0 +1,215 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+
+namespace System.ClientModel.Internal;
+
+/// <summary>
+/// TODO.
+/// </summary>
+internal class PipelineMessageSanitizer
+{
+    private const string LogAllValue = "*";
+    private readonly bool _logAllHeaders;
+    private readonly bool _logFullQueries;
+    private readonly string[] _allowedQueryParameters;
+    private readonly string _redactedPlaceholder;
+    private readonly HashSet<string> _allowedHeaders;
+
+    [ThreadStatic]
+    private static StringBuilder? s_cachedStringBuilder;
+    private const int MaxCachedStringBuilderCapacity = 1024;
+
+    /// <summary>
+    /// TODO.
+    /// </summary>
+    /// <param name="allowedQueryParameters"></param>
+    /// <param name="allowedHeaders"></param>
+    /// <param name="redactedPlaceholder"></param>
+    public PipelineMessageSanitizer(string[] allowedQueryParameters, string[] allowedHeaders, string redactedPlaceholder = "REDACTED")
+    {
+        _logAllHeaders = allowedHeaders.Contains(LogAllValue);
+        _logFullQueries = allowedQueryParameters.Contains(LogAllValue);
+
+        _allowedQueryParameters = allowedQueryParameters;
+        _redactedPlaceholder = redactedPlaceholder;
+        _allowedHeaders = new HashSet<string>(allowedHeaders, StringComparer.InvariantCultureIgnoreCase);
+    }
+
+    /// <summary>
+    /// TODO.
+    /// </summary>
+    /// <param name="name"></param>
+    /// <param name="value"></param>
+    /// <returns></returns>
+    public string SanitizeHeader(string name, string value)
+    {
+        if (_logAllHeaders || _allowedHeaders.Contains(name))
+        {
+            return value;
+        }
+
+        return _redactedPlaceholder;
+    }
+
+    /// <summary>
+    /// TODO.
+    /// </summary>
+    /// <param name="url"></param>
+    /// <returns></returns>
+    public string SanitizeUrl(string url)
+    {
+        if (_logFullQueries)
+        {
+            return url;
+        }
+
+#if NET5_0_OR_GREATER
+        int indexOfQuerySeparator = url.IndexOf('?', StringComparison.Ordinal);
+#else
+        int indexOfQuerySeparator = url.IndexOf('?');
+#endif
+
+        if (indexOfQuerySeparator == -1)
+        {
+            return url;
+        }
+
+        // PERF: Avoid allocations in this heavily-used method:
+        // 1. Use ReadOnlySpan<char> to avoid creating substrings.
+        // 2. Defer creating a StringBuilder until absolutely necessary.
+        // 3. Use a rented StringBuilder to avoid allocating a new one
+        //    each time.
+
+        // Create the StringBuilder only when necessary (when we encounter
+        // a query parameter that needs to be redacted)
+        StringBuilder? stringBuilder = null;
+
+        // Keeps track of the number of characters we've processed so far
+        // so that, if we need to create a StringBuilder, we know how many
+        // characters to copy over from the original URL.
+        int lengthSoFar = indexOfQuerySeparator + 1;
+
+        ReadOnlySpan<char> query = url.AsSpan(indexOfQuerySeparator + 1); // +1 to skip the '?'
+
+        while (query.Length > 0)
+        {
+            int endOfParameterValue = query.IndexOf('&');
+            int endOfParameterName = query.IndexOf('=');
+            bool noValue = false;
+
+            // Check if we have parameter without value
+            if ((endOfParameterValue == -1 && endOfParameterName == -1) ||
+                (endOfParameterValue != -1 && (endOfParameterName == -1 || endOfParameterName > endOfParameterValue)))
+            {
+                endOfParameterName = endOfParameterValue;
+                noValue = true;
+            }
+
+            if (endOfParameterName == -1)
+            {
+                endOfParameterName = query.Length;
+            }
+
+            if (endOfParameterValue == -1)
+            {
+                endOfParameterValue = query.Length;
+            }
+            else
+            {
+                // include the separator
+                endOfParameterValue++;
+            }
+
+            ReadOnlySpan<char> parameterName = query.Slice(0, endOfParameterName);
+
+            bool isAllowed = false;
+            foreach (string name in _allowedQueryParameters)
+            {
+                if (parameterName.Equals(name.AsSpan(), StringComparison.OrdinalIgnoreCase))
+                {
+                    isAllowed = true;
+                    break;
+                }
+            }
+
+            int valueLength = endOfParameterValue;
+            int nameLength = endOfParameterName;
+
+            if (isAllowed || noValue)
+            {
+                if (stringBuilder is null)
+                {
+                    lengthSoFar += valueLength;
+                }
+                else
+                {
+                    AppendReadOnlySpan(stringBuilder, query.Slice(0, valueLength));
+                }
+            }
+            else
+            {
+                // Encountered a query value that needs to be redacted.
+                // Create the StringBuilder if we haven't already.
+                stringBuilder ??= RentStringBuilder(url.Length).Append(url, 0, lengthSoFar);
+
+                AppendReadOnlySpan(stringBuilder, query.Slice(0, nameLength))
+                    .Append('=')
+                    .Append(_redactedPlaceholder);
+
+                if (query[endOfParameterValue - 1] == '&')
+                {
+                    stringBuilder.Append('&');
+                }
+            }
+
+            query = query.Slice(valueLength);
+        }
+
+        return stringBuilder is null ? url : ToStringAndReturnStringBuilder(stringBuilder);
+
+        static StringBuilder AppendReadOnlySpan(StringBuilder builder, ReadOnlySpan<char> span)
+        {
+#if NET6_0_OR_GREATER
+            return builder.Append(span);
+#else
+            foreach (char c in span)
+            {
+                builder.Append(c);
+            }
+
+            return builder;
+#endif
+        }
+    }
+
+    private static StringBuilder RentStringBuilder(int capacity)
+    {
+        if (capacity <= MaxCachedStringBuilderCapacity)
+        {
+            StringBuilder? builder = s_cachedStringBuilder;
+            if (builder is not null && builder.Capacity >= capacity)
+            {
+                s_cachedStringBuilder = null;
+                return builder;
+            }
+        }
+
+        return new StringBuilder(capacity);
+    }
+
+    private static string ToStringAndReturnStringBuilder(StringBuilder builder)
+    {
+        string result = builder.ToString();
+        if (builder.Capacity <= MaxCachedStringBuilderCapacity)
+        {
+            s_cachedStringBuilder = builder.Clear();
+        }
+
+        return result;
+    }
+}