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"
                });
            }
        }
Exemple #5
0
        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);
            }
        }
Exemple #7
0
        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");
            }
        }
Exemple #8
0
        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"
                });
            }
        }
Exemple #10
0
        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());
        }
Exemple #11
0
        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);
                }
        }
Exemple #14
0
        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();
 }