static int Main(string[] args) { try { InMemoryLog4NetLogger.Setup(); var logger = LogManager.GetLogger(typeof(Program)); var ddTraceSettings = TracerSettings.FromDefaultSources(); ddTraceSettings.LogsInjectionEnabled = true; ddTraceSettings.TraceEnabled = true; ddTraceSettings.TracerMetricsEnabled = true; GlobalSettings.SetDebugEnabled(true); Tracer.Configure(ddTraceSettings); var tracer = Tracer.Instance; var totalIterations = 100; var threadRepresentation = Enumerable.Range(0, 25).ToArray(); var threadCount = threadRepresentation.Length; // Two logs per thread iteration + 1 extra log at the end of each thread var expectedLogCount = threadCount; var exceptionBag = new ConcurrentBag <Exception>(); Console.WriteLine($"Running {threadRepresentation.Length} threads with {totalIterations} iterations."); var threads = threadRepresentation .Select( idx => new Thread( thread => { try { var i = 0; while (i++ < totalIterations) { using (var outerScope = tracer.StartActive("outer-span")) { } } Thread.Sleep(100); // Verify everything is cleaned up on this thread logger.Info(ThreadFinishedMessage); } catch (Exception ex) { exceptionBag.Add(ex); } })) .ToList(); foreach (var thread in threads) { thread.Start(); } while (threads.Any(x => x.IsAlive)) { Thread.Sleep(500); } if (exceptionBag.Any()) { // No exceptions are acceptable throw new AggregateException(exceptionBag.ToArray()); } var loggingEvents = InMemoryLog4NetLogger.InMemoryAppender.GetEvents(); var systemOutOfRangeException = loggingEvents.Where(e => e.RenderedMessage.Contains("Index was outside the bounds of the array")); int systemOutOfRangeExceptionCount = systemOutOfRangeException.Count(); Console.WriteLine($"Received {systemOutOfRangeExceptionCount} log events containing 'Index was outside the bounds of the array'."); if (systemOutOfRangeException.Count() > 0) { throw new Exception("Got exception with 'System.IndexOutOfRangeException'"); } Console.WriteLine("Press any key to exit"); Console.ReadKey(); } catch (Exception ex) { Console.Error.WriteLine(ex); return((int)ExitCode.UnknownError); } return((int)ExitCode.Success); }
static int Main(string[] args) { try { InMemoryLog4NetLogger.Setup(); var logger = LogManager.GetLogger(typeof(Program)); var ddTraceSettings = TracerSettings.FromDefaultSources(); ddTraceSettings.LogsInjectionEnabled = true; ddTraceSettings.TraceEnabled = true; Tracer.Configure(ddTraceSettings); var tracer = Tracer.Instance; var totalIterations = 10_000; var threadRepresentation = Enumerable.Range(0, 10).ToArray(); var threadCount = threadRepresentation.Length; // Two logs per thread iteration + 1 extra log at the end of each thread var expectedLogCount = (totalIterations * threadCount * 2) + threadCount; var exceptionBag = new ConcurrentBag <Exception>(); Console.WriteLine($"Running {threadRepresentation.Length} threads with {totalIterations} iterations."); var threads = threadRepresentation .Select( idx => new Thread( thread => { try { Thread.Sleep(2000); var i = 0; while (i++ < totalIterations) { using (var outerScope = tracer.StartActive("thread-test")) { var outerTraceId = outerScope.Span.TraceId; var outerSpanId = outerScope.Span.SpanId; logger.Info($"TraceId: {outerTraceId}, SpanId: {outerSpanId}"); using (var innerScope = tracer.StartActive("nest-thread-test")) { var innerTraceId = innerScope.Span.TraceId; var innerSpanId = innerScope.Span.SpanId; if (outerTraceId != innerTraceId) { throw new Exception($"TraceId mismatch - outer: {outerTraceId}, inner: {innerTraceId}"); } if (outerSpanId == innerSpanId) { throw new Exception($"Unexpected SpanId match - outer: {outerSpanId}, inner: {innerSpanId}"); } logger.Info($"TraceId: {innerTraceId}, SpanId: {innerSpanId}"); } } } // Verify everything is cleaned up on this thread logger.Info(NonTraceMessage); } catch (Exception ex) { exceptionBag.Add(ex); } })) .ToList(); foreach (var thread in threads) { thread.Start(); } while (threads.Any(x => x.IsAlive)) { Thread.Sleep(1000); } if (exceptionBag.Any()) { // No exceptions are acceptable throw new AggregateException(exceptionBag.ToArray()); } var loggingEvents = RelevantLogs(); foreach (var group in loggingEvents.Where(e => e.RenderedMessage != NonTraceMessage).GroupBy(e => e.RenderedMessage)) { var message = group.First().RenderedMessage; if (group.Count() > 1) { Console.WriteLine($"Has duplicate log entries ({group.Count()}): {message}"); } } Console.WriteLine($"Expecting {expectedLogCount} total log events."); Console.WriteLine($"Received {loggingEvents.Length} total log events."); if (loggingEvents.Length != expectedLogCount) { throw new Exception($"Expected {expectedLogCount}, actual log count {loggingEvents.Length}"); } foreach (var loggingEvent in loggingEvents) { var attachedTraceId = loggingEvent.Properties[TraceIdKey]; var attachedSpanIdId = loggingEvent.Properties[SpanIdKey]; var expectedMessage = $"TraceId: {attachedTraceId}, SpanId: {attachedSpanIdId}"; if (expectedMessage.Equals(loggingEvent.RenderedMessage)) { // all is well continue; } throw new Exception($"LOGGING EVENT DOES NOT MATCH ({attachedTraceId}, {attachedSpanIdId}): {loggingEvent.RenderedMessage}"); } Console.WriteLine("Every trace wrapped logging event has the expected TraceId and SpanId."); // Test non-traced logging event logger.Info(NonTraceMessage); var lastLog = RelevantLogs().Last(); var lastLogTraceId = lastLog.Properties[TraceIdKey]; var lastLogSpanIdId = lastLog.Properties[SpanIdKey]; var actual = $"TraceId: {lastLogTraceId}, SpanId: {lastLogSpanIdId}"; if (!actual.Equals(NonTraceMessage)) { throw new Exception($"Unexpected TraceId or SpanId: {actual}"); } Console.WriteLine("Non-trace wrapped logging event has 0 for TraceId and SpanId."); Console.WriteLine("All is well!"); } catch (Exception ex) { Console.Error.WriteLine(ex); return((int)ExitCode.UnknownError); } #if NETCOREAPP2_1 // Add a delay to avoid a race condition on shutdown: https://github.com/dotnet/coreclr/pull/22712 // This would cause a segmentation fault on .net core 2.x System.Threading.Thread.Sleep(5000); #endif return((int)ExitCode.Success); }