Skip to content

Commit

Permalink
Some improvements to RF (#56659)
Browse files Browse the repository at this point in the history 
+ added a maximumWaitTime config default to 10 mins
+ actually breaks into the debugger when it times out when debugBreakOnTestHang is specified
+ prints out the progress while we wait so it's obvious if it's hung or just because some
  tests are taking a long time. example output -

[7/30/2021 6:52:26 PM 1] ============current number of tests running   14, allocated 50,040,808,336 so far, 879,122,336 since last; (GC 439:420:420), waited 55s
[7/30/2021 6:52:26 PM 1] Still running: DirectedGraph.dll
[7/30/2021 6:52:26 PM 1] Still running: LargeObjectAlloc.dll
[7/30/2021 6:52:26 PM 1] Still running: LargeObjectAlloc1.dll
[7/30/2021 6:52:29 PM 1] Still running: LargeObjectAlloc2.dll
  • Loading branch information
@Maoni0
Maoni0 authored Aug 17, 2021
1 parent 616ace3 commit a53ec50
Show file tree
Hide file tree
Showing 3 changed files with 62 additions and 21 deletions.
3 changes: 3 additions & 0 deletions src/tests/GC/Stress/Framework/ReliabilityConfiguration.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -404,6 +404,9 @@ private void GetTestsToRun(string testConfig)
_curTestSet.MaximumTime = ConvertTimeValueToTestRunTime(timeValue);
}

break;
case "maximumWaitTime":
_curTestSet.MaximumWaitTime = ConvertTimeValueToTestRunTime(currentXML.Value);
break;
case "id":
_curTestSet.FriendlyName = currentXML.Value;
Expand Down
64 changes: 43 additions & 21 deletions src/tests/GC/Stress/Framework/ReliabilityFramework.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -630,7 +630,6 @@ public int RunReliabilityTests(string testConfig, bool doReplay)
return (99);
}

#if !PROJECTK_BUILD
[DllImport("kernel32.dll")]
private extern static void DebugBreak();

Expand All @@ -639,7 +638,6 @@ public int RunReliabilityTests(string testConfig, bool doReplay)

[DllImport("kernel32.dll")]
private extern static void OutputDebugString(string debugStr);
#endif

/// <summary>
/// Checks to see if we should block all execution due to a fatal error
Expand All @@ -661,20 +659,11 @@ private static void NoExitPoll()
}
internal static void MyDebugBreak(string extraData)
{
#if !PROJECTK_BUILD
if (IsDebuggerPresent())
{
OutputDebugString(String.Format("\r\n\r\n\r\nRELIABILITYFRAMEWORK DEBUGBREAK: Breaking in because test throw an exception ({0})\r\n\r\n\r\n", extraData));
Console.WriteLine(string.Format("DebugBreak: {0}", extraData));
DebugBreak();
}
else
#else
if (Debugger.IsAttached)
{
Console.WriteLine(string.Format("DebugBreak: breaking in because test threw an exception: {0}", extraData));
Debugger.Break();
}
#endif
{
// We need to stop the process now,
// but all the threads are still running
Expand Down Expand Up @@ -1081,25 +1070,46 @@ private void TestSetShutdown(int totalTestsToRun)
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
Console.WriteLine(msg);

int secondsIter = 5;
int waitCnt = 0;
while (_testsRunningCount > 0 && waitCnt < 7200) // wait a max of 2 hours for the tests to exit...
{
Thread.Sleep(1000);
Console.Write("\b\b\b\b{0,4}", _testsRunningCount);
int waitCntTotal = _curTestSet.MaximumWaitTime * 60 / secondsIter;
msg = String.Format("START WAITING for {0}s", _curTestSet.MaximumWaitTime * 60);
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
long lastAllocatedBytes = GC.GetTotalAllocatedBytes(false);
while (_testsRunningCount > 0 && waitCnt < waitCntTotal)
{
Thread.Sleep(secondsIter * 1000);
long currentAllocatedBytes = GC.GetTotalAllocatedBytes(false);
msg = String.Format("============current number of tests running {0,4}, allocated {1:n0} so far, {2:n0} since last; (GC {3}:{4}:{5}), waited {6}s",
_testsRunningCount, currentAllocatedBytes, (currentAllocatedBytes - lastAllocatedBytes),
GC.CollectionCount(0),
GC.CollectionCount(1),
GC.CollectionCount(2),
(waitCnt * secondsIter));
lastAllocatedBytes = currentAllocatedBytes;
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);

for (int i = 0; i < _curTestSet.Tests.Length; i++)
{
if (_curTestSet.Tests[i].RunningCount != 0)
{
msg = String.Format("Still running: {0}", _curTestSet.Tests[i].RefOrID);
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
}
}
waitCnt++;
}
}

// let the user know what tests haven't finished...
if (_testsRunningCount != 0)
{
string msg;

_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, "************Timeout reached************");
for (int i = 0; i < _curTestSet.Tests.Length; i++)
{
if (_curTestSet.Tests[i].RunningCount != 0)
{
msg = String.Format("Still running: {0}", _curTestSet.Tests[i].RefOrID);
string msg = String.Format("Still running: {0}", _curTestSet.Tests[i].RefOrID);
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
Console.WriteLine(msg);
AddFailure("Test Hang", _curTestSet.Tests[i], -1);
Expand All @@ -1116,6 +1126,9 @@ private void TestSetShutdown(int totalTestsToRun)
[MethodImpl(MethodImplOptions.NoInlining)]
private void TestIsHungDebugBreak()
{
string msg = String.Format("break");
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);

MyDebugBreak("TestHang");
}

Expand Down Expand Up @@ -1165,7 +1178,8 @@ private void StartTest(ReliabilityTest test)

Interlocked.Increment(ref _testsRunningCount);
test.TestStarted();
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.TestStarter, String.Format("RF.StartTest, RTs({0}) - Instances of this test: {1} - New Test:{2}", _testsRunningCount, test.RunningCount, test.RefOrID));
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.TestStarter, String.Format("RF.StartTest, RTs({0}) - Instances of this test: {1} - New Test:{2}, {3} threads",
_testsRunningCount, test.RunningCount, test.RefOrID, Process.GetCurrentProcess().Threads.Count));

newThread.Start(test);
}
Expand Down Expand Up @@ -1207,7 +1221,11 @@ private void StartTestWorker(object test)
#if PROJECTK_BUILD
Task.Factory.StartNew(() =>
{
Console.WriteLine("==============================running test: {0}==============================", daTest.Assembly);
string msg = String.Format("==============================[tid: {0, 4}, running test: {1} STATUS: START, {2} tests running {3} threads ==============================",
Thread.CurrentThread.ManagedThreadId, daTest.Assembly, _testsRunningCount,
Process.GetCurrentProcess().Threads.Count);
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
try
{
daTest.EntryPointMethod.Invoke(null, new object[] { (daTest.Arguments == null) ? new string[0] : daTest.GetSplitArguments() });
Expand All @@ -1220,6 +1238,10 @@ private void StartTestWorker(object test)
Console.WriteLine(e);
}
msg = String.Format("==============================[tid: {0, 4}, running test: {1} STATUS: DONE, {2} tests running {3} threads ==============================",
Thread.CurrentThread.ManagedThreadId, daTest.Assembly, _testsRunningCount,
Process.GetCurrentProcess().Threads.Count);
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
Interlocked.Increment(ref _testsRanCount);
SignalTestFinished(daTest);
});
Expand Down
16 changes: 16 additions & 0 deletions src/tests/GC/Stress/Framework/ReliabilityTestSet.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ public class ReliabilityTestSet
{
private int _maximumTestLoops = 0; // default run based on time.
private int _maximumExecutionTime = 60; // 60 minute run by default.
private int _maximumWaitTime = 10; // 10 minute wait by default.
private int _percentPassIsPass = System.Environment.GetEnvironmentVariable("PERCENTPASSISPASS") == null ? -1 : Convert.ToInt32(System.Environment.GetEnvironmentVariable("PERCENTPASSISPASS"));
private int[] _minPercentCPUStaggered_times = null;
private int[] _minPercentCPUStaggered_usage = null;
Expand Down Expand Up @@ -94,6 +95,21 @@ public int MaximumTime
}
}

/// <summary>
/// Maximum wait time, in minutes.
/// </summary>
public int MaximumWaitTime
{
get
{
return (_maximumWaitTime);
}
set
{
_maximumWaitTime = value;
}
}

public string FriendlyName
{
get
Expand Down

0 comments on commit a53ec50

Please sign in to comment.