From bc8829ce140c5a621a25478b4e952ee659f84c15 Mon Sep 17 00:00:00 2001 From: Shannon Date: Fri, 7 Apr 2017 12:07:35 +1000 Subject: [PATCH] U4-8432 Update log4net async appender to use the official log4net one --- .../AsynchronousRollingFileAppender.cs | 2 +- .../Logging/ParallelForwardingAppender.cs | 297 +--------------- src/Umbraco.Core/Umbraco.Core.csproj | 3 + src/Umbraco.Core/packages.config | 1 + .../Logging/AsyncRollingFileAppenderTest.cs | 168 --------- src/Umbraco.Tests/Logging/DebugAppender.cs | 25 -- .../Logging/ParallelForwarderTest.cs | 327 ------------------ src/Umbraco.Tests/Logging/RingBufferTest.cs | 150 -------- .../Scheduling/BackgroundTaskRunnerTests2.cs | 2 +- .../{Logging => TestHelpers}/ConsoleLogger.cs | 2 +- src/Umbraco.Tests/Umbraco.Tests.csproj | 9 +- src/Umbraco.Tests/packages.config | 1 + .../config/log4net.Release.config | 2 +- src/Umbraco.Web.UI/config/log4net.config | 2 +- 14 files changed, 16 insertions(+), 975 deletions(-) delete mode 100644 src/Umbraco.Tests/Logging/AsyncRollingFileAppenderTest.cs delete mode 100644 src/Umbraco.Tests/Logging/DebugAppender.cs delete mode 100644 src/Umbraco.Tests/Logging/ParallelForwarderTest.cs delete mode 100644 src/Umbraco.Tests/Logging/RingBufferTest.cs rename src/Umbraco.Tests/{Logging => TestHelpers}/ConsoleLogger.cs (98%) diff --git a/src/Umbraco.Core/Logging/AsynchronousRollingFileAppender.cs b/src/Umbraco.Core/Logging/AsynchronousRollingFileAppender.cs index c226bd03c8..cd62008cd4 100644 --- a/src/Umbraco.Core/Logging/AsynchronousRollingFileAppender.cs +++ b/src/Umbraco.Core/Logging/AsynchronousRollingFileAppender.cs @@ -16,7 +16,7 @@ namespace Umbraco.Core.Logging /// This is an old/deprecated logger and has been superceded by ParallelForwardingAppender which is included in Umbraco and /// also by AsyncForwardingAppender in the Log4Net.Async library. /// - [Obsolete("This is superceded by the ParallelForwardingAppender, this will be removed in v8")] + [Obsolete("This is superceded by the ParallelForwardingAppender, this will be removed in v8, do not use this")] [EditorBrowsable(EditorBrowsableState.Never)] public class AsynchronousRollingFileAppender : RollingFileAppender { diff --git a/src/Umbraco.Core/Logging/ParallelForwardingAppender.cs b/src/Umbraco.Core/Logging/ParallelForwardingAppender.cs index 48bb3ec710..c930347791 100644 --- a/src/Umbraco.Core/Logging/ParallelForwardingAppender.cs +++ b/src/Umbraco.Core/Logging/ParallelForwardingAppender.cs @@ -13,301 +13,8 @@ namespace Umbraco.Core.Logging /// /// Borrowed from https://github.com/cjbhaines/Log4Net.Async - will reference Nuget packages directly in v8 /// - public class ParallelForwardingAppender : AsyncForwardingAppenderBase, IDisposable + [Obsolete("Use the Log4Net.Async.ParallelForwardingAppender instead this will be removed in future versions")] + public class ParallelForwardingAppender : Log4Net.Async.ParallelForwardingAppender { - #region Private Members - - private const int DefaultBufferSize = 1000; - private BlockingCollection _loggingEvents; - private CancellationTokenSource _loggingCancelationTokenSource; - private CancellationToken _loggingCancelationToken; - private Task _loggingTask; - private Double _shutdownFlushTimeout = 2; - private TimeSpan _shutdownFlushTimespan = TimeSpan.FromSeconds(2); - private static readonly Type ThisType = typeof(ParallelForwardingAppender); - private volatile bool shutDownRequested; - private int? bufferSize = DefaultBufferSize; - - #endregion Private Members - - #region Properties - - /// - /// Gets or sets the number of LoggingEvents that will be buffered. Set to null for unlimited. - /// - public override int? BufferSize - { - get { return bufferSize; } - set { bufferSize = value; } - } - - public int BufferEntryCount - { - get - { - if (_loggingEvents == null) return 0; - return _loggingEvents.Count; - } - } - - /// - /// Gets or sets the time period in which the system will wait for appenders to flush before canceling the background task. - /// - public Double ShutdownFlushTimeout - { - get - { - return _shutdownFlushTimeout; - } - set - { - _shutdownFlushTimeout = value; - } - } - - protected override string InternalLoggerName - { - get - { - { - return "ParallelForwardingAppender"; - } - } - } - - #endregion Properties - - #region Startup - - public override void ActivateOptions() - { - base.ActivateOptions(); - _shutdownFlushTimespan = TimeSpan.FromSeconds(_shutdownFlushTimeout); - StartForwarding(); - } - - private void StartForwarding() - { - if (shutDownRequested) - { - return; - } - //Create a collection which will block the thread and wait for new entries - //if the collection is empty - if (BufferSize.HasValue && BufferSize > 0) - { - _loggingEvents = new BlockingCollection(BufferSize.Value); - } - else - { - //No limit on the number of events. - _loggingEvents = new BlockingCollection(); - } - //The cancellation token is used to cancel a running task gracefully. - _loggingCancelationTokenSource = new CancellationTokenSource(); - _loggingCancelationToken = _loggingCancelationTokenSource.Token; - _loggingTask = new Task(SubscriberLoop, _loggingCancelationToken); - _loggingTask.Start(); - } - - #endregion Startup - - #region Shutdown - - private void CompleteSubscriberTask() - { - shutDownRequested = true; - if (_loggingEvents == null || _loggingEvents.IsAddingCompleted) - { - return; - } - //Don't allow more entries to be added. - _loggingEvents.CompleteAdding(); - //Allow some time to flush - Thread.Sleep(_shutdownFlushTimespan); - if (!_loggingTask.IsCompleted && !_loggingCancelationToken.IsCancellationRequested) - { - _loggingCancelationTokenSource.Cancel(); - //Wait here so that the error logging messages do not get into a random order. - //Don't pass the cancellation token because we are not interested - //in catching the OperationCanceledException that results. - _loggingTask.Wait(); - } - if (!_loggingEvents.IsCompleted) - { - ForwardInternalError("The buffer was not able to be flushed before timeout occurred.", null, ThisType); - } - } - - protected override void OnClose() - { - CompleteSubscriberTask(); - base.OnClose(); - } - - #endregion Shutdown - - #region Appending - - protected override void Append(LoggingEvent loggingEvent) - { - if (_loggingEvents == null || _loggingEvents.IsAddingCompleted || loggingEvent == null) - { - return; - } - - loggingEvent.Fix = Fix; - //In the case where blocking on a full collection, and the task is subsequently completed, the cancellation token - //will prevent the entry from attempting to add to the completed collection which would result in an exception. - _loggingEvents.Add(new LoggingEventContext(loggingEvent, HttpContext), _loggingCancelationToken); - } - - protected override void Append(LoggingEvent[] loggingEvents) - { - if (_loggingEvents == null || _loggingEvents.IsAddingCompleted || loggingEvents == null) - { - return; - } - - foreach (var loggingEvent in loggingEvents) - { - Append(loggingEvent); - } - } - - #endregion Appending - - #region Forwarding - - /// - /// Iterates over a BlockingCollection containing LoggingEvents. - /// - private void SubscriberLoop() - { - Thread.CurrentThread.Name = String.Format("{0} ParallelForwardingAppender Subscriber Task", Name); - //The task will continue in a blocking loop until - //the queue is marked as adding completed, or the task is canceled. - try - { - //This call blocks until an item is available or until adding is completed - foreach (var entry in _loggingEvents.GetConsumingEnumerable(_loggingCancelationToken)) - { - HttpContext = entry.HttpContext; - ForwardLoggingEvent(entry.LoggingEvent, ThisType); - } - } - catch (OperationCanceledException ex) - { - //The thread was canceled before all entries could be forwarded and the collection completed. - ForwardInternalError("Subscriber task was canceled before completion.", ex, ThisType); - //Cancellation is called in the CompleteSubscriberTask so don't call that again. - } - catch (ThreadAbortException ex) - { - //Thread abort may occur on domain unload. - ForwardInternalError("Subscriber task was aborted.", ex, ThisType); - //Cannot recover from a thread abort so complete the task. - CompleteSubscriberTask(); - //The exception is swallowed because we don't want the client application - //to halt due to a logging issue. - } - catch (Exception ex) - { - //On exception, try to log the exception - ForwardInternalError("Subscriber task error in forwarding loop.", ex, ThisType); - //Any error in the loop is going to be some sort of extenuating circumstance from which we - //probably cannot recover anyway. Complete subscribing. - CompleteSubscriberTask(); - } - } - - #endregion Forwarding - - #region IDisposable Implementation - - private bool _disposed = false; - - //Implement IDisposable. - public void Dispose() - { - Dispose(true); - GC.SuppressFinalize(this); - } - - protected virtual void Dispose(bool disposing) - { - if (!_disposed) - { - if (disposing) - { - if (_loggingTask != null) - { - if (!(_loggingTask.IsCanceled || _loggingTask.IsCompleted || _loggingTask.IsFaulted)) - { - try - { - CompleteSubscriberTask(); - } - catch (Exception ex) - { - LogLog.Error(ThisType, "Exception Completing Subscriber Task in Dispose Method", ex); - } - } - try - { - _loggingTask.Dispose(); - } - catch (Exception ex) - { - LogLog.Error(ThisType, "Exception Disposing Logging Task", ex); - } - finally - { - _loggingTask = null; - } - } - if (_loggingEvents != null) - { - try - { - _loggingEvents.Dispose(); - } - catch (Exception ex) - { - LogLog.Error(ThisType, "Exception Disposing BlockingCollection", ex); - } - finally - { - _loggingEvents = null; - } - } - if (_loggingCancelationTokenSource != null) - { - try - { - _loggingCancelationTokenSource.Dispose(); - } - catch (Exception ex) - { - LogLog.Error(ThisType, "Exception Disposing CancellationTokenSource", ex); - } - finally - { - _loggingCancelationTokenSource = null; - } - } - } - _disposed = true; - } - } - - // Use C# destructor syntax for finalization code. - ~ParallelForwardingAppender() - { - // Simply call Dispose(false). - Dispose(false); - } - - #endregion IDisposable Implementation } } \ No newline at end of file diff --git a/src/Umbraco.Core/Umbraco.Core.csproj b/src/Umbraco.Core/Umbraco.Core.csproj index 6b4285392d..f2d65aa5ad 100644 --- a/src/Umbraco.Core/Umbraco.Core.csproj +++ b/src/Umbraco.Core/Umbraco.Core.csproj @@ -59,6 +59,9 @@ ..\packages\log4net.2.0.8\lib\net45-full\log4net.dll + + ..\packages\Log4Net.Async.2.0.4\lib\net40\Log4Net.Async.dll + ..\packages\Microsoft.AspNet.Identity.Core.2.2.1\lib\net45\Microsoft.AspNet.Identity.Core.dll True diff --git a/src/Umbraco.Core/packages.config b/src/Umbraco.Core/packages.config index 11e49f0398..191eb11c01 100644 --- a/src/Umbraco.Core/packages.config +++ b/src/Umbraco.Core/packages.config @@ -4,6 +4,7 @@ + diff --git a/src/Umbraco.Tests/Logging/AsyncRollingFileAppenderTest.cs b/src/Umbraco.Tests/Logging/AsyncRollingFileAppenderTest.cs deleted file mode 100644 index c5e37f424a..0000000000 --- a/src/Umbraco.Tests/Logging/AsyncRollingFileAppenderTest.cs +++ /dev/null @@ -1,168 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Diagnostics; -using System.IO; -using System.Linq; -using System.Threading; -using log4net; -using log4net.Config; -using log4net.Core; -using log4net.Layout; -using log4net.Repository; -using NUnit.Framework; -using Umbraco.Core; -using Umbraco.Core.Logging; - -namespace Umbraco.Tests.Logging -{ - [TestFixture] - public class AsyncRollingFileAppenderTest - { - private const string ErrorMessage = "TEST ERROR MESSAGE"; - private const string FileFolderPath = @"c:\LogTesting\"; - private readonly Level ErrorLevel = Level.Error; - private AsynchronousRollingFileAppender appender; - private ILoggerRepository rep; - private Guid fileGuid; - - private string GetFilePath() - { - return string.Format("{0}{1}.log", FileFolderPath, fileGuid); - } - - [SetUp] - public void SetUp() - { - fileGuid = Guid.NewGuid(); - if (File.Exists(GetFilePath())) - { - File.Delete(GetFilePath()); - } - - appender = new AsynchronousRollingFileAppender(); - appender.Threshold = ErrorLevel; - appender.File = GetFilePath(); - appender.Layout = new PatternLayout("%d|%-5level|%logger| %message %exception%n"); - appender.StaticLogFileName = true; - appender.AppendToFile = true; - appender.ActivateOptions(); - - rep = LogManager.CreateRepository(Guid.NewGuid().ToString()); - BasicConfigurator.Configure(rep, appender); - } - - [TearDown] - public void TearDown() - { - rep.Shutdown(); - if (File.Exists(GetFilePath())) - { - File.Delete(GetFilePath()); - } - } - - [TestFixtureTearDown] - public void FixtureTearDown() - { - foreach (string file in Directory.GetFiles(FileFolderPath)) - { - try - { - File.Delete(file); - } - catch { } - } - } - - private void ReleaseFileLocks() - { - rep.Shutdown(); - appender.Close(); - } - - [Test] - public void CanWriteToFile() - { - // Arrange - ILog log = LogManager.GetLogger(rep.Name, "CanWriteToDatabase"); - - // Act - log.Error(ErrorMessage); - Thread.Sleep(200); // let background thread finish - - // Assert - ReleaseFileLocks(); - Assert.That(File.Exists(GetFilePath()), Is.True); - IEnumerable readLines = File.ReadLines(GetFilePath()); - Assert.That(readLines.Count(), Is.GreaterThanOrEqualTo(1)); - } - - [Test] - public void ReturnsQuicklyAfterLogging100Messages() - { - // Arrange - ILog log = LogManager.GetLogger(rep.Name, "ReturnsQuicklyAfterLogging100Messages"); - - // Act - DateTime startTime = DateTime.UtcNow; - 100.Times(i => log.Error(ErrorMessage)); - DateTime endTime = DateTime.UtcNow; - - // Give background thread time to finish - Thread.Sleep(500); - - // Assert - ReleaseFileLocks(); - Assert.That(endTime - startTime, Is.LessThan(TimeSpan.FromMilliseconds(100))); - Assert.That(File.Exists(GetFilePath()), Is.True); - IEnumerable readLines = File.ReadLines(GetFilePath()); - Assert.That(readLines.Count(), Is.GreaterThanOrEqualTo(100)); - } - - [Test] - [Ignore] - public void CanLogAtleast1000MessagesASecond() - { - // Arrange - ILog log = LogManager.GetLogger(rep.Name, "CanLogAtLeast1000MessagesASecond"); - - int logCount = 0; - bool logging = true; - bool logsCounted = false; - - var logTimer = new Timer(s => - { - logging = false; - - if (File.Exists(GetFilePath())) - { - ReleaseFileLocks(); - IEnumerable readLines = File.ReadLines(GetFilePath()); - logCount = readLines.Count(); - } - logsCounted = true; - }, null, TimeSpan.FromSeconds(3), TimeSpan.FromMilliseconds(-1)); - - // Act - DateTime startTime = DateTime.UtcNow; - while (logging) - { - log.Error(ErrorMessage); - } - TimeSpan testDuration = DateTime.UtcNow - startTime; - - while (!logsCounted) - { - Thread.Sleep(1); - } - - logTimer.Dispose(); - - // Assert - var logsPerSecond = logCount / testDuration.TotalSeconds; - - Debug.Print("{0} messages logged in {1}s => {2}/s", logCount, testDuration.TotalSeconds, logsPerSecond); - Assert.That(logsPerSecond, Is.GreaterThan(1000), "Must log at least 1000 messages per second"); - } - } -} \ No newline at end of file diff --git a/src/Umbraco.Tests/Logging/DebugAppender.cs b/src/Umbraco.Tests/Logging/DebugAppender.cs deleted file mode 100644 index db78a96965..0000000000 --- a/src/Umbraco.Tests/Logging/DebugAppender.cs +++ /dev/null @@ -1,25 +0,0 @@ -using System; -using System.Threading; -using log4net.Appender; -using log4net.Core; - -namespace Umbraco.Tests.Logging -{ - /// - /// Borrowed from https://github.com/cjbhaines/Log4Net.Async - will reference Nuget packages directly in v8 - /// - public class DebugAppender : MemoryAppender - { - public TimeSpan AppendDelay { get; set; } - public int LoggedEventCount { get { return m_eventsList.Count; } } - - protected override void Append(LoggingEvent loggingEvent) - { - if (AppendDelay > TimeSpan.Zero) - { - Thread.Sleep(AppendDelay); - } - base.Append(loggingEvent); - } - } -} \ No newline at end of file diff --git a/src/Umbraco.Tests/Logging/ParallelForwarderTest.cs b/src/Umbraco.Tests/Logging/ParallelForwarderTest.cs deleted file mode 100644 index 88471ab650..0000000000 --- a/src/Umbraco.Tests/Logging/ParallelForwarderTest.cs +++ /dev/null @@ -1,327 +0,0 @@ -using System; -using System.Diagnostics; -using System.Security.Principal; -using System.Threading; -using log4net; -using log4net.Appender; -using log4net.Config; -using log4net.Core; -using log4net.Filter; -using log4net.Repository; -using Moq; -using NUnit.Framework; -using Umbraco.Core.Logging; - -namespace Umbraco.Tests.Logging -{ - /// - /// Borrowed from https://github.com/cjbhaines/Log4Net.Async - will reference Nuget packages directly in v8 - /// - [TestFixture] - public class ParallelForwarderTest : IDisposable - { - private ParallelForwardingAppender asyncForwardingAppender; - private DebugAppender debugAppender; - private ILoggerRepository repository; - private ILog log; - - [SetUp] - public void TestFixtureSetUp() - { - debugAppender = new DebugAppender(); - debugAppender.ActivateOptions(); - - asyncForwardingAppender = new ParallelForwardingAppender(); - asyncForwardingAppender.AddAppender(debugAppender); - asyncForwardingAppender.ActivateOptions(); - - repository = LogManager.CreateRepository(Guid.NewGuid().ToString()); - BasicConfigurator.Configure(repository, asyncForwardingAppender); - - log = LogManager.GetLogger(repository.Name, "TestLogger"); - } - - [TearDown] - public void TearDown() - { - LogManager.Shutdown(); - } - - [Test] - public void CanHandleNullLoggingEvent() - { - // Arrange - - // Act - asyncForwardingAppender.DoAppend((LoggingEvent)null); - log.Info("SusequentMessage"); - asyncForwardingAppender.Close(); - - // Assert - should not have had an exception from previous call - Assert.That(debugAppender.LoggedEventCount, Is.EqualTo(1), "Expected subsequent message only"); - Assert.That(debugAppender.GetEvents()[0].MessageObject, Is.EqualTo("SusequentMessage")); - } - - [Test] - public void CanHandleNullLoggingEvents() - { - // Arrange - - // Act - asyncForwardingAppender.DoAppend((LoggingEvent[])null); - log.Info("SusequentMessage"); - asyncForwardingAppender.Close(); - - // Assert - should not have had an exception from previous call - Assert.That(debugAppender.LoggedEventCount, Is.EqualTo(1), "Expected subsequent message only"); - Assert.That(debugAppender.GetEvents()[0].MessageObject, Is.EqualTo("SusequentMessage")); - } - - [Test] - public void CanHandleAppenderThrowing() - { - // Arrange - var badAppender = new Mock(); - asyncForwardingAppender.AddAppender(badAppender.Object); - - badAppender - .Setup(ba => ba.DoAppend(It.IsAny())) - .Throws(new Exception("Bad Appender")); - //.Verifiable(); - - // Act - log.Info("InitialMessage"); - log.Info("SusequentMessage"); - asyncForwardingAppender.Close(); - - // Assert - Assert.That(debugAppender.LoggedEventCount, Is.EqualTo(2)); - Assert.That(debugAppender.GetEvents()[1].MessageObject, Is.EqualTo("SusequentMessage")); - badAppender.Verify(appender => appender.DoAppend(It.IsAny()), Times.Exactly(2)); - } - - [Test] - public void WillLogFastWhenThereIsASlowAppender() - { - const int testSize = 1000; - - // Arrange - debugAppender.AppendDelay = TimeSpan.FromSeconds(30); - var watch = new Stopwatch(); - - // Act - watch.Start(); - for (int i = 0; i < testSize; i++) - { - log.Error("Exception"); - } - watch.Stop(); - - // Assert - Assert.That(debugAppender.LoggedEventCount, Is.EqualTo(0)); - Assert.That(watch.ElapsedMilliseconds, Is.LessThan(testSize)); - Debug.Print("Logged {0} errors in {1}ms", testSize, watch.ElapsedMilliseconds); - } - - [Test] - public void WillNotOverflow() - { - const int testSize = 1000; - - // Arrange - debugAppender.AppendDelay = TimeSpan.FromMilliseconds(1); - asyncForwardingAppender.BufferSize = 100; - - // Act - for (int i = 0; i < testSize; i++) - { - log.Error("Exception"); - } - - while (asyncForwardingAppender.BufferEntryCount > 0) ; - asyncForwardingAppender.Close(); - - // Assert - Assert.That(debugAppender.LoggedEventCount, Is.EqualTo(testSize)); - } - - [Test] - public void WillTryToFlushBufferOnShutdown() - { - const int testSize = 250; - - // Arrange - debugAppender.AppendDelay = TimeSpan.FromMilliseconds(1); - - // Act - for (int i = 0; i < testSize; i++) - { - log.Error("Exception"); - } - - Thread.Sleep(50); - - var numberLoggedBeforeClose = debugAppender.LoggedEventCount; - asyncForwardingAppender.Close(); - var numberLoggedAfterClose = debugAppender.LoggedEventCount; - - // Assert - //We can't use specific numbers here because the timing and counts will be different on different systems. - Assert.That(numberLoggedBeforeClose, Is.GreaterThan(0), "Some number of Logging events should be logged prior to appender close."); - //On some systems, we may not be able to flush all events prior to close, but it is reasonable to assume in this test case - //that some events should be logged after close. - Assert.That(numberLoggedAfterClose, Is.GreaterThan(numberLoggedBeforeClose), "Some number of LoggingEvents should be logged after close."); - Debug.Print("Flushed {0} events during shutdown", numberLoggedAfterClose - numberLoggedBeforeClose); - } - - [Test, Explicit("Long-running")] - public void WillShutdownIfBufferCannotBeFlushedFastEnough() - { - const int testSize = 250; - - // Arrange - debugAppender.AppendDelay = TimeSpan.FromSeconds(1); - Stopwatch watch = new Stopwatch(); - - // Act - for (int i = 0; i < testSize; i++) - { - log.Error("Exception"); - } - - Thread.Sleep(TimeSpan.FromSeconds(2)); - var numberLoggedBeforeClose = debugAppender.LoggedEventCount; - - watch.Start(); - asyncForwardingAppender.Close(); - watch.Stop(); - - var numberLoggedAfterClose = debugAppender.LoggedEventCount; - - // Assert - Assert.That(numberLoggedBeforeClose, Is.GreaterThan(0)); - Assert.That(numberLoggedAfterClose, Is.GreaterThan(numberLoggedBeforeClose)); - Assert.That(numberLoggedAfterClose, Is.LessThan(testSize)); - //We can't assume what the shutdown time will be. It will vary from system to system. Don't test shutdown time. - var events = debugAppender.GetEvents(); - var evnt = events[events.Length - 1]; - Assert.That(evnt.MessageObject, Is.EqualTo("The buffer was not able to be flushed before timeout occurred.")); - Debug.Print("Flushed {0} events during shutdown which lasted {1}ms", numberLoggedAfterClose - numberLoggedBeforeClose, watch.ElapsedMilliseconds); - } - - [Test] - public void ThreadContextPropertiesArePreserved() - { - // Arrange - ThreadContext.Properties["TestProperty"] = "My Value"; - Assert.That(asyncForwardingAppender.Fix & FixFlags.Properties, Is.EqualTo(FixFlags.Properties), "Properties must be fixed if they are to be preserved"); - - // Act - log.Info("Information"); - asyncForwardingAppender.Close(); - - // Assert - var lastLoggedEvent = debugAppender.GetEvents()[0]; - Assert.That(lastLoggedEvent.Properties["TestProperty"], Is.EqualTo("My Value")); - } - - [Test] - public void MessagesExcludedByFilterShouldNotBeAppended() - { - // Arrange - var levelFilter = - new LevelRangeFilter - { - LevelMin = Level.Warn, - LevelMax = Level.Error, - }; - - asyncForwardingAppender.AddFilter(levelFilter); - - // Act - log.Info("Info"); - log.Warn("Warn"); - log.Error("Error"); - log.Fatal("Fatal"); - - asyncForwardingAppender.Close(); - - //Assert - Assert.That(debugAppender.LoggedEventCount, Is.EqualTo(2)); - } - - [Test] - public void HelperCanGenerateLoggingEventWithAllProperties() - { - // Arrange - var helper = new LoggingEventHelper("TestLoggerName", FixFlags.All); - ThreadContext.Properties["MyProperty"] = "MyValue"; - var exception = new Exception("SomeError"); - - var stackFrame = new StackFrame(0); - var currentUser = WindowsIdentity.GetCurrent(); - var loggingTime = DateTime.Now; // Log4Net does not seem to be using UtcNow - - // Act - var loggingEvent = helper.CreateLoggingEvent(Level.Emergency, "Who's on live support?", exception); - Thread.Sleep(50); // to make sure the time stamp is actually captured - - // Assert - Assert.That(loggingEvent.Domain, Is.EqualTo(AppDomain.CurrentDomain.FriendlyName), "Domain"); - //The identity assigned to new threads is dependent upon AppDomain principal policy. - //Background information here:http://www.neovolve.com/post/2010/10/21/Unit-testing-a-workflow-that-relies-on-ThreadCurrentPrincipalIdentityName.aspx - //VS2013 does have a principal assigned to new threads in the unit test. - //It's probably best not to test that the identity has been set. - //Assert.That(loggingEvent.Identity, Is.Empty, "Identity: always empty for some reason"); - Assert.That(loggingEvent.UserName, Is.EqualTo(currentUser == null ? String.Empty : currentUser.Name), "UserName"); - Assert.That(loggingEvent.ThreadName, Is.EqualTo(Thread.CurrentThread.Name), "ThreadName"); - - Assert.That(loggingEvent.Repository, Is.Null, "Repository: Helper does not have access to this"); - Assert.That(loggingEvent.LoggerName, Is.EqualTo("TestLoggerName"), "LoggerName"); - - Assert.That(loggingEvent.Level, Is.EqualTo(Level.Emergency), "Level"); - //Raised time to within 10 ms. However, this may not be a valid test. The time is going to vary from system to system. The - //tolerance setting here is arbitrary. - Assert.That(loggingEvent.TimeStamp, Is.EqualTo(loggingTime).Within(TimeSpan.FromMilliseconds(10)), "TimeStamp"); - Assert.That(loggingEvent.ExceptionObject, Is.EqualTo(exception), "ExceptionObject"); - Assert.That(loggingEvent.MessageObject, Is.EqualTo("Who's on live support?"), "MessageObject"); - - Assert.That(loggingEvent.LocationInformation.MethodName, Is.EqualTo(stackFrame.GetMethod().Name), "LocationInformation"); - Assert.That(loggingEvent.Properties["MyProperty"], Is.EqualTo("MyValue"), "Properties"); - } - - private bool _disposed = false; - - //Implement IDisposable. - public void Dispose() - { - Dispose(true); - GC.SuppressFinalize(this); - } - - protected virtual void Dispose(bool disposing) - { - if (!_disposed) - { - if (disposing) - { - if (asyncForwardingAppender != null) - { - asyncForwardingAppender.Dispose(); - asyncForwardingAppender = null; - } - } - // Free your own state (unmanaged objects). - // Set large fields to null. - _disposed = true; - } - } - - // Use C# destructor syntax for finalization code. - ~ParallelForwarderTest() - { - // Simply call Dispose(false). - Dispose(false); - } - } -} \ No newline at end of file diff --git a/src/Umbraco.Tests/Logging/RingBufferTest.cs b/src/Umbraco.Tests/Logging/RingBufferTest.cs deleted file mode 100644 index 69c58b8631..0000000000 --- a/src/Umbraco.Tests/Logging/RingBufferTest.cs +++ /dev/null @@ -1,150 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Diagnostics; -using System.Threading; -using System.Threading.Tasks; -using NUnit.Framework; -using Umbraco.Core.Logging; -using Umbraco.Tests.TestHelpers; - -namespace Umbraco.Tests.Logging -{ - /// - /// Borrowed from https://github.com/cjbhaines/Log4Net.Async - will reference Nuget packages directly in v8 - /// - [TestFixture] - public class RingBufferTest - { - [Test] - public void PerfTest() - { - RingBuffer ringBuffer = new RingBuffer(1000); - Stopwatch ringWatch = new Stopwatch(); - ringWatch.Start(); - for (int i = 0; i < 1000000; i++) - { - ringBuffer.Enqueue("StringOfFun"); - } - ringWatch.Stop(); - - Assert.That(ringWatch.ElapsedMilliseconds, Is.LessThan(150)); - } - - [Test] - public void PerfTestThreads() - { - RingBuffer ringBuffer = new RingBuffer(1000); - - Stopwatch ringWatch = new Stopwatch(); - List ringTasks = new List(); - CancellationTokenSource cancelationTokenSource = new CancellationTokenSource(); - CancellationToken cancelationToken = cancelationTokenSource.Token; - for (int t = 0; t < 10; t++) - { - ringTasks.Add(new Task(() => - { - for (int i = 0; i < 1000000; i++) - { - ringBuffer.Enqueue("StringOfFun"); - } - }, cancelationToken)); - } - ringWatch.Start(); - ringTasks.ForEach(t => t.Start()); - var allTasks = ringTasks.ToArray(); - Task.WaitAny(allTasks); - ringWatch.Stop(); - //Cancel tasks to avoid System.AppDominUnloadException which is caused when the domain is unloaded - //and threads created in the domain are not stopped. - //Do this before assertions because they may throw an exception causing the thread cancellation to not happen. - cancelationTokenSource.Cancel(); - try - { - Task.WaitAll(allTasks); - } - catch (AggregateException) - { - //Don't care about cancellation Exceptions. - } - //Tolerance at 500 was too low - ringTasks.ForEach(t => t.Dispose()); - Assert.That(ringWatch.ElapsedMilliseconds, Is.LessThan(1000)); - } - - [Test] - public void PerfTestThreadsWithDequeues() - { - RingBuffer ringBuffer = new RingBuffer(1000); - - Stopwatch ringWatch = new Stopwatch(); - List ringTasks = new List(); - CancellationTokenSource cancelationTokenSource = new CancellationTokenSource(); - CancellationToken cancelationToken = cancelationTokenSource.Token; - for (int t = 0; t < 10; t++) - { - ringTasks.Add(new Task(() => - { - for (int i = 0; i < 1000000; i++) - { - ringBuffer.Enqueue("StringOfFun"); - } - }, cancelationToken)); - } - for (int t = 0; t < 10; t++) - { - ringTasks.Add(new Task(() => - { - for (int i = 0; i < 1000000; i++) - { - string foo; - ringBuffer.TryDequeue(out foo); - } - })); - } - ringWatch.Start(); - ringTasks.ForEach(t => t.Start()); - var allTasks = ringTasks.ToArray(); - Task.WaitAny(allTasks); - ringWatch.Stop(); - //Cancel tasks to avoid System.AppDominUnloadException which is caused when the domain is unloaded - //and threads created in the domain are not stopped. - //Do this before assertions because they may throw an exception causing the thread cancellation to not happen. - cancelationTokenSource.Cancel(); - try - { - Task.WaitAll(allTasks); - } - catch (AggregateException) - { - //Don't care about cancellation Exceptions. - } - ringTasks.ForEach(t => t.Dispose()); - Assert.That(ringWatch.ElapsedMilliseconds, Is.LessThan(800)); - } - - [Test] - public void WhenRingSizeLimitIsHit_ItemsAreDequeued() - { - // Arrange - const int limit = 2; - object object1 = "one"; - object object2 = "two"; - object object3 = "three"; - RingBuffer queue = new RingBuffer(limit); - - // Act - queue.Enqueue(object1); - queue.Enqueue(object2); - queue.Enqueue(object3); - - // Assert - object value; - queue.TryDequeue(out value); - Assert.That(value, Is.EqualTo(object2)); - queue.TryDequeue(out value); - Assert.That(value, Is.EqualTo(object3)); - queue.TryDequeue(out value); - Assert.That(value, Is.Null); - } - } -} \ No newline at end of file diff --git a/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests2.cs b/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests2.cs index baffcb4b14..744d4e7bc2 100644 --- a/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests2.cs +++ b/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests2.cs @@ -3,7 +3,7 @@ using System.Diagnostics; using System.Threading; using System.Threading.Tasks; using NUnit.Framework; -using Umbraco.Tests.Logging; +using Umbraco.Tests.TestHelpers; using Umbraco.Web.Scheduling; namespace Umbraco.Tests.Scheduling diff --git a/src/Umbraco.Tests/Logging/ConsoleLogger.cs b/src/Umbraco.Tests/TestHelpers/ConsoleLogger.cs similarity index 98% rename from src/Umbraco.Tests/Logging/ConsoleLogger.cs rename to src/Umbraco.Tests/TestHelpers/ConsoleLogger.cs index e90aa64f47..a456ba876d 100644 --- a/src/Umbraco.Tests/Logging/ConsoleLogger.cs +++ b/src/Umbraco.Tests/TestHelpers/ConsoleLogger.cs @@ -2,7 +2,7 @@ using System.Linq; using Umbraco.Core.Logging; -namespace Umbraco.Tests.Logging +namespace Umbraco.Tests.TestHelpers { public class ConsoleLogger : ILogger { diff --git a/src/Umbraco.Tests/Umbraco.Tests.csproj b/src/Umbraco.Tests/Umbraco.Tests.csproj index 1bb38ed8cb..8332458c0e 100644 --- a/src/Umbraco.Tests/Umbraco.Tests.csproj +++ b/src/Umbraco.Tests/Umbraco.Tests.csproj @@ -70,6 +70,9 @@ ..\packages\log4net.2.0.8\lib\net45-full\log4net.dll + + ..\packages\Log4Net.Async.2.0.4\lib\net40\Log4Net.Async.dll + ..\packages\Lucene.Net.2.9.4.1\lib\net40\Lucene.Net.dll @@ -165,7 +168,7 @@ - + @@ -207,9 +210,6 @@ - - - @@ -487,7 +487,6 @@ - diff --git a/src/Umbraco.Tests/packages.config b/src/Umbraco.Tests/packages.config index 833b50746d..a1b426a52b 100644 --- a/src/Umbraco.Tests/packages.config +++ b/src/Umbraco.Tests/packages.config @@ -5,6 +5,7 @@ + diff --git a/src/Umbraco.Web.UI/config/log4net.Release.config b/src/Umbraco.Web.UI/config/log4net.Release.config index 10b8c9eb7a..0e93b7122f 100644 --- a/src/Umbraco.Web.UI/config/log4net.Release.config +++ b/src/Umbraco.Web.UI/config/log4net.Release.config @@ -18,7 +18,7 @@ - + diff --git a/src/Umbraco.Web.UI/config/log4net.config b/src/Umbraco.Web.UI/config/log4net.config index eca84962a1..372e5c7b88 100644 --- a/src/Umbraco.Web.UI/config/log4net.config +++ b/src/Umbraco.Web.UI/config/log4net.config @@ -18,7 +18,7 @@ - +