[tests] Add more logging to pinpoint hang (#104982)

dotnet · Jul 17, 2024 · 8a7e38e · 8a7e38e
1 parent 8602bb3
commit 8a7e38e
Show file tree

Hide file tree

Showing 3 changed files with 7 additions and 0 deletions.
diff --git 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
@@ -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
@@ -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)