public void QueueHangfire_Logging() { var hangFireLogger = new HangfireLogProvider(TestLoggerFactory); var sourceContext = "QueueHangfireUnitTests"; var logger = hangFireLogger.GetLogger(sourceContext); var testString = "Test: QueueHangfire_Logging"; using (TestCorrelator.CreateContext()) { logger.Log(LogLevel.Debug, () => testString); TestCorrelator.GetLogEventsFromCurrentContext() .Should().ContainSingle() .Which.Properties["State"].ToString() .Should().Be(testString.ToDoubleQuoted()); TestCorrelator.GetLogEventsFromCurrentContext() .Should().ContainSingle() .Which.Properties["SourceContext"].ToString() .Should().Be(sourceContext.ToDoubleQuoted()); } }
public async Task Should_create_log_scope() { using (TestCorrelator.CreateContext()) { _logger.LogInformation("Start message without correlation id."); // Act await _sut.CorrelateAsync(() => { _logger.LogInformation("Message with correlation id."); return(Task.CompletedTask); }); _logger.LogInformation("End message without correlation id."); // Assert List <LogEvent> logEvents = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); logEvents.Should() .HaveCount(3) .And.ContainSingle(ev => ev.MessageTemplate.Text == "Message with correlation id." && ev.Properties.ContainsKey("CorrelationId")); } }
public void XunitSink_Create_TestCorrelator() { var fileSystem = new FileSystem(typeof(XunitSinkUnitTests)); var loggerSettings = new SerilogLoggerSettings(fileSystem, LogEventLevel.Debug, LoggingOutputFlags.TestCorrelator); var loggerConfiguration = XunitLoggingSink.CreateXUnitLoggerConfiguration(_testOutputHelper, loggerSettings, XUnitSerilogFormatter.RenderedCompactJsonFormatter); var loggerFactory = XunitLoggingSink.CreateXUnitSerilogFactory(loggerSettings, loggerConfiguration); var logger = loggerFactory.CreatePureLogger <XunitSinkUnitTests>(); logger.Should().NotBeNull("CreatePureLogger should always succeed"); using (TestCorrelator.CreateContext()) { logger.LogInformation("Test: XunitSink_Create_TestCorrelator"); TestCorrelator.GetLogEventsFromCurrentContext() .Should().ContainSingle() .Which.MessageTemplate.Text .Should().Be("Test: XunitSink_Create_TestCorrelator"); } }
public async Task Run_ThrowsOnReportingRepositoryException() { // Arrange SetupRepositoryMethods(); var expectedException = new ApplicationException("Connection was unsuccessful"); // Override migration with an exception _externalStoredProcedureRepository .Setup(r => r.ExecuteReportingGenerateStoredProcedure()) .Throws(expectedException); Log.Logger = new LoggerConfiguration().WriteTo.TestCorrelator().CreateLogger(); using (TestCorrelator.CreateContext()) { // Act var actualException = await Assert.ThrowsAsync<ApplicationException>(async () => await _reportingDataRefreshJob.Run(null)); // Assert Assert.Equal(expectedException, actualException); AssertRepositoryMethodsCalled(); var logEvents = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); AssertContainsInfoMessages(logEvents, new[] { "Starting specimen-matching uspGenerate", "Starting migration uspGenerate", "Starting reporting uspGenerate" }); Assert.Contains(logEvents, logEvent => logEvent.Level == LogEventLevel.Error && logEvent.RenderMessage() == "Error occured during reporting data refresh job" && logEvent.Exception == expectedException); AssertDoesNotContainInfoMessages(logEvents, new[] { "Finishing reporting data refresh job" }); } }
public void Getting_LogEvents_preserves_the_order_in_which_they_were_emitted() { var logEvents = Enumerable.Range(0, 100) .Select(_ => new LogEvent( DateTimeOffset.MinValue, LogEventLevel.Information, null, new MessageTemplate(Enumerable.Empty <MessageTemplateToken>()), Enumerable.Empty <LogEventProperty>())) .ToList(); using (var context = TestCorrelator.CreateContext()) { foreach (var logEvent in logEvents) { Log.Write(logEvent); } TestCorrelator.GetLogEventsFromCurrentContext().Should().Equal(logEvents); } }
public async Task Invoke_logs_as_expected() { var logger = new LoggerConfiguration() .WriteTo.TestCorrelator() .CreateLogger(); var mw = new RequestLoggingMiddleware((innerHttpContext) => Task.FromResult(0), Helpers.MockIAppSettings(), logger); var context = TestContext(); using (TestCorrelator.CreateContext()) { await mw.InvokeAsync(context); var logEvent = TestCorrelator.GetLogEventsFromCurrentContext().FirstOrDefault(); using var scope = new AssertionScope(); logEvent.Should().NotBeNull(); Assert.AreEqual(RequestLoggingMiddleware.DBG_LOG_TEMPLATE, logEvent.MessageTemplate.Text); logEvent.Level.Should().Be(LogEventLevel.Information); } }
public async Task Run_LogsInfo_WhenFieldReducedByVerySmallAmount(int currentCount, int previousCount) { // Arrange var tableCounts = new[] { CreateBasicTableCounts(currentCount), CreateBasicTableCounts(previousCount) }; _tableCountsRepository .Setup(r => r.GetRecentTableCounts()) .Returns(Task.FromResult(tableCounts.AsEnumerable())); Log.Logger = new LoggerConfiguration().WriteTo.TestCorrelator().CreateLogger(); using (TestCorrelator.CreateContext()) { // Act await _updateTableCountsJob.Run(null); // Assert var logEvents = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); Assert.DoesNotContain(logEvents, logEvent => logEvent.Level > LogEventLevel.Information); Assert.Contains(logEvents, logEvent => logEvent.Level == LogEventLevel.Information && logEvent.RenderMessage() == "Table counts look normal"); } }
public void When_A_Request_Logger_Is_In_The_Pipeline() { Log.Logger = new LoggerConfiguration().MinimumLevel.Information().WriteTo.TestCorrelator().CreateLogger(); using (var context = TestCorrelator.CreateContext()) { var myCommand = new MyCommand(); var registry = new SubscriberRegistry(); registry.Register <MyCommand, IHandleRequests <MyCommand> >(); var container = new ServiceCollection(); var requestLogger = new RequestLoggingHandler <MyCommand>(); container.AddTransient <IHandleRequests <MyCommand>, MyLoggedHandler>(); container.AddTransient(typeof(RequestLoggingHandler <MyCommand>), provider => requestLogger); var handlerFactory = new ServiceProviderHandlerFactory(container.BuildServiceProvider()); var commandProcessor = new CommandProcessor(registry, handlerFactory, handlerFactory, new InMemoryRequestContextFactory(), new PolicyRegistry()); commandProcessor.Send(myCommand); //_should_log_the_request_handler_call //_should_log_the_type_of_handler_in_the_call //TestCorrelator.GetLogEventsFromCurrentContext().Should().HaveCount(3); TestCorrelator.GetLogEventsFromContextGuid(context.Guid) .Should().Contain(x => x.MessageTemplate.Text.StartsWith("Logging handler pipeline call")) .Which.Properties["1"].ToString().Should().Be($"\"{typeof(MyCommand)}\""); commandProcessor?.Dispose(); } }
public async Task Run_ThrowsOnSpecimenMatchingStoredProcedureMessage() { // Arrange List<dynamic> sqlResult = new List<object> { new { ErrorMessage = "Divide by zero error encountered." } }; const string serialisedResult = "[{\"ErrorMessage\":\"Divide by zero error encountered.\"}]"; SetupRepositoryMethods(specimenMatchingReturnResult: sqlResult.AsEnumerable()); Log.Logger = new LoggerConfiguration().WriteTo.TestCorrelator().CreateLogger(); using (TestCorrelator.CreateContext()) { // Act var exception = await Assert.ThrowsAsync<ApplicationException>(async () => await _reportingDataRefreshJob.Run(null)); // Assert Assert.Equal("Stored procedure did not execute successfully as result has messages, check the logs", exception.Message); AssertRepositoryMethodsCalled(reportingCalled: false); var logEvents = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); AssertContainsInfoMessages(logEvents, new[] { "Starting migration uspGenerate", "Starting specimen-matching uspGenerate", $"Result: {serialisedResult}" }); Assert.Contains(logEvents, logEvent => logEvent.Level == LogEventLevel.Error && logEvent.RenderMessage() == "Error occured during reporting data refresh job"); AssertDoesNotContainInfoMessages(logEvents, new[] { "Starting reporting uspGenerate", "Finishing reporting data refresh job" }); } }
static int Main(string[] args) { InitLogger(); Test.Module("Nancy.Serilog.Core Tests"); Test.CaseAsync("Serilog emits correlated log events when with same logger being passed down to dependencies", async() => { using (TestCorrelator.CreateContext()) { var browser = new Browser(new Bootstrapper()); var result = await browser.Get("/"); var eventLogs = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); Test.Equal(5, eventLogs.Count()); Test.Equal(true, eventLogs.All(log => log.Level == LogEventLevel.Information)); var firstRequestId = eventLogs.First().Properties.AsEnumerable().First(log => log.Key == "RequestId").Value.ToString(); Test.Equal(false, String.IsNullOrWhiteSpace(firstRequestId)); var allRequestIds = eventLogs.Select(log => { return(log.Properties .ToList() .First(prop => prop.Key == "RequestId") .Value .ToString()); }); Test.Equal(true, allRequestIds.All(requestId => requestId == firstRequestId)); } }); return(Test.Report()); }
public void Log_each_incoming_request_and_each_outgoing_response() { using (TestCorrelator.CreateContext()) { AppFunc pipelineFunc(AppFunc next) => RequestLogging.Middleware(next, m_Logger); var ctx = SetupOwinTestEnvironment("/test"); var pipeline = pipelineFunc(m_NoOp); var env = ctx.Environment; pipeline(env); var msgs = TestCorrelator.GetLogEventsFromCurrentContext(); msgs.Should().NotBeEmpty().And.HaveCount(2); var reqLogMsg = msgs.First(); reqLogMsg.Level.Should().Be(LogEventLevel.Information); reqLogMsg.RenderMessage().Should().Be("Incoming request: \"GET\", PathString { Value: \"/test\", HasValue: True }, []"); var resLogMsg = msgs.Last(); resLogMsg.Level.Should().Be(LogEventLevel.Information); resLogMsg.RenderMessage().Should().Be("Outgoing response: 200, []"); } }
public void PureSeriLogger_PushLogProperties_LogPropertyList_Include_False() { const string testProperty = "Property"; const string testValue = "Value"; const string testLogMsg = "Test Message"; var logPropertyList = new List <IPureLogPropertyLevel>() { new PureLogPropertyLevel(new KeyValuePair <string, object>(testProperty, testValue), LogLevel.Debug) }; using (TestCorrelator.CreateContext()) using (_pureSeriLogger.PushLogProperties(logPropertyList, IncludeLogPropertyFalse)) { _pureSeriLogger.LogDebug(testLogMsg); var currentTestContext = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); currentTestContext.Should().ContainSingle().Which.Properties.ContainsKey(testProperty).Should().BeFalse(); currentTestContext.Should().ContainSingle().Which.MessageTemplate.Text.Should().Be(testLogMsg); } }
public void PureSeriLogger_PushLogProperties_KeyValue_LogPropertyList() { const string testProperty = "Property"; const string testValue = "Value"; const string testLogMsg = "Test Message"; var logPropertyList = new List <KeyValuePair <string, object> >() { new KeyValuePair <string, object>(testProperty, testValue) }; using (TestCorrelator.CreateContext()) using (_pureSeriLogger.PushLogProperties(logPropertyList)) { _pureSeriLogger.LogDebug(testLogMsg); var currentTestContext = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); currentTestContext.Should().ContainSingle().Which.Properties.ContainsKey(testProperty).Should().BeTrue(); currentTestContext.Should().ContainSingle().Which.Properties[testProperty].ToString().Should().Be(testValue.ToDoubleQuoted()); currentTestContext.Should().ContainSingle().Which.MessageTemplate.Text.Should().Be(testLogMsg); } }
public async Task Run_LogsInfo_WhenNotEnoughRecords(int numberOfRecords) { // Arrange _tableCountsRepository .Setup(r => r.GetRecentTableCounts()) .Returns(Task.FromResult(Enumerable.Repeat(CreateBasicTableCounts(), numberOfRecords))); Log.Logger = new LoggerConfiguration().WriteTo.TestCorrelator().CreateLogger(); using (TestCorrelator.CreateContext()) { // Act await _updateTableCountsJob.Run(null); const string expectedMessage = "Not enough table counts available. Try re-running the update-table-counts job."; // Assert var logEvents = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); Assert.DoesNotContain(logEvents, logEvent => logEvent.Level > LogEventLevel.Information); Assert.Contains(logEvents, logEvent => logEvent.Level == LogEventLevel.Information && logEvent.RenderMessage() == expectedMessage); } }
private void RoundTripTest <T>(T obj) { using (TestCorrelator.CreateContext()) { Log.Information("This is a test message {@Obj}", obj); var loggedEvents = TestCorrelator.GetLogEventsFromCurrentContext().ToList(); loggedEvents.Should().ContainSingle(); var writer = new StringWriter(); new CompactJsonFormatter().Format(loggedEvents.Single(), writer); var reader = new StringReader(writer.ToString()); using var jsonReader = new LogEventReader(reader); jsonReader.TryRead(out var deserialisedEvent); string objJson = deserialisedEvent.Properties["Obj"].ToString(); var deserialisedObj = JsonConvert.DeserializeObject <T>(objJson, _jsonSerializerSettings !); deserialisedObj.Should().BeEquivalentTo(obj, "of round trip"); } }
private void ResetContext() { _context.Dispose(); _context = TestCorrelator.CreateContext(); }