From 7940062040d4e8f8c3016c7b8300dfed31c8b9ce Mon Sep 17 00:00:00 2001 From: Pavel Krymets Date: Tue, 15 Jan 2019 09:04:57 -0800 Subject: [PATCH] [2.2.x] Port Drop messages in azure loggers if queue is full (#592) --- .../src/Internal/BatchingLoggerProvider.cs | 20 ++++++++++++++++--- .../test/BatchingLoggerProviderTests.cs | 13 ++++++------ 2 files changed, 23 insertions(+), 10 deletions(-) diff --git a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs index 79720c5531..34250addd8 100644 --- a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs +++ b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs @@ -18,6 +18,8 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal private readonly int? _batchSize; private readonly IDisposable _optionsChangeToken; + private int _messagesDropped; + private BlockingCollection _messageQueue; private Task _outputTask; private CancellationTokenSource _cancellationTokenSource; @@ -78,6 +80,16 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal limit--; } + var messagesDropped = Interlocked.Exchange(ref _messagesDropped, 0); + if (messagesDropped != 0) + { + _currentBatch.Add(new LogMessage() + { + Message = $"{messagesDropped} message(s) dropped because of queue size limit. Increase the queue size or decrease logging verbosity to avoid this.{Environment.NewLine}", + Timestamp = DateTimeOffset.Now + }); + } + if (_currentBatch.Count > 0) { try @@ -91,7 +103,6 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal _currentBatch.Clear(); } - await IntervalAsync(_interval, _cancellationTokenSource.Token); } } @@ -107,7 +118,10 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal { try { - _messageQueue.Add(new LogMessage { Message = message, Timestamp = timestamp }, _cancellationTokenSource.Token); + if (!_messageQueue.TryAdd(new LogMessage { Message = message, Timestamp = timestamp }, millisecondsTimeout: 0, cancellationToken: _cancellationTokenSource.Token)) + { + Interlocked.Increment(ref _messagesDropped); + } } catch { @@ -160,4 +174,4 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal return new BatchingLogger(this, categoryName); } } -} \ No newline at end of file +} diff --git a/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs b/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs index 42cefe99df..9d25b5a547 100644 --- a/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs +++ b/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs @@ -1,4 +1,4 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; @@ -51,7 +51,6 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Test Assert.Single(provider.Batches); Assert.Single(provider.Batches[0]); Assert.Equal("2016-05-04 03:02:01.000 +00:00 [Information] Cat: Info message" + _nl, provider.Batches[0][0].Message); - provider.IntervalControl.Resume(); await provider.IntervalControl.Pause; @@ -62,7 +61,7 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Test } [Fact] - public async Task BlocksWhenReachingMaxQueue() + public async Task DropsMessagesWhenReachingMaxQueue() { var provider = new TestBatchingLoggingProvider(maxQueueSize: 1); var logger = (BatchingLogger)provider.CreateLogger("Cat"); @@ -70,14 +69,14 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Test await provider.IntervalControl.Pause; logger.Log(_timestampOne, LogLevel.Information, 0, "Info message", null, (state, ex) => state); - var task = Task.Run(() => logger.Log(_timestampOne.AddHours(1), LogLevel.Error, 0, "Error message", null, (state, ex) => state)); - - Assert.False(task.Wait(1000)); + logger.Log(_timestampOne.AddHours(1), LogLevel.Error, 0, "Error message", null, (state, ex) => state); provider.IntervalControl.Resume(); await provider.IntervalControl.Pause; - Assert.True(task.Wait(1000)); + Assert.Equal(2, provider.Batches[0].Length); + Assert.Equal("2016-05-04 03:02:01.000 +00:00 [Information] Cat: Info message" + _nl, provider.Batches[0][0].Message); + Assert.Equal("1 message(s) dropped because of queue size limit. Increase the queue size or decrease logging verbosity to avoid this." + _nl, provider.Batches[0][1].Message); } private class TestBatchingLoggingProvider: BatchingLoggerProvider