public void GetLinkingMetadata_IsHandled_MetadataPropertyAdded() { // Arrange var wasRun = false; var testDict = new Dictionary <string, string> { { "trace.id", "trace-id" }, { "span.id", "span-id" }, { "entity.name", "entity-name" }, { "entity.type", "entity-type" }, { "entity.guid", "entity-guid" }, { "hostname", "host-name" } }; Mock.Arrange(() => _testAgent.GetLinkingMetadata()) .DoInstead(() => { wasRun = true; }) .Returns(testDict); var testEnricher = new NewRelicEnricher(() => _testAgent); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); // Act testLogger.Warning(WarningLogMessage); // Assert Assert.That(wasRun, Is.True); Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(1)); Assert.That(_outputSink.LogEvents[0].MessageTemplate.Text, Is.EqualTo(WarningLogMessage)); Assert.That(_outputSink.LogEvents[0].Properties, Does.ContainKey(LinkingMetadataKey)); Assert.That(_testRunDebugLogs.Count, Is.EqualTo(0)); }
public void GetLinkingMetadata_IsHandled_DuplicateKeyInMessageTemplate() { // Arrange const string TestValue = "TEST VALUE"; const string TestTemplate = "TEMPLATE {newrelic.linkingmetadata}"; // matches our metadata property name var wasRun = false; var testDict = new Dictionary <string, string> { { "message", "duplicate" } }; // must not be empty Mock.Arrange(() => _testAgent.GetLinkingMetadata()) .DoInstead(() => { wasRun = true; }) .Returns(testDict); var testEnricher = new NewRelicEnricher(() => _testAgent); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); // Act testLogger.Warning(TestTemplate, TestValue); // Assert Assert.That(wasRun, Is.True); Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(1)); Assert.That(_outputSink.LogEvents[0].MessageTemplate.Text, Is.EqualTo(TestTemplate)); Assert.That(_testRunDebugLogs.Count, Is.EqualTo(0)); Assert.That(_outputSink.LogEvents[0].Properties, Does.ContainKey(LinkingMetadataKey)); Assert.That(_outputSink.LogEvents[0].Properties[LinkingMetadataKey].ToString(), Does.Not.Contain(TestValue)); }
public void Enricher_IsHandled_Exception() { // Arrange var wasRun = false; Mock.Arrange(() => _testAgent.GetLinkingMetadata()) .DoInstead(() => { wasRun = true; throw new Exception("Exception - GetLinkingMetadata"); }); var testEnricher = new NewRelicEnricher(() => _testAgent); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); // Act testLogger.Warning(ExceptionLogMessage); // Assert Assert.That(wasRun, Is.True); Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(1)); Assert.That(_outputSink.LogEvents[0].MessageTemplate.Text, Is.EqualTo(ExceptionLogMessage)); Assert.That(_outputSink.LogEvents[0].Properties, Does.Not.ContainKey(LinkingMetadataKey)); Assert.That(_testRunDebugLogs.Count, Is.EqualTo(1)); Assert.That(_testRunDebugLogs[0], Does.Contain("System.Exception")); }
public void Output_Intrinsics_ThreadId() { const string ThreadIDKey = "ThreadID"; var testThreadIDValue = _random.Next(0, int.MaxValue); // Arrange var testEnricher = new TestEnricher(); var threadIdEnricher = new TestEnricher() .WithUserPropValue(ThreadIDKey, testThreadIDValue); var formatter = new NewRelicFormatter() .WithPropertyMapping(ThreadIDKey, NewRelicLoggingProperty.ThreadId); var testOutputSink = new TestSinkWithFormatter(formatter); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher, threadIdEnricher); // Act testLogger.Warning(LogMessage); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); //additional 1 for threadid AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties + 1, resultDic); Assert.That(resultDic, Contains.Key("thread.id")); Assert.That(testOutputSink.InputsAndOutputs[0].LogEvent.Properties[ThreadIDKey].ToString(), Is.EqualTo(resultDic["thread.id"].GetString())); }
public void IsHandled_NullValue_InNewRelicDictionary() { // Arrange var testNRProperties = new Dictionary <string, string>() { { StringATestKey, StringTestValue }, { NullTestKey, null } }; var testEnricher = new TestEnricher() .WithUserPropValue(IntegerTestKey, IntegerTestValue) .WithNewRelicMetadataValue(testNRProperties); var testOutputSink = new TestSinkWithFormatter(new NewRelicFormatter()); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act testLogger.Warning(LogMessage); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties, resultDic); Asserts.KeyAndValueMatch(resultDic, UserPropertyKeyPrefix + IntegerTestKey, IntegerTestValue); Assert.That(resultDic, Does.Not.ContainKey(UserPropertyKeyPrefix + LinkingMetadataKey)); Asserts.KeyAndValueMatch(resultDic, StringATestKey, StringTestValue); Asserts.KeyAndValueMatch(resultDic, NullTestKey, JsonValueKind.Null); }
public void Output_ExceptionProperties_NoMessage() { // Arrange var testEnricher = new TestEnricher(); var testOutputSink = new TestSinkWithFormatter(new NewRelicFormatter()); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); var testException = new Exception(string.Empty); // Act try { TestHelpers.CreateStackTracedError(0, testException, 3); } catch (Exception ex) { testLogger.Error(ex, LogMessage); } // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties + 2, resultDic); Assert.That(resultDic, Does.Not.ContainKey("error.message")); Asserts.KeyAndValueMatch(resultDic, "error.class", testException.GetType().FullName); Asserts.KeyAndValueMatch(resultDic, "error.stack", testException.StackTrace); }
public void Mapping_NonReservedProperty_MapsProperly() { var testNRProperties = new Dictionary <string, string>() { { StringATestKey, "TestValue1" }, { StringBTestKey, "TestValue2" } }; var testEnricher = new TestEnricher() .WithNewRelicMetadataValue(testNRProperties); // Build test data and configure formatter var expectedOutputs = new Dictionary <string, string>(); var inputValues = new Dictionary <string, int>(); var testFormatter = new NewRelicFormatter(); foreach (var prop in _newRelicPropertiesNotReserved) { var propName = Guid.NewGuid().ToString(); var propValue = _random.Next(int.MaxValue); inputValues.Add(propName, propValue); expectedOutputs.Add(LoggingExtensions.GetOutputName(prop), propValue.ToString()); testEnricher.WithUserPropValue(propName, propValue); testFormatter.WithPropertyMapping(propName, prop); } var testOutputSink = new TestSinkWithFormatter(testFormatter); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act testLogger.Warning(LogMessage); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); foreach (var expectedOutput in expectedOutputs) { Asserts.KeyAndValueMatch(resultDic, expectedOutput.Key, expectedOutput.Value); } foreach (var inputVal in inputValues) { Assert.That(resultDic, Does.Not.ContainKey(inputVal.Key)); Assert.That(resultDic, Does.Not.ContainKey(UserPropertyKeyPrefix + inputVal.Key)); } }
public void GetLinkingMetadata_IsHandled_NotAttachedAgent() { // Arrange var testEnricher = new NewRelicEnricher(); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); // Act testLogger.Warning(WarningLogMessage); // Assert Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(1)); Assert.That(_outputSink.LogEvents[0].MessageTemplate.Text, Is.EqualTo(WarningLogMessage)); Assert.That(_outputSink.LogEvents[0].Properties, Does.Not.ContainKey(LinkingMetadataKey), "The agent was running and instrumented the test process."); Assert.That(_testRunDebugLogs.Count, Is.EqualTo(0)); }
public void GetLinkingMetadata_IsHandled_NullAgent() { // Arrange var testEnricher = new NewRelicEnricher(() => null); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); // Act testLogger.Warning(WarningLogMessage); // Assert Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(1)); Assert.That(_outputSink.LogEvents[0].MessageTemplate.Text, Is.EqualTo(WarningLogMessage)); Assert.That(_outputSink.LogEvents[0].Properties, Does.Not.ContainKey(LinkingMetadataKey)); Assert.That(_testRunDebugLogs.Count, Is.EqualTo(0)); }
public void Output_Intrinsics_LogLevel(LogEventLevel level) { // Arrange var testEnricher = new TestEnricher(); var testOutputSink = new TestSinkWithFormatter(new NewRelicFormatter()); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act testLogger.Write(level, LogMessage); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties, resultDic); Assert.That(resultDic, Contains.Key("log.level")); Assert.That(testOutputSink.InputsAndOutputs[0].LogEvent.Level.ToString(), Is.EqualTo(resultDic["log.level"].GetString())); }
public void Output_Intrinsics_Timestamp_AsUnixTimestamp() { // Arrange var testEnricher = new TestEnricher(); var testOutputSink = new TestSinkWithFormatter(new NewRelicFormatter()); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act testLogger.Warning(LogMessage); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties, resultDic); Assert.That(resultDic, Contains.Key("timestamp")); Assert.That(testOutputSink.InputsAndOutputs[0].LogEvent.Timestamp.ToUnixTimeMilliseconds(), Is.EqualTo(resultDic["timestamp"].GetInt64())); }
public void Output_Intrinsics_MessageAndTemplate() { // Arrange var testEnricher = new TestEnricher(); var testOutputSink = new TestSinkWithFormatter(new NewRelicFormatter()); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act const string template = "We have {value1}, {value2}, and {value3}."; testLogger.Warning(template, 1, "two", false); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, template); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties + 3, resultDic); Asserts.KeyAndValueMatch(resultDic, "message", "We have 1, \"two\", and False."); }
public void GetLinkingMetadata_IsHandled_EmptyDictionaryResult() { // Arrange var wasRun = false; Mock.Arrange(() => _testAgent.GetLinkingMetadata()) .DoInstead(() => { wasRun = true; }) .Returns(new Dictionary <string, string>()); var testEnricher = new NewRelicEnricher(() => _testAgent); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); // Act testLogger.Warning(WarningLogMessage); // Assert Assert.That(wasRun, Is.True); Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(1)); Assert.That(_outputSink.LogEvents[0].MessageTemplate.Text, Is.EqualTo(WarningLogMessage)); Assert.That(_outputSink.LogEvents[0].Properties, Does.Not.ContainKey(LinkingMetadataKey)); Assert.That(_testRunDebugLogs.Count, Is.EqualTo(0)); }
public void Output_UserProperties() { // Arrange var testEnricher = new TestEnricher() .WithUserPropValue(IntegerTestKey, IntegerTestValue) .WithUserPropValue(BooleanTestKey, BooleanTestValue) .WithUserPropValue(NullTestKey, NullTestValue) .WithUserPropValue(StringATestKey, StringTestValue) .WithUserPropValue(DictionaryTestKey, new Dictionary <string, object>() { { "DKeyA", "DValueA" }, { "DKeyB", 42 } }) .WithNewRelicMetadataValue(new Dictionary <string, string>()); var testOutputSink = new TestSinkWithFormatter(new NewRelicFormatter()); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act testLogger.Warning(LogMessage); // Assert AssertNoSerilogErrorsAndCountOutputs(_testRunDebugLogs, testOutputSink.InputsAndOutputs, LogMessage); var resultDic = SerilogTestHelpers.DeserializeOutputJSON(testOutputSink.InputsAndOutputs[0]); AssertThatPropertyCountsMatch(testEnricher, CountIntrinsicProperties, resultDic); Asserts.KeyAndValueMatch(resultDic, UserPropertyKeyPrefix + IntegerTestKey, IntegerTestValue); Asserts.KeyAndValueMatch(resultDic, UserPropertyKeyPrefix + BooleanTestKey, BooleanTestValue); Asserts.KeyAndValueMatch(resultDic, UserPropertyKeyPrefix + NullTestKey, JsonValueKind.Null); Asserts.KeyAndValueMatch(resultDic, UserPropertyKeyPrefix + StringATestKey, StringTestValue); Assert.That(resultDic, Contains.Key(UserPropertyKeyPrefix + DictionaryTestKey)); Assert.That(resultDic[UserPropertyKeyPrefix + DictionaryTestKey].ValueKind, Is.EqualTo(JsonValueKind.Object)); var innerDic = JsonSerializer.Deserialize <Dictionary <string, JsonElement> >(resultDic[UserPropertyKeyPrefix + DictionaryTestKey].ToString()); Assert.That(innerDic, Contains.Key("DKeyA")); Assert.That(innerDic["DKeyA"].GetString(), Is.EqualTo("DValueA")); Assert.That(innerDic, Contains.Key("DKeyB")); Assert.That(innerDic["DKeyB"].GetUInt32(), Is.EqualTo(42)); Assert.That(resultDic, Does.Not.ContainKey(UserPropertyKeyPrefix + LinkingMetadataKey)); }
public void IsHandled_Exception() { // Arrange // Setup formatter to fail part-way through emitting the JSON string. // Want to verify that a partial JSON string is not written out. var testEnricher = new TestEnricher() .WithUserPropValue("StartTestKey", "This is the start") .WithUserPropValue("ErrorTestKey", TestErrMsg) .WithUserPropValue("EndTestKey", "This is the end"); var testFormatter = new TestFormatterThatThrowException(); var testOutputSink = new TestSinkWithFormatter(testFormatter); var testLogger = SerilogTestHelpers.GetLogger(testOutputSink, testEnricher); // Act testLogger.Warning(LogMessage); // Assert Assert.That(_testRunDebugLogs.Count, Is.EqualTo(1)); Assert.That(testOutputSink.InputsAndOutputs.Count, Is.EqualTo(1)); Assert.That(testOutputSink.InputsAndOutputs[0].LogEvent.MessageTemplate.Text, Is.EqualTo(LogMessage)); Assert.That(testOutputSink.InputsAndOutputs[0].FormattedOutput, Is.Null); }
public void GetLinkingMetadata_CalledOnceForEachEvent() { // Arrange const string warningCountLogMessageExpected = "This is warning #"; const string warningCountLogMessage = "This is warning #{Count}"; var testEnricher = new NewRelicEnricher(() => _testAgent); var testLogger = SerilogTestHelpers.GetLogger(_outputSink, testEnricher); var rnd = new Random(); var countLogAttempts = rnd.Next(2, 25); var expectedMessages = new List <string>(); // Act for (var i = 0; i < countLogAttempts; i++) { expectedMessages.Add(warningCountLogMessageExpected + i.ToString()); testLogger.Warning(warningCountLogMessage, i); } // Assert Assert.That(_testRunDebugLogs.Count, Is.EqualTo(0)); Mock.Assert(() => _testAgent.GetLinkingMetadata(), Occurs.Exactly(countLogAttempts)); Assert.That(_outputSink.LogEvents.Count, Is.EqualTo(countLogAttempts)); Assert.That(_outputSink.LogEvents[0].Properties, Does.Not.ContainKey(LinkingMetadataKey)); //The actual messages are what we expected. for (var i = 0; i < _outputSink.LogEvents.Count; i++) { var expectedMessage = expectedMessages[i]; var sw = new StringWriter(); var logEvent = _outputSink.LogEvents[i]; logEvent.RenderMessage(sw); var actualMessage = sw.ToString(); Assert.That(actualMessage, Is.EqualTo(expectedMessage)); } }