using System; using System.Collections.Generic; using System.IO; using System.Linq; using System.Reflection; using System.Threading; using System.Threading.Tasks; using AMWD.Common.Logging; using Microsoft.Extensions.Logging; using Microsoft.VisualStudio.TestTools.UnitTesting; using Moq; namespace UnitTests.Common.Logging { [TestClass] public class FileLoggerTests { private Mock streamWriterMock; private List lines; [TestInitialize] public void Initialize() { lines = new List(); } [TestMethod] public void ShouldCreateInstance() { // arrange string path = Path.GetTempFileName(); try { // act using var logger = new FileLogger(path); // assert Assert.IsNotNull(logger); Assert.IsTrue(File.Exists(path)); Assert.AreEqual(path, logger.FileName); Assert.AreEqual(LogLevel.Trace, logger.MinLevel); Assert.IsNull(logger.Name); Assert.IsNull(logger.ParentLogger); Assert.IsNull(logger.TimestampFormat); Assert.IsNull(logger.ScopeProvider); } finally { File.Delete(path); } } [TestMethod] public void ShouldCreateInstanceAsNamedInstance() { // arrange string name = "NamedInstance"; string path = Path.GetTempFileName(); try { // act using var logger = new FileLogger(path, name); // assert Assert.IsNotNull(logger); Assert.IsTrue(File.Exists(path)); Assert.AreEqual(path, logger.FileName); Assert.AreEqual(LogLevel.Trace, logger.MinLevel); Assert.AreEqual(name, logger.Name); Assert.IsNull(logger.ParentLogger); Assert.IsNull(logger.TimestampFormat); Assert.IsNull(logger.ScopeProvider); } finally { File.Delete(path); } } [TestMethod] [ExpectedException(typeof(ObjectDisposedException))] public void ShouldThrowDisposedOnIsEnabled() { // arrange var logger = GetFileLogger(); // act logger.Dispose(); logger.IsEnabled(LogLevel.Error); // assert - ObjectDisposedException Assert.Fail(); } [TestMethod] [ExpectedException(typeof(ObjectDisposedException))] public void ShouldThrowDisposedOnLog() { // arrange var logger = GetFileLogger(); // act logger.Dispose(); logger.Log(LogLevel.None, "Some Message"); // assert - ObjectDisposedException Assert.Fail(); } [TestMethod] [ExpectedException(typeof(ObjectDisposedException))] public void ShouldThrowDisposedOnBeginScope() { // arrange var logger = GetFileLogger(); // act logger.Dispose(); logger.BeginScope("foo"); // assert - ObjectDisposedException Assert.Fail(); } [DataTestMethod] [DataRow(LogLevel.Trace, false)] [DataRow(LogLevel.Debug, false)] [DataRow(LogLevel.Information, false)] [DataRow(LogLevel.Warning, true)] [DataRow(LogLevel.Error, true)] [DataRow(LogLevel.Critical, true)] [DataRow(LogLevel.None, true)] public void ShouldReturnIsEnabled(LogLevel logLevel, bool expectedResult) { // arrange using var logger = GetFileLogger(); logger.MinLevel = LogLevel.Warning; // act bool result = logger.IsEnabled(logLevel); // assert Assert.AreEqual(expectedResult, result); } [TestMethod] public void ShouldLogMessage() { // arrange using var logger = GetFileLogger(); // act logger.Log(LogLevel.Information, "Test Message"); SpinWait.SpinUntil(() => lines.Count == 1); // assert Assert.AreEqual("INFO | Test Message", lines.First()); streamWriterMock.Verify(sw => sw.WriteLineAsync(It.IsAny()), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); } [TestMethod] public void ShouldLogAllLevels() { // arrange using var logger = GetFileLogger(); // act foreach (LogLevel level in Enum.GetValues()) logger.Log(level, "Test Message"); SpinWait.SpinUntil(() => lines.Count == 7); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync("TRCE | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync("DBUG | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync("INFO | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync("WARN | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync("FAIL | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync("CRIT | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync(" | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.AtLeastOnce); streamWriterMock.VerifyNoOtherCalls(); } [TestMethod] public void ShouldLogOnlyAboveMinLevel() { // arrange using var logger = GetFileLogger(); logger.MinLevel = LogLevel.Error; // act foreach (LogLevel level in Enum.GetValues()) logger.Log(level, "Test Message"); SpinWait.SpinUntil(() => lines.Count == 3); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync("FAIL | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync("CRIT | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.WriteLineAsync(" | Test Message"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.AtLeastOnce); streamWriterMock.VerifyNoOtherCalls(); } [TestMethod] public void ShouldLogWithLocalTimestamp() { // arrange using var logger = GetFileLogger(); logger.UseUtcTimestamp = false; logger.TimestampFormat = "yyyy-MM-dd HH:mm"; // act logger.LogWarning("Some Warning"); SpinWait.SpinUntil(() => lines.Count == 1); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync($"{DateTime.Now:yyyy-MM-dd HH:mm} | WARN | Some Warning"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); } [TestMethod] public void ShouldLogWithUtcTimestamp() { // arrange using var logger = GetFileLogger(); logger.UseUtcTimestamp = true; logger.TimestampFormat = "yyyy-MM-dd HH:mm"; // act logger.LogWarning("Some Warning"); SpinWait.SpinUntil(() => lines.Count == 1); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync($"{DateTime.UtcNow:yyyy-MM-dd HH:mm} | WARN | Some Warning"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); } [TestMethod] public void ShouldUseParentLogger() { // arrange string file = Path.GetTempFileName(); try { using var parent = GetFileLogger(); parent.UseUtcTimestamp = false; parent.TimestampFormat = "yyyy-MM-dd HH:mm"; using var logger = new FileLogger(file, "NamedInstance", parent); // act logger.LogWarning("Some Warning"); SpinWait.SpinUntil(() => lines.Count == 1); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync($"{DateTime.Now:yyyy-MM-dd HH:mm} | WARN | [NamedInstance] Some Warning"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); Assert.AreEqual(0, new FileInfo(file).Length); } finally { File.Delete(file); } } [TestMethod] public void ShouldUseScopeProvider() { // arrange var scopeProvider = new Mock(); using var logger = GetFileLogger("NamedInstance", scopeProvider.Object); // act using (var scope = logger.BeginScope("scope")) { logger.LogError("Test"); SpinWait.SpinUntil(() => lines.Count == 1); } // assert streamWriterMock.Verify(sw => sw.WriteLineAsync("FAIL | [NamedInstance] Test"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); scopeProvider.Verify(sp => sp.Push("scope"), Times.Once); scopeProvider.Verify(sp => sp.ForEachScope(It.IsAny>(), It.IsAny()), Times.Once); scopeProvider.VerifyNoOtherCalls(); } [TestMethod] public void ShouldLogException() { // arrange using var logger = GetFileLogger(); // act logger.LogCritical(new Exception("TestException"), ""); SpinWait.SpinUntil(() => lines.Count == 1); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync("CRIT | System.Exception: TestException"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); } [TestMethod] public void ShouldLogExceptionWithMessage() { // arrange using var logger = GetFileLogger(); // act logger.LogCritical(new Exception("TestException"), "Bad things happen..."); SpinWait.SpinUntil(() => lines.Count == 1); // assert streamWriterMock.Verify(sw => sw.WriteLineAsync($"CRIT | Bad things happen...{Environment.NewLine} System.Exception: TestException"), Times.Once); streamWriterMock.Verify(sw => sw.FlushAsync(), Times.Once); streamWriterMock.VerifyNoOtherCalls(); } private FileLogger GetFileLogger(string name = null, IExternalScopeProvider scopeProvider = null) { string tmpFilePath = Path.GetTempFileName(); try { streamWriterMock = new Mock(Stream.Null); streamWriterMock .Setup(sw => sw.WriteLineAsync(It.IsAny())) .Callback(line => lines.Add(line)) .Returns(Task.CompletedTask); FileLogger fileLogger; if (name == null || scopeProvider == null) { fileLogger = new FileLogger(tmpFilePath); } else { fileLogger = new FileLogger(tmpFilePath, name, scopeProvider); } var fieldInfo = fileLogger.GetType().GetField("fileWriter", BindingFlags.NonPublic | BindingFlags.Instance); (fieldInfo.GetValue(fileLogger) as StreamWriter).Dispose(); fieldInfo.SetValue(fileLogger, streamWriterMock.Object); return fileLogger; } finally { File.Delete(tmpFilePath); } } } }