< Summary

Class:Azure.Core.Pipeline.LoggingPolicy
Assembly:Azure.Core
File(s):C:\Git\azure-sdk-for-net\sdk\core\Azure.Core\src\Pipeline\Internal\LoggingPolicy.cs
Covered lines:163
Uncovered lines:18
Coverable lines:181
Total lines:452
Line coverage:90% (163 of 181)
Covered branches:69
Total branches:82
Branch coverage:84.1% (69 of 82)

Metrics

MethodCyclomatic complexity Line coverage Branch coverage
.ctor(...)-100%100%
.cctor()-100%100%
ProcessAsync()-100%100%
ProcessAsync()-86.49%75%
FormatUri(...)-100%100%
Process(...)-100%100%
FormatHeaders(...)-100%100%
.ctor(...)-100%100%
Seek(...)-0%100%
Read(...)-100%100%
LogBuffer(...)-100%100%
ReadAsync()-100%100%
get_CanRead()-0%100%
get_CanSeek()-0%100%
get_Length()-0%100%
get_Position()-0%100%
set_Position(...)-0%100%
Close()-0%100%
Dispose(...)-0%100%
DecrementLength(...)-100%100%
.ctor(...)-100%100%
LogAsync()-100%100%
LogAsync()-100%100%
Log(...)-80%62.5%
IsEnabled(...)-100%100%
IsEnabled(...)-100%50%
FormatAsync()-100%100%
FormatAsync()-100%100%
Log(...)-100%95.83%
ResponseOrError(...)-100%100%
.ctor(...)-100%100%
Write(...)-100%100%
WriteAsync(...)-100%50%
DecrementLength(...)-100%100%

File(s)

C:\Git\azure-sdk-for-net\sdk\core\Azure.Core\src\Pipeline\Internal\LoggingPolicy.cs

#LineLine coverage
 1// Copyright (c) Microsoft Corporation. All rights reserved.
 2// Licensed under the MIT License.
 3
 4using System;
 5using System.Collections.Generic;
 6using System.Diagnostics;
 7using System.Diagnostics.Tracing;
 8using System.IO;
 9using System.Text;
 10using System.Threading;
 11using System.Threading.Tasks;
 12using Azure.Core.Diagnostics;
 13
 14namespace Azure.Core.Pipeline
 15{
 16    internal class LoggingPolicy : HttpPipelinePolicy
 17    {
 13218        public LoggingPolicy(bool logContent, int maxLength, string[] allowedHeaderNames, string[] allowedQueryParameter
 19        {
 13220            _sanitizer = new HttpMessageSanitizer(allowedQueryParameters, allowedHeaderNames);
 13221            _logContent = logContent;
 13222            _maxLength = maxLength;
 13223            _assemblyName = assemblyName;
 13224        }
 25
 26        private const double RequestTooLongTime = 3.0; // sec
 27
 228        private static readonly AzureCoreEventSource s_eventSource = AzureCoreEventSource.Singleton;
 29
 30        private readonly bool _logContent;
 31        private readonly int _maxLength;
 32        private HttpMessageSanitizer _sanitizer;
 33        private readonly string? _assemblyName;
 34
 35        public override async ValueTask ProcessAsync(HttpMessage message, ReadOnlyMemory<HttpPipelinePolicy> pipeline)
 36        {
 107437            await ProcessAsync(message, pipeline, true).ConfigureAwait(false);
 106438        }
 39
 40        private async ValueTask ProcessAsync(HttpMessage message, ReadOnlyMemory<HttpPipelinePolicy> pipeline, bool asyn
 41        {
 213042            if (!s_eventSource.IsEnabled())
 43            {
 044                if (async)
 45                {
 046                    await ProcessNextAsync(message, pipeline).ConfigureAwait(false);
 47                }
 48                else
 49                {
 050                    ProcessNext(message, pipeline);
 51                }
 052                return;
 53            }
 54
 213055            Request request = message.Request;
 56
 213057            s_eventSource.Request(request.ClientRequestId, request.Method.ToString(), FormatUri(request.Uri), FormatHead
 58
 213059            Encoding? requestTextEncoding = null;
 60
 213061            if (request.TryGetHeader(HttpHeader.Names.ContentType, out var contentType))
 62            {
 1663                ContentTypeUtilities.TryGetTextEncoding(contentType, out requestTextEncoding);
 64            }
 65
 213066            var logWrapper = new ContentEventSourceWrapper(s_eventSource, _logContent, _maxLength, message.CancellationT
 67
 213068            await logWrapper.LogAsync(request.ClientRequestId, request.Content, requestTextEncoding, async).ConfigureAwa
 69
 213070            var before = Stopwatch.GetTimestamp();
 71
 72            try
 73            {
 213074                if (async)
 75                {
 107476                    await ProcessNextAsync(message, pipeline).ConfigureAwait(false);
 77                }
 78                else
 79                {
 105680                    ProcessNext(message, pipeline);
 81                }
 211082            }
 2083            catch (Exception ex)
 84            {
 2085                s_eventSource.ExceptionResponse(request.ClientRequestId, ex.ToString());
 2086                throw;
 87            }
 88
 211089            var after = Stopwatch.GetTimestamp();
 90
 211091            bool isError = message.ResponseClassifier.IsErrorResponse(message);
 92
 211093            Response response = message.Response;
 211094            ContentTypeUtilities.TryGetTextEncoding(response.Headers.ContentType, out Encoding? responseTextEncoding);
 95
 211096            bool wrapResponseContent = response.ContentStream != null &&
 211097                                       response.ContentStream?.CanSeek == false &&
 211098                                       logWrapper.IsEnabled(isError);
 99
 2110100            double elapsed = (after - before) / (double)Stopwatch.Frequency;
 101
 2110102            if (isError)
 103            {
 438104                s_eventSource.ErrorResponse(response.ClientRequestId, response.Status, response.ReasonPhrase, FormatHead
 105            }
 106            else
 107            {
 1672108                s_eventSource.Response(response.ClientRequestId, response.Status, response.ReasonPhrase, FormatHeaders(r
 109            }
 110
 2110111            if (wrapResponseContent)
 112            {
 20113                response.ContentStream = new LoggingStream(response.ClientRequestId, logWrapper, _maxLength, response.Co
 114            }
 115            else
 116            {
 2090117                await logWrapper.LogAsync(response.ClientRequestId, isError, response.ContentStream, responseTextEncodin
 118            }
 119
 2110120            if (elapsed > RequestTooLongTime)
 121            {
 0122                s_eventSource.ResponseDelay(response.ClientRequestId, elapsed);
 123            }
 2110124        }
 125
 126        private string FormatUri(RequestUriBuilder requestUri)
 127        {
 2130128            return _sanitizer.SanitizeUrl(requestUri.ToString());
 129        }
 130
 131        public override void Process(HttpMessage message, ReadOnlyMemory<HttpPipelinePolicy> pipeline)
 132        {
 1056133            ProcessAsync(message, pipeline, false).EnsureCompleted();
 1046134        }
 135
 136        private string FormatHeaders(IEnumerable<HttpHeader> headers)
 137        {
 4240138            var stringBuilder = new StringBuilder();
 33212139            foreach (HttpHeader header in headers)
 140            {
 12366141                stringBuilder.Append(header.Name);
 12366142                stringBuilder.Append(':');
 12366143                string newValue = _sanitizer.SanitizeHeader(header.Name, header.Value);
 12366144                stringBuilder.AppendLine(newValue);
 145            }
 4240146            return stringBuilder.ToString();
 147        }
 148
 149        private class LoggingStream : ReadOnlyStream
 150        {
 151            private readonly string _requestId;
 152
 153            private readonly ContentEventSourceWrapper _eventSourceWrapper;
 154
 155            private int _maxLoggedBytes;
 156
 157            private readonly Stream _originalStream;
 158
 159            private readonly bool _error;
 160
 161            private readonly Encoding? _textEncoding;
 162
 163            private int _blockNumber;
 164
 20165            public LoggingStream(string requestId, ContentEventSourceWrapper eventSourceWrapper, int maxLoggedBytes, Str
 166            {
 167                // Should only wrap non-seekable streams
 168                Debug.Assert(!originalStream.CanSeek);
 20169                _requestId = requestId;
 20170                _eventSourceWrapper = eventSourceWrapper;
 20171                _maxLoggedBytes = maxLoggedBytes;
 20172                _originalStream = originalStream;
 20173                _error = error;
 20174                _textEncoding = textEncoding;
 20175            }
 176
 177            public override long Seek(long offset, SeekOrigin origin)
 178            {
 0179                return _originalStream.Seek(offset, origin);
 180            }
 181
 182            public override int Read(byte[] buffer, int offset, int count)
 183            {
 30184                var result = _originalStream.Read(buffer, offset, count);
 185
 30186                var countToLog = result;
 30187                DecrementLength(ref countToLog);
 30188                LogBuffer(buffer, offset, countToLog);
 189
 30190                return result;
 191            }
 192
 193            private void LogBuffer(byte[] buffer, int offset, int count)
 194            {
 60195                if (count == 0)
 196                {
 24197                    return;
 198                }
 199
 36200                _eventSourceWrapper.Log(_requestId, _error, buffer, offset, count, _textEncoding, _blockNumber);
 201
 36202                _blockNumber++;
 36203            }
 204
 205            public override async Task<int> ReadAsync(byte[] buffer, int offset, int count, CancellationToken cancellati
 206            {
 30207                var result = await _originalStream.ReadAsync(buffer, offset, count, cancellationToken).ConfigureAwait(fa
 208
 30209                var countToLog = result;
 30210                DecrementLength(ref countToLog);
 30211                LogBuffer(buffer, offset, countToLog);
 212
 30213                return result;
 30214            }
 215
 0216            public override bool CanRead => _originalStream.CanRead;
 0217            public override bool CanSeek => _originalStream.CanSeek;
 0218            public override long Length => _originalStream.Length;
 219            public override long Position
 220            {
 0221                get => _originalStream.Position;
 0222                set => _originalStream.Position = value;
 223            }
 224
 225            public override void Close()
 226            {
 0227                _originalStream.Close();
 0228            }
 229
 230            protected override void Dispose(bool disposing)
 231            {
 0232                base.Dispose(disposing);
 233
 0234                _originalStream.Dispose();
 0235            }
 236
 237            private void DecrementLength(ref int count)
 238            {
 60239                var left = Math.Min(count, _maxLoggedBytes);
 60240                count = left;
 60241                _maxLoggedBytes -= count;
 60242            }
 243        }
 244
 245        private readonly struct ContentEventSourceWrapper
 246        {
 247            private const int CopyBufferSize = 8 * 1024;
 248            private readonly AzureCoreEventSource? _eventSource;
 249
 250            private readonly int _maxLength;
 251
 252            private readonly CancellationToken _cancellationToken;
 253
 254            public ContentEventSourceWrapper(AzureCoreEventSource eventSource, bool logContent, int maxLength, Cancellat
 255            {
 2130256                _eventSource = logContent ? eventSource : null;
 2130257                _maxLength = maxLength;
 2130258                _cancellationToken = cancellationToken;
 2130259            }
 260
 261            public async ValueTask LogAsync(string requestId, bool isError, Stream? stream, Encoding? textEncoding, bool
 262            {
 2090263                EventType eventType = ResponseOrError(isError);
 264
 2090265                if (stream == null || !IsEnabled(eventType))
 266                {
 2070267                    return;
 268                }
 269
 20270                var bytes = await FormatAsync(stream, async).ConfigureAwait(false).EnsureCompleted(async);
 20271                Log(requestId, eventType, bytes, textEncoding);
 272
 2090273            }
 274
 275            public async ValueTask LogAsync(string requestId, RequestContent? content, Encoding? textEncoding, bool asyn
 276            {
 2130277                EventType eventType = EventType.Request;
 278
 2130279                if (content == null || !IsEnabled(eventType))
 280                {
 2114281                    return;
 282                }
 283
 16284                var bytes = await FormatAsync(content, async).ConfigureAwait(false).EnsureCompleted(async);
 285
 16286                Log(requestId, eventType, bytes, textEncoding);
 2130287            }
 288
 289            public void Log(string requestId, bool isError, byte[] buffer, int offset, int length, Encoding? textEncodin
 290            {
 36291                EventType eventType = ResponseOrError(isError);
 292
 36293                if (buffer == null || !IsEnabled(eventType))
 294                {
 0295                    return;
 296                }
 297
 36298                var logLength = Math.Min(length, _maxLength);
 299
 300                byte[] bytes;
 36301                if (length == logLength && offset == 0)
 302                {
 0303                    bytes = buffer;
 304                }
 305                else
 306                {
 36307                    bytes = new byte[logLength];
 36308                    Array.Copy(buffer, offset, bytes, 0, logLength);
 309                }
 310
 36311                Log(requestId, eventType, bytes, textEncoding, block);
 36312            }
 313
 314            public bool IsEnabled(bool isError)
 315            {
 1632316                return IsEnabled(ResponseOrError(isError));
 317            }
 318
 319            private bool IsEnabled(EventType errorResponse)
 320            {
 3764321                return _eventSource != null &&
 3764322                       (_eventSource.IsEnabled(EventLevel.Informational, EventKeywords.All) ||
 3764323                       (errorResponse == EventType.ErrorResponse && _eventSource.IsEnabled(EventLevel.Warning, EventKeyw
 324            }
 325
 326            private async ValueTask<byte[]> FormatAsync(RequestContent requestContent, bool async)
 327            {
 16328                using var memoryStream = new MaxLengthStream(_maxLength);
 329
 16330                if (async)
 331                {
 8332                    await requestContent.WriteToAsync(memoryStream, _cancellationToken).ConfigureAwait(false);
 333                }
 334                else
 335                {
 8336                    requestContent.WriteTo(memoryStream, _cancellationToken);
 337                }
 338
 16339                return memoryStream.ToArray();
 16340            }
 341
 342            private async ValueTask<byte[]> FormatAsync(Stream content, bool async)
 343            {
 20344                using var memoryStream = new MaxLengthStream(_maxLength);
 345
 20346                if (async)
 347                {
 10348                    await content.CopyToAsync(memoryStream, CopyBufferSize, _cancellationToken).ConfigureAwait(false);
 349                }
 350                else
 351                {
 10352                    content.CopyTo(memoryStream);
 353                }
 354
 20355                content.Seek(0, SeekOrigin.Begin);
 356
 20357                return memoryStream.ToArray();
 20358            }
 359
 360            private void Log(string requestId, EventType eventType, byte[] bytes, Encoding? textEncoding, int? block = n
 361            {
 72362                string? stringValue = textEncoding?.GetString(bytes);
 363
 364                // We checked IsEnabled before we got here
 365                Debug.Assert(_eventSource != null);
 72366                AzureCoreEventSource azureCoreEventSource = _eventSource!;
 367
 72368                switch (eventType)
 369                {
 16370                    case EventType.Request when stringValue != null:
 8371                        azureCoreEventSource.RequestContentText(requestId, stringValue);
 8372                        break;
 373                    case EventType.Request:
 8374                        azureCoreEventSource.RequestContent(requestId, bytes);
 8375                        break;
 376
 377                    // Response
 32378                    case EventType.Response when block != null && stringValue != null:
 12379                        azureCoreEventSource.ResponseContentTextBlock(requestId, block.Value, stringValue);
 12380                        break;
 20381                    case EventType.Response when block != null:
 8382                        azureCoreEventSource.ResponseContentBlock(requestId, block.Value, bytes);
 8383                        break;
 12384                    case EventType.Response when stringValue != null:
 8385                        azureCoreEventSource.ResponseContentText(requestId, stringValue);
 8386                        break;
 387                    case EventType.Response:
 4388                        azureCoreEventSource.ResponseContent(requestId, bytes);
 4389                        break;
 390
 391                    // ResponseError
 24392                    case EventType.ErrorResponse when block != null && stringValue != null:
 8393                        azureCoreEventSource.ErrorResponseContentTextBlock(requestId, block.Value, stringValue);
 8394                        break;
 16395                    case EventType.ErrorResponse when block != null:
 8396                        azureCoreEventSource.ErrorResponseContentBlock(requestId, block.Value, bytes);
 8397                        break;
 8398                    case EventType.ErrorResponse when stringValue != null:
 4399                        azureCoreEventSource.ErrorResponseContentText(requestId, stringValue);
 4400                        break;
 401                    case EventType.ErrorResponse:
 4402                        azureCoreEventSource.ErrorResponseContent(requestId, bytes);
 403                        break;
 404                }
 4405            }
 406
 407            private static EventType ResponseOrError(bool isError)
 408            {
 3758409                return isError ? EventType.ErrorResponse : EventType.Response;
 410            }
 411
 412            private enum EventType
 413            {
 414                Request,
 415                Response,
 416                ErrorResponse
 417            }
 418
 419            private class MaxLengthStream : MemoryStream
 420            {
 421                private int _bytesLeft;
 422
 36423                public MaxLengthStream(int maxLength) : base()
 424                {
 36425                    _bytesLeft = maxLength;
 36426                }
 427
 428                public override void Write(byte[] buffer, int offset, int count)
 429                {
 36430                    DecrementLength(ref count);
 36431                    if (count > 0)
 432                    {
 36433                        base.Write(buffer, offset, count);
 434                    }
 36435                }
 436
 437                public override Task WriteAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToke
 438                {
 8439                    return count > 0 ? base.WriteAsync(buffer, offset, count, cancellationToken) : Task.CompletedTask;
 440                }
 441
 442                private void DecrementLength(ref int count)
 443                {
 36444                    var left = Math.Min(count, _bytesLeft);
 36445                    count = left;
 446
 36447                    _bytesLeft -= count;
 36448                }
 449            }
 450        }
 451    }
 452}