From 8a7e38e38bb5f5dc39aa697e7b8eb8675c42e397 Mon Sep 17 00:00:00 2001
From: Mitchell Hwang <16830051+mdh1418@users.noreply.github.com>
Date: Wed, 17 Jul 2024 10:08:07 -0400
Subject: [PATCH] [tests] Add more logging to pinpoint hang (#104982)

---
 src/tests/Loader/binding/tracing/BinderEventListener.cs | 1 +
 src/tests/Loader/binding/tracing/BinderTracingTest.cs   | 4 ++++
 src/tests/Loader/binding/tracing/Helpers.cs             | 2 ++
 3 files changed, 7 insertions(+)

diff --git a/src/tests/Loader/binding/tracing/BinderEventListener.cs b/src/tests/Loader/binding/tracing/BinderEventListener.cs
index 771fbe49830c5..3db42b4b5a57a 100644
--- a/src/tests/Loader/binding/tracing/BinderEventListener.cs
+++ b/src/tests/Loader/binding/tracing/BinderEventListener.cs
@@ -190,6 +190,7 @@ public BindOperation[] WaitAndGetEventsForAssembly(AssemblyName assemblyName)
                     }
                 }
 
+                Console.WriteLine($"Waiting for bind events for {assemblyName.Name} ({timeWaitedInMs}ms waited) Sleeping for {waitIntervalInMs}ms");
                 Thread.Sleep(waitIntervalInMs);
                 timeWaitedInMs += waitIntervalInMs;
 
diff --git a/src/tests/Loader/binding/tracing/BinderTracingTest.cs b/src/tests/Loader/binding/tracing/BinderTracingTest.cs
index 2f246ee8eeb07..6a2bf8de2a0f5 100644
--- a/src/tests/Loader/binding/tracing/BinderTracingTest.cs
+++ b/src/tests/Loader/binding/tracing/BinderTracingTest.cs
@@ -172,6 +172,7 @@ private static bool RunSingleTest(MethodInfo method)
                 Func<BindOperation> func = (Func<BindOperation>)method.CreateDelegate(typeof(Func<BindOperation>));
                 using (var listener = new BinderEventListener(loadsToTrack))
                 {
+                    Console.WriteLine($"[{DateTime.Now:T}] Invoking {method.Name}...");
                     BindOperation expected = func();
                     ValidateSingleBind(listener, expected.AssemblyName, expected);
                 }
@@ -182,6 +183,7 @@ private static bool RunSingleTest(MethodInfo method)
                 return false;
             }
 
+            Console.WriteLine($"Test {method.Name} finished.");
             return true;
         }
 
@@ -197,6 +199,7 @@ private static bool RunTestInSeparateProcess(MethodInfo method)
             Console.WriteLine($"[{DateTime.Now:T}] Launching process for {method.Name}...");
             using (Process p = Process.Start(startInfo))
             {
+                Console.WriteLine($"Started subprocess {p.Id} for {method.Name}...");
                 p.OutputDataReceived += (_, args) => Console.WriteLine(args.Data);
                 p.BeginOutputReadLine();
 
@@ -210,6 +213,7 @@ private static bool RunTestInSeparateProcess(MethodInfo method)
 
         private static void ValidateSingleBind(BinderEventListener listener, AssemblyName assemblyName, BindOperation expected)
         {
+            Console.WriteLine($"[{DateTime.Now:T}] Validating bind operation for {assemblyName}...");
             BindOperation[] binds = listener.WaitAndGetEventsForAssembly(assemblyName);
             Assert.True(binds.Length == 1, $"Bind event count for {assemblyName} - expected: 1, actual: {binds.Length}");
             BindOperation actual = binds[0];
diff --git a/src/tests/Loader/binding/tracing/Helpers.cs b/src/tests/Loader/binding/tracing/Helpers.cs
index aee1dc1891960..6545104cb8715 100644
--- a/src/tests/Loader/binding/tracing/Helpers.cs
+++ b/src/tests/Loader/binding/tracing/Helpers.cs
@@ -17,6 +17,7 @@ internal class Helpers
     {
         public static void ValidateBindOperation(BindOperation expected, BindOperation actual)
         {
+            Console.WriteLine("ValidateBindOperation Started");
             ValidateAssemblyName(expected.AssemblyName, actual.AssemblyName, nameof(BindOperation.AssemblyName));
             Assert.Equal(expected.AssemblyPath ?? string.Empty, actual.AssemblyPath);
             Assert.Equal(expected.AssemblyLoadContext, actual.AssemblyLoadContext);
@@ -37,6 +38,7 @@ public static void ValidateBindOperation(BindOperation expected, BindOperation a
             ValidateProbedPaths(expected.ProbedPaths, actual.ProbedPaths);
 
             ValidateNestedBinds(expected.NestedBinds, actual.NestedBinds);
+            Console.WriteLine("ValidateBindOperation Finished");
         }
 
         public static string GetAssemblyInAppPath(string assemblyName)