public void Check()
{
using (var unitOfWork = _unitOfWorkFactory.GetUnitOfWork(true))
{
var repository = unitOfWork.SubmitResultRepository;
var submit = repository.DequeueUnchecked();
if (submit == null)
{
return;
}
using (NestedDiagnosticsLogicalContext.Push($"Submit-{submit.Id}"))
{
this.logger.Info($"Dequeued submit");
var result = _service.Check(submit);
submit.PassedTests = result.TestsPassedCount;
submit.TotalBytes = result.PeakMemoryBytes;
submit.TotalMilliseconds = result.TimeConsumedMilliseconds;
submit.Status = result.GetStatus();
submit.CompileOutput = result.CompileResult.Output;
submit.RunDescription = result.Description;
submit.RunOutput = result.Output;
unitOfWork.Commit();
}
}
}
public void NDLCDeepTest()
{
LogManager.Configuration = CreateConfigurationFromString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${ndlc:topframes=1} ${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
NestedDiagnosticsLogicalContext.Clear();
for (int i = 1; i <= 100; ++i)
{
NestedDiagnosticsLogicalContext.Push(i);
}
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", "100 0");
NestedDiagnosticsLogicalContext.PopObject();
LogManager.GetLogger("A").Debug("1");
AssertDebugLastMessage("debug", "99 1");
NestedDiagnosticsLogicalContext.Clear();
LogManager.GetLogger("A").Debug("2");
AssertDebugLastMessage("debug", " 2");
}
public static IDisposable CreateDiagnosticLogicalContext <T>(T state)
{
try
{
#if NETSTANDARD
return(NestedDiagnosticsLogicalContext.Push(state)); // AsyncLocal has no requirement to be Serializable
#else
// TODO Add support for Net46 in NLog (AsyncLocal), then we only have to do this check for legacy Net451 (CallContext)
if (state?.GetType().IsSerializable ?? true)
{
return(NestedDiagnosticsLogicalContext.Push(state));
}
else
{
return
(NestedDiagnosticsLogicalContext
.Push(state
.ToString())); // Support HostingLogScope, ActionLogScope, FormattedLogValues and others
}
#endif
}
catch (Exception ex)
{
InternalLogger.Debug(ex, "Exception in BeginScope push NestedDiagnosticsLogicalContext");
return(null);
}
}
public void NestedDiagnosticContextInformation_is_stored_in_the_same_sort_order_as_used_by_the_nested_diagnostic_layout_renderer()
{
var ndcSeparator = "::";
var ndlcSeparator = " ";
ConfigureLogManager(ndcSeparator, ndlcSeparator);
// Act
NestedDiagnosticsContext.Clear();
NestedDiagnosticsLogicalContext.Push("foo");
NestedDiagnosticsLogicalContext.Push("bar");
NestedDiagnosticsLogicalContext.Clear();
NestedDiagnosticsContext.Push("baz1");
NestedDiagnosticsContext.Push("baz2");
NestedDiagnosticsContext.Push("baz3");
var logEvent = Log("A", LogLevel.Debug, null, null, "some message");
// Assert
var expected = GetExpectedNdcValue(logEvent, ndcSeparator, ndlcSeparator);
var actual = GetXmlDocument().GetElementsByTagName("log4j:NDC")[0].InnerText;
Assert.Equal(expected, actual);
}
/// <summary>
/// Begin a scope. Use in config with ${ndlc}
/// </summary>
/// <param name="state">The state (message)</param>
/// <returns></returns>
public IDisposable BeginScope <TState>(TState state)
{
if (state == null)
{
throw new ArgumentNullException(nameof(state));
}
if (_options.CaptureMessageProperties)
{
if (state is IEnumerable <KeyValuePair <string, object> > messageProperties)
{
ScopeProperties scope = new ScopeProperties();
foreach (var property in messageProperties)
{
if (string.IsNullOrEmpty(property.Key))
{
continue;
}
scope.AddProperty(property.Key, property.Value);
}
scope.AddDispose(NestedDiagnosticsLogicalContext.Push(state));
return(scope);
}
}
return(NestedDiagnosticsLogicalContext.Push(state));
}
public IDisposable ParseBeginScope <T>(T state)
{
if (_options.CaptureMessageProperties)
{
if (state is IList <KeyValuePair <string, object> > scopePropertyList)
{
return(ScopeProperties.CaptureScopeProperties(scopePropertyList));
}
if (!(state is string))
{
if (state is System.Collections.IEnumerable scopePropertyCollection)
{
return(ScopeProperties.CaptureScopeProperties(scopePropertyCollection, _scopeStateExtractors));
}
else
{
return(ScopeProperties.CaptureScopeProperty(state, _scopeStateExtractors));
}
}
else
{
return(NestedDiagnosticsLogicalContext.Push(state));
}
}
return(CreateDiagnosticLogicalContext(state));
}
static void Main(string[] args)
{
Logger logger = LogManager.GetLogger("RmqTarget");
var logEventInfo = new LogEventInfo(LogLevel.Debug, "RmqLogMessage", $"This is a test message, generated at {DateTime.UtcNow}.");
logEventInfo.Properties["fieldA"] = "Field A";
logEventInfo.Properties["fieldB"] = "Field B";
logEventInfo.Properties["fields"] = new List <KeyValuePair <string, object> >
{
new KeyValuePair <string, object>("FieldC", "Field c")
};
// Provide global application properties
GlobalDiagnosticsContext.Set("globalFieldA", "Global Field A");
GlobalDiagnosticsContext.Set("globalFieldB", "Global Field B");
// Provide context properties for the current thread
NestedDiagnosticsLogicalContext.Push("Nested Field C");
// Provide scope detail for the current thread
MappedDiagnosticsLogicalContext.Set("mappedFieldA", "Mapped Field A");
MappedDiagnosticsLogicalContext.Set("mappedFieldB", "Mapped Field B");
logger.Log(logEventInfo);
LogManager.Shutdown();
}
public IDisposable BeginScope <TState>(TState state)
{
if (state == null)
{
throw new ArgumentNullException(nameof(state));
}
return(NestedDiagnosticsLogicalContext.Push(state));
}
private static IDisposable CreateScopeProperties(object scopeObject, IReadOnlyList <KeyValuePair <string, object> > propertyList)
{
if (propertyList?.Count > 0)
{
return(new ScopeProperties(NestedDiagnosticsLogicalContext.Push(scopeObject), MappedDiagnosticsLogicalContext.SetScoped(propertyList)));
}
return(NestedDiagnosticsLogicalContext.Push(scopeObject));
}
public void MediumTrustWithExternalClass()
{
var fileWritePath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString());
try
{
int times = 25;
{
// ClassUnderTest must extend MarshalByRefObject
AppDomain partialTrusted;
var classUnderTest = MediumTrustContext.Create <ClassUnderTest>(fileWritePath, out partialTrusted);
#if NET4_0 || NET4_5
using (NestedDiagnosticsLogicalContext.Push("PartialTrust"))
#endif
{
classUnderTest.PartialTrustSuccess(times, fileWritePath);
}
AppDomain.Unload(partialTrusted);
}
// this also checks that thread-volatile layouts
// such as ${threadid} are properly cached and not recalculated
// in logging threads.
var threadID = Thread.CurrentThread.ManagedThreadId.ToString();
Assert.False(File.Exists(Path.Combine(fileWritePath, "Trace.txt")));
AssertFileContents(Path.Combine(fileWritePath, "Debug.txt"),
StringRepeat(times, "aaa " + threadID + "\n"), Encoding.UTF8);
AssertFileContents(Path.Combine(fileWritePath, "Info.txt"),
StringRepeat(times, "bbb " + threadID + "\n"), Encoding.UTF8);
AssertFileContents(Path.Combine(fileWritePath, "Warn.txt"),
StringRepeat(times, "ccc " + threadID + "\n"), Encoding.UTF8);
AssertFileContents(Path.Combine(fileWritePath, "Error.txt"),
StringRepeat(times, "ddd " + threadID + "\n"), Encoding.UTF8);
AssertFileContents(Path.Combine(fileWritePath, "Fatal.txt"),
StringRepeat(times, "eee " + threadID + "\n"), Encoding.UTF8);
}
finally
{
if (Directory.Exists(fileWritePath))
{
Directory.Delete(fileWritePath, true);
}
// Clean up configuration change, breaks onetimeonlyexceptioninhandlertest
LogManager.ThrowExceptions = true;
}
}
public static IDisposable CreateDiagnosticLogicalContext <T>(T state)
{
try
{
return(NestedDiagnosticsLogicalContext.Push(state)); // AsyncLocal has no requirement to be Serializable
}
catch (Exception ex)
{
InternalLogger.Debug(ex, "Exception in BeginScope push NestedDiagnosticsLogicalContext");
return(null);
}
}
public void TargetWithContextNdlcSerializeTest()
{
NestedDiagnosticsLogicalContext.Clear();
NestedDiagnosticsLogicalContext.Push(new { a = "b" });
CustomTargetWithContext target = new CustomTargetWithContext()
{
IncludeNdlc = true, SkipAssert = true
};
WriteAndAssertSingleKey(target);
}
/// <summary>
/// Begin a scope. Use in config with ${ndlc}
/// </summary>
/// <param name="state">The state (message)</param>
/// <returns></returns>
public IDisposable BeginScope <TState>(TState state)
{
if (state == null)
{
throw new ArgumentNullException(nameof(state));
}
if (_options.CaptureMessageProperties && state is IEnumerable <KeyValuePair <string, object> > messageProperties)
{
return(ScopeProperties.CreateFromState(state, messageProperties));
}
return(NestedDiagnosticsLogicalContext.Push(state));
}
private static void RunAppDomainTestMethod(string fileWritePath, int times, bool autoShutdown)
{
// ClassUnderTest must extend MarshalByRefObject
AppDomain partialTrusted;
var classUnderTest = MediumTrustContext.Create <ClassUnderTest>(fileWritePath, out partialTrusted);
#if NET4_0 || NET4_5
MappedDiagnosticsLogicalContext.Set("Winner", new { Hero = "Zero" });
using (NestedDiagnosticsLogicalContext.Push(new { Hello = "World" }))
#endif
{
classUnderTest.PartialTrustSuccess(times, fileWritePath, autoShutdown);
}
AppDomain.Unload(partialTrusted);
}
public static IDisposable CaptureScopeProperty <TState>(TState scopeProperty, ExtractorDictionary stateExractor)
{
if (!TryLookupExtractor(stateExractor, scopeProperty.GetType(), out var keyValueExtractor))
{
return(NestedDiagnosticsLogicalContext.Push(scopeProperty));
}
var propertyValue = TryParseKeyValueProperty(keyValueExtractor, scopeProperty);
if (!propertyValue.HasValue)
{
return(NestedDiagnosticsLogicalContext.Push(scopeProperty));
}
return(new ScopeProperties(NestedDiagnosticsLogicalContext.Push(scopeProperty), MappedDiagnosticsLogicalContext.SetScoped(propertyValue.Value.Key, propertyValue.Value.Value)));
}
public void NDLCTop1TestTest()
{
LogManager.Configuration = CreateConfigurationFromString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${ndlc:topframes=1} ${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
NestedDiagnosticsLogicalContext.Clear();
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", " 0");
using (NestedDiagnosticsLogicalContext.Push("ala"))
{
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
using (NestedDiagnosticsLogicalContext.Push("ma"))
{
LogManager.GetLogger("A").Debug("b");
AssertDebugLastMessage("debug", "ma b");
using (NestedDiagnosticsLogicalContext.Push("kota"))
{
LogManager.GetLogger("A").Debug("c");
AssertDebugLastMessage("debug", "kota c");
NestedDiagnosticsLogicalContext.Push("kopytko");
LogManager.GetLogger("A").Debug("d");
AssertDebugLastMessage("debug", "kopytko d");
Assert.Equal("kopytko", NestedDiagnosticsLogicalContext.PopObject()); // manual pop
LogManager.GetLogger("A").Debug("c");
AssertDebugLastMessage("debug", "kota c");
}
LogManager.GetLogger("A").Debug("b");
AssertDebugLastMessage("debug", "ma b");
}
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
}
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", " 0");
Assert.Equal(string.Empty, NestedDiagnosticsLogicalContext.Pop());
NestedDiagnosticsLogicalContext.Push("zzz");
NestedDiagnosticsLogicalContext.Push("yyy");
Assert.Equal("yyy", NestedDiagnosticsLogicalContext.Pop());
NestedDiagnosticsLogicalContext.Clear();
Assert.Equal(string.Empty, NestedDiagnosticsLogicalContext.Pop());
}
public void NDLCTop1TestTest()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${ndlc:topframes=1} ${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
NestedDiagnosticsLogicalContext.Clear();
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", " 0");
using (NestedDiagnosticsLogicalContext.Push("ala"))
{
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
using (NestedDiagnosticsLogicalContext.Push("ma"))
{
LogManager.GetLogger("A").Debug("b");
AssertDebugLastMessage("debug", "ma b");
using (NestedDiagnosticsLogicalContext.Push("kota"))
{
LogManager.GetLogger("A").Debug("c");
AssertDebugLastMessage("debug", "kota c");
NestedDiagnosticsLogicalContext.Push("kopytko");
LogManager.GetLogger("A").Debug("d");
AssertDebugLastMessage("debug", "kopytko d");
Assert.Equal("kopytko", NestedDiagnosticsLogicalContext.PopObject()); // manual pop
LogManager.GetLogger("A").Debug("c");
AssertDebugLastMessage("debug", "kota c");
}
LogManager.GetLogger("A").Debug("b");
AssertDebugLastMessage("debug", "ma b");
}
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
}
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", " 0");
Assert.Null(NestedDiagnosticsLogicalContext.Pop()); //inconsistent with NDC - should be string.empty, but for backwardsscomp. Fix in NLog 5
NestedDiagnosticsLogicalContext.Push("zzz");
NestedDiagnosticsLogicalContext.Push("yyy");
Assert.Equal("yyy", NestedDiagnosticsLogicalContext.Pop());
NestedDiagnosticsLogicalContext.Clear();
Assert.Null(NestedDiagnosticsLogicalContext.Pop()); //inconsistent with NDC - should be string.empty, but for backwardsscomp. Fix in NLog 5
}
public static IDisposable CreateFromState <TState>(TState state, IEnumerable <KeyValuePair <string, object> > messageProperties)
{
ScopeProperties scope = new ScopeProperties();
foreach (var property in messageProperties)
{
if (String.IsNullOrEmpty(property.Key))
{
continue;
}
scope.AddProperty(property.Key, property.Value);
}
scope.AddDispose(NestedDiagnosticsLogicalContext.Push(state));
return(scope);
}
public void NdlcGetAllMessages()
{
object value = 5;
NestedDiagnosticsLogicalContext.Clear();
var popper = NestedDiagnosticsLogicalContext.Push(value);
string expected = "5";
string[] actual = NestedDiagnosticsLogicalContext.GetAllMessages();
Assert.Single(actual);
Assert.Equal(expected, actual[0]);
popper.Dispose();
actual = NestedDiagnosticsLogicalContext.GetAllMessages();
Assert.Empty(actual);
}
public void FallbackGroupTargetAsyncTest()
{
using (new NoThrowNLogExceptions())
{
var myTarget1 = new MyTarget {
FailCounter = int.MaxValue
}; // Always failing.
var myTarget1Async = new AsyncTargetWrapper(myTarget1)
{
TimeToSleepBetweenBatches = 0
}; // Always failing.
var myTarget2 = new MyTarget()
{
Layout = "${ndlc}"
};
var wrapper = CreateAndInitializeFallbackGroupTarget(true, myTarget1Async, myTarget2);
var exceptions = new List <Exception>();
// no exceptions
for (var i = 0; i < 10; ++i)
{
using (NestedDiagnosticsLogicalContext.Push("Hello World"))
{
wrapper.WriteAsyncLogEvent(LogEventInfo.CreateNullEvent().WithContinuation(exceptions.Add));
}
}
ManualResetEvent resetEvent = new ManualResetEvent(false);
myTarget1Async.Flush((ex) => { Assert.Null(ex); resetEvent.Set(); });
resetEvent.WaitOne(1000);
Assert.Equal(10, exceptions.Count);
for (var i = 0; i < 10; ++i)
{
Assert.Null(exceptions[i]);
}
Assert.Equal(10, myTarget2.WriteCount);
AssertNoFlushException(wrapper);
}
}
public void NDLCTest()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${ndlc} ${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
NestedDiagnosticsLogicalContext.Clear();
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", " 0");
using (NestedDiagnosticsLogicalContext.Push("ala"))
{
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
using (NestedDiagnosticsLogicalContext.Push("ma"))
{
LogManager.GetLogger("A").Debug("b");
AssertDebugLastMessage("debug", "ala ma b");
using (NestedDiagnosticsLogicalContext.Push("kota"))
{
LogManager.GetLogger("A").Debug("c");
AssertDebugLastMessage("debug", "ala ma kota c");
using (NestedDiagnosticsLogicalContext.Push("kopytko"))
{
LogManager.GetLogger("A").Debug("d");
AssertDebugLastMessage("debug", "ala ma kota kopytko d");
}
LogManager.GetLogger("A").Debug("c");
AssertDebugLastMessage("debug", "ala ma kota c");
}
LogManager.GetLogger("A").Debug("b");
AssertDebugLastMessage("debug", "ala ma b");
}
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
}
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", " 0");
}
public void NDLCAsyncLogging()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${ndlc:separator=\:} ${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
System.Threading.Tasks.Task task;
using (NestedDiagnosticsLogicalContext.Push("ala"))
{
LogManager.GetLogger("A").Debug("a");
AssertDebugLastMessage("debug", "ala a");
task = System.Threading.Tasks.Task.Run(async() => { await System.Threading.Tasks.Task.Delay(50); LogManager.GetLogger("B").Debug("b"); });
}
task.Wait();
AssertDebugLastMessage("debug", "ala b");
}
public Scope(ILogger logger, string scopeName, IDictionary <string, object> properties)
{
if (string.IsNullOrWhiteSpace(scopeName))
{
throw new ArgumentNullException(nameof(scopeName));
}
_logger = logger ?? throw new ArgumentNullException(nameof(logger));
_parentScope = GetParentScope();
ScopeName = scopeName;
ScopeId = Guid.NewGuid();
ScopeIdTrace = GetScopeTrace();
ScopeTrace = GetScopeNameTrace();
_properties = ConstructScopeProperties(properties);
_disposable = NestedDiagnosticsLogicalContext.Push(this);
_logger.Extended(LogLevel.Trace, "Start logical scope", null);
}
public IDisposable ParseBeginScope <T>(T state)
{
if (_options.CaptureMessageProperties)
{
if (state is IReadOnlyList <KeyValuePair <string, object> > scopePropertyList)
{
return(ScopeProperties.CaptureScopeProperties(scopePropertyList, _options.IncludeActivtyIdsWithBeginScope));
}
if (!(state is string))
{
if (state is IEnumerable scopePropertyCollection)
{
return(ScopeProperties.CaptureScopeProperties(scopePropertyCollection, _scopeStateExtractors));
}
return(ScopeProperties.CaptureScopeProperty(state, _scopeStateExtractors));
}
}
return(NestedDiagnosticsLogicalContext.Push(state));
}
public void If_Ndc_And_Ndlc_is_present_they_are_combined_with_a_NdcSeparator()
{
// Arrange
var ndcSeparator = "::";
var ndlcSeparator = " ";
ConfigureLogManager(ndcSeparator, ndlcSeparator);
// Act
NestedDiagnosticsContext.Clear();
NestedDiagnosticsContext.Push("foo");
NestedDiagnosticsLogicalContext.Clear();
NestedDiagnosticsLogicalContext.Push("bar");
var logEvent = Log("A", LogLevel.Debug, null, null, "some message");
// Assert
var expected = GetExpectedNdcValue(logEvent, ndcSeparator, ndlcSeparator);
var actual = GetXmlDocument().GetElementsByTagName("log4j:NDC")[0].InnerText;
Assert.Equal(expected, actual);
}
public void PublishTask(TaskBase task, string createdBy)
{
Logger.Info("{createdBy} publish task {@task}", createdBy, task);
PublishedTask publishedTask = databases.Snittlistan.PublishedTasks.Add(
PublishedTask.CreateImmediate(
task,
currentTenant.TenantId,
correlationId,
causationId,
createdBy));
try
{
HostingEnvironment.QueueBackgroundWorkItem(ct =>
PublishMessage(currentTenant, publishedTask.MessageId, ct));
}
catch (Exception ex)
{
Logger.Error(
ex,
"QueueBackgroundWorkItem failed, using fallback (publish immediately)");
try
{
DoPublishMessage(currentTenant, publishedTask);
}
catch (Exception ex2)
{
Logger.Error(ex2);
}
}
async void PublishMessage(Tenant tenant, Guid messageId, CancellationToken ct)
{
const int MaxTries = 10;
using IDisposable logScope = NestedDiagnosticsLogicalContext.Push("QueueBackgroundWork");
using SnittlistanContext context = new();
try
{
for (int i = 0; i < MaxTries; i++)
{
Logger.Info("try #{try}", i);
PublishedTask?publishedTask =
await context.PublishedTasks.SingleOrDefaultAsync(x => x.MessageId == messageId);
if (publishedTask == null)
{
Logger.Warn("message not found: {messageId}", messageId);
await Task.Delay(300);
}
else
{
DoPublishMessage(tenant, publishedTask);
return;
}
}
throw new Exception($"max tries reached: {MaxTries}");
}
catch (Exception ex)
{
Logger.Error(ex, "failed to publish message");
}
}
void DoPublishMessage(Tenant tenant, PublishedTask publishedTask)
{
using MsmqGateway msmqGateway = msmqFactory.Create();
using MsmqGateway.MsmqTransactionScope scope = msmqGateway.Create();
MessageEnvelope message = new(
publishedTask.Task,
publishedTask.TenantId,
tenant.Hostname,
publishedTask.CorrelationId,
publishedTask.CausationId,
publishedTask.MessageId);
scope.Send(message);
scope.Commit();
Logger.Info("published message {@message}", message);
}
}
public void Log4JXmlTest()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog throwExceptions='true'>
<targets>
<target name='debug' type='Debug' layout='${log4jxmlevent:includeCallSite=true:includeSourceInfo=true:includeNdlc=true:includeMdc=true:IncludeNdc=true:includeMdlc=true:IncludeAllProperties=true:ndcItemSeparator=\:\::includenlogdata=true:loggerName=${logger}}' />
</targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
MappedDiagnosticsContext.Clear();
NestedDiagnosticsContext.Clear();
MappedDiagnosticsContext.Set("foo1", "bar1");
MappedDiagnosticsContext.Set("foo2", "bar2");
MappedDiagnosticsLogicalContext.Clear();
MappedDiagnosticsLogicalContext.Set("foo3", "bar3");
NestedDiagnosticsLogicalContext.Push("boo1");
NestedDiagnosticsLogicalContext.Push("boo2");
NestedDiagnosticsContext.Push("baz1");
NestedDiagnosticsContext.Push("baz2");
NestedDiagnosticsContext.Push("baz3");
ILogger logger = LogManager.GetLogger("A");
var logEventInfo = LogEventInfo.Create(LogLevel.Debug, "A", new Exception("Hello Exception", new Exception("Goodbye Exception")), null, "some message");
logEventInfo.Properties["nlogPropertyKey"] = "nlogPropertyValue";
logger.Log(logEventInfo);
string result = GetDebugLastMessage("debug");
string wrappedResult = "<log4j:dummyRoot xmlns:log4j='http://log4j' xmlns:nlog='http://nlog'>" + result + "</log4j:dummyRoot>";
Assert.NotEqual("", result);
// make sure the XML can be read back and verify some fields
StringReader stringReader = new StringReader(wrappedResult);
var foundsChilds = new Dictionary <string, int>();
var requiredChilds = new List <string>
{
"log4j.event",
"log4j.message",
"log4j.NDC",
"log4j.locationInfo",
"nlog.locationInfo",
"log4j.properties",
"nlog.properties",
"log4j.throwable",
"log4j.data",
"nlog.data",
};
using (XmlReader reader = XmlReader.Create(stringReader))
{
while (reader.Read())
{
var key = reader.LocalName;
var fullKey = reader.Prefix + "." + key;
if (!foundsChilds.ContainsKey(fullKey))
{
foundsChilds[fullKey] = 0;
}
foundsChilds[fullKey]++;
if (reader.NodeType == XmlNodeType.Element && reader.Prefix == "log4j")
{
switch (reader.LocalName)
{
case "dummyRoot":
break;
case "event":
Assert.Equal("DEBUG", reader.GetAttribute("level"));
Assert.Equal("A", reader.GetAttribute("logger"));
var epochStart = new DateTime(1970, 1, 1, 0, 0, 0, DateTimeKind.Utc);
long timestamp = Convert.ToInt64(reader.GetAttribute("timestamp"));
var time = epochStart.AddMilliseconds(timestamp);
var now = DateTime.UtcNow;
Assert.True(now.Ticks - time.Ticks < TimeSpan.FromSeconds(3).Ticks);
Assert.Equal(Thread.CurrentThread.ManagedThreadId.ToString(), reader.GetAttribute("thread"));
break;
case "message":
reader.Read();
Assert.Equal("some message", reader.Value);
break;
case "NDC":
reader.Read();
Assert.Equal("baz1::baz2::baz3::boo1 boo2", reader.Value);
break;
case "locationInfo":
Assert.Equal(MethodBase.GetCurrentMethod().DeclaringType.FullName, reader.GetAttribute("class"));
Assert.Equal(MethodBase.GetCurrentMethod().ToString(), reader.GetAttribute("method"));
break;
case "properties":
break;
case "throwable":
reader.Read();
Assert.Contains("Hello Exception", reader.Value);
Assert.Contains("Goodbye Exception", reader.Value);
break;
case "data":
string name = reader.GetAttribute("name");
string value = reader.GetAttribute("value");
switch (name)
{
case "log4japp":
Assert.Equal(AppDomain.CurrentDomain.FriendlyName + "(" + Process.GetCurrentProcess().Id + ")", value);
break;
case "log4jmachinename":
Assert.Equal(Environment.MachineName, value);
break;
case "foo1":
Assert.Equal("bar1", value);
break;
case "foo2":
Assert.Equal("bar2", value);
break;
case "foo3":
Assert.Equal("bar3", value);
break;
case "nlogPropertyKey":
Assert.Equal("nlogPropertyValue", value);
break;
default:
Assert.True(false, "Unknown <log4j:data>: " + name);
break;
}
break;
default:
throw new NotSupportedException("Unknown element: " + key);
}
continue;
}
if (reader.NodeType == XmlNodeType.Element && reader.Prefix == "nlog")
{
switch (key)
{
case "eventSequenceNumber":
break;
case "locationInfo":
Assert.Equal(GetType().Assembly.FullName, reader.GetAttribute("assembly"));
break;
case "properties":
break;
case "data":
var name = reader.GetAttribute("name");
var value = reader.GetAttribute("value");
Assert.Equal("nlogPropertyKey", name);
Assert.Equal("nlogPropertyValue", value);
break;
default:
throw new NotSupportedException("Unknown element: " + key);
}
}
}
}
foreach (var required in requiredChilds)
{
Assert.True(foundsChilds.ContainsKey(required), $"{required} not found!");
}
}
public void NDLCTimingTest()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${ndlc}|${ndlctiming:CurrentScope=false:ScopeBeginTime=true:Format=yyyy-MM-dd HH\:mm\:ss}|${ndlctiming:CurrentScope=false:ScopeBeginTime=false:Format=fff}|${ndlctiming:CurrentScope=true:ScopeBeginTime=true:Format=HH\:mm\:ss.fff}|${ndlctiming:CurrentScope=true:ScopeBeginTime=false:Format=fffffff}|${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug' />
</rules>
</nlog>");
NestedDiagnosticsLogicalContext.Clear();
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", "|||||0");
using (NestedDiagnosticsLogicalContext.Push("ala"))
{
LogManager.GetLogger("A").Debug("a");
var measurements = GetDebugLastMessage("debug").Split(new[] { '|' }, System.StringSplitOptions.RemoveEmptyEntries);
Assert.Equal(6, measurements.Length);
Assert.Equal("ala", measurements[0]);
Assert.InRange(int.Parse(measurements[2]), 0, 999);
Assert.InRange(int.Parse(measurements[4]), 0, 9999999);
Assert.Equal("a", measurements[measurements.Length - 1]);
System.Threading.Thread.Sleep(10);
LogManager.GetLogger("A").Debug("b");
measurements = GetDebugLastMessage("debug").Split(new[] { '|' }, System.StringSplitOptions.RemoveEmptyEntries);
Assert.Equal("ala", measurements[0]);
Assert.InRange(int.Parse(measurements[2]), 10, 999);
Assert.InRange(int.Parse(measurements[4]), 100000, 9999999);
Assert.Equal("b", measurements[measurements.Length - 1]);
using (NestedDiagnosticsLogicalContext.Push("ma"))
{
LogManager.GetLogger("A").Debug("a");
measurements = GetDebugLastMessage("debug").Split(new[] { '|' }, System.StringSplitOptions.RemoveEmptyEntries);
Assert.Equal(6, measurements.Length);
Assert.Equal("ala ma", measurements[0]);
Assert.InRange(int.Parse(measurements[2]), 10, 999);
Assert.InRange(int.Parse(measurements[4]), 0, 9999999);
Assert.Equal("a", measurements[measurements.Length - 1]);
System.Threading.Thread.Sleep(10);
LogManager.GetLogger("A").Debug("b");
measurements = GetDebugLastMessage("debug").Split(new[] { '|' }, System.StringSplitOptions.RemoveEmptyEntries);
Assert.Equal(6, measurements.Length);
Assert.Equal("ala ma", measurements[0]);
Assert.InRange(int.Parse(measurements[2]), 20, 999);
Assert.InRange(int.Parse(measurements[4]), 100000, 9999999);
Assert.Equal("b", measurements[measurements.Length - 1]);
}
LogManager.GetLogger("A").Debug("c");
measurements = GetDebugLastMessage("debug").Split(new[] { '|' }, System.StringSplitOptions.RemoveEmptyEntries);
Assert.Equal("ala", measurements[0]);
Assert.InRange(int.Parse(measurements[2]), 20, 999);
Assert.InRange(int.Parse(measurements[4]), 200000, 9999999);
Assert.Equal("c", measurements[measurements.Length - 1]);
}
LogManager.GetLogger("A").Debug("0");
AssertDebugLastMessage("debug", "|||||0");
}
public IDisposable BeginScope <TState>(TState state)
{
return(NestedDiagnosticsLogicalContext.Push(state));
}
/// <summary> /// Creates the scope for this log transaction. /// </summary> /// <param name="messageFormat"></param> /// <param name="args"></param> /// <returns></returns> public IDisposable Scope(string messageFormat, params string[] args) => NestedDiagnosticsLogicalContext.Push(FormatMessage(messageFormat, args));