Skip to content

Commit a53ec50

Browse files
authored
Some improvements to RF (#56659)
+ 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
1 parent 616ace3 commit a53ec50

File tree

3 files changed

+62
-21
lines changed

3 files changed

+62
-21
lines changed

src/tests/GC/Stress/Framework/ReliabilityConfiguration.cs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -404,6 +404,9 @@ private void GetTestsToRun(string testConfig)
404404
_curTestSet.MaximumTime = ConvertTimeValueToTestRunTime(timeValue);
405405
}
406406

407+
break;
408+
case "maximumWaitTime":
409+
_curTestSet.MaximumWaitTime = ConvertTimeValueToTestRunTime(currentXML.Value);
407410
break;
408411
case "id":
409412
_curTestSet.FriendlyName = currentXML.Value;

src/tests/GC/Stress/Framework/ReliabilityFramework.cs

Lines changed: 43 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -630,7 +630,6 @@ public int RunReliabilityTests(string testConfig, bool doReplay)
630630
return (99);
631631
}
632632

633-
#if !PROJECTK_BUILD
634633
[DllImport("kernel32.dll")]
635634
private extern static void DebugBreak();
636635

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

640639
[DllImport("kernel32.dll")]
641640
private extern static void OutputDebugString(string debugStr);
642-
#endif
643641

644642
/// <summary>
645643
/// Checks to see if we should block all execution due to a fatal error
@@ -661,20 +659,11 @@ private static void NoExitPoll()
661659
}
662660
internal static void MyDebugBreak(string extraData)
663661
{
664-
#if !PROJECTK_BUILD
665662
if (IsDebuggerPresent())
666663
{
667-
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));
664+
Console.WriteLine(string.Format("DebugBreak: {0}", extraData));
668665
DebugBreak();
669666
}
670-
else
671-
#else
672-
if (Debugger.IsAttached)
673-
{
674-
Console.WriteLine(string.Format("DebugBreak: breaking in because test threw an exception: {0}", extraData));
675-
Debugger.Break();
676-
}
677-
#endif
678667
{
679668
// We need to stop the process now,
680669
// but all the threads are still running
@@ -1081,25 +1070,46 @@ private void TestSetShutdown(int totalTestsToRun)
10811070
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
10821071
Console.WriteLine(msg);
10831072

1073+
int secondsIter = 5;
10841074
int waitCnt = 0;
1085-
while (_testsRunningCount > 0 && waitCnt < 7200) // wait a max of 2 hours for the tests to exit...
1086-
{
1087-
Thread.Sleep(1000);
1088-
Console.Write("\b\b\b\b{0,4}", _testsRunningCount);
1075+
int waitCntTotal = _curTestSet.MaximumWaitTime * 60 / secondsIter;
1076+
msg = String.Format("START WAITING for {0}s", _curTestSet.MaximumWaitTime * 60);
1077+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
1078+
long lastAllocatedBytes = GC.GetTotalAllocatedBytes(false);
1079+
while (_testsRunningCount > 0 && waitCnt < waitCntTotal)
1080+
{
1081+
Thread.Sleep(secondsIter * 1000);
1082+
long currentAllocatedBytes = GC.GetTotalAllocatedBytes(false);
1083+
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",
1084+
_testsRunningCount, currentAllocatedBytes, (currentAllocatedBytes - lastAllocatedBytes),
1085+
GC.CollectionCount(0),
1086+
GC.CollectionCount(1),
1087+
GC.CollectionCount(2),
1088+
(waitCnt * secondsIter));
1089+
lastAllocatedBytes = currentAllocatedBytes;
1090+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
1091+
1092+
for (int i = 0; i < _curTestSet.Tests.Length; i++)
1093+
{
1094+
if (_curTestSet.Tests[i].RunningCount != 0)
1095+
{
1096+
msg = String.Format("Still running: {0}", _curTestSet.Tests[i].RefOrID);
1097+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
1098+
}
1099+
}
10891100
waitCnt++;
10901101
}
10911102
}
10921103

10931104
// let the user know what tests haven't finished...
10941105
if (_testsRunningCount != 0)
10951106
{
1096-
string msg;
1097-
1107+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, "************Timeout reached************");
10981108
for (int i = 0; i < _curTestSet.Tests.Length; i++)
10991109
{
11001110
if (_curTestSet.Tests[i].RunningCount != 0)
11011111
{
1102-
msg = String.Format("Still running: {0}", _curTestSet.Tests[i].RefOrID);
1112+
string msg = String.Format("Still running: {0}", _curTestSet.Tests[i].RefOrID);
11031113
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
11041114
Console.WriteLine(msg);
11051115
AddFailure("Test Hang", _curTestSet.Tests[i], -1);
@@ -1116,6 +1126,9 @@ private void TestSetShutdown(int totalTestsToRun)
11161126
[MethodImpl(MethodImplOptions.NoInlining)]
11171127
private void TestIsHungDebugBreak()
11181128
{
1129+
string msg = String.Format("break");
1130+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
1131+
11191132
MyDebugBreak("TestHang");
11201133
}
11211134

@@ -1165,7 +1178,8 @@ private void StartTest(ReliabilityTest test)
11651178

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

11701184
newThread.Start(test);
11711185
}
@@ -1207,7 +1221,11 @@ private void StartTestWorker(object test)
12071221
#if PROJECTK_BUILD
12081222
Task.Factory.StartNew(() =>
12091223
{
1210-
Console.WriteLine("==============================running test: {0}==============================", daTest.Assembly);
1224+
string msg = String.Format("==============================[tid: {0, 4}, running test: {1} STATUS: START, {2} tests running {3} threads ==============================",
1225+
Thread.CurrentThread.ManagedThreadId, daTest.Assembly, _testsRunningCount,
1226+
Process.GetCurrentProcess().Threads.Count);
1227+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
1228+
12111229
try
12121230
{
12131231
daTest.EntryPointMethod.Invoke(null, new object[] { (daTest.Arguments == null) ? new string[0] : daTest.GetSplitArguments() });
@@ -1220,6 +1238,10 @@ private void StartTestWorker(object test)
12201238

12211239
Console.WriteLine(e);
12221240
}
1241+
msg = String.Format("==============================[tid: {0, 4}, running test: {1} STATUS: DONE, {2} tests running {3} threads ==============================",
1242+
Thread.CurrentThread.ManagedThreadId, daTest.Assembly, _testsRunningCount,
1243+
Process.GetCurrentProcess().Threads.Count);
1244+
_logger.WriteToInstrumentationLog(_curTestSet, LoggingLevels.StartupShutdown, msg);
12231245
Interlocked.Increment(ref _testsRanCount);
12241246
SignalTestFinished(daTest);
12251247
});

src/tests/GC/Stress/Framework/ReliabilityTestSet.cs

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ public class ReliabilityTestSet
1414
{
1515
private int _maximumTestLoops = 0; // default run based on time.
1616
private int _maximumExecutionTime = 60; // 60 minute run by default.
17+
private int _maximumWaitTime = 10; // 10 minute wait by default.
1718
private int _percentPassIsPass = System.Environment.GetEnvironmentVariable("PERCENTPASSISPASS") == null ? -1 : Convert.ToInt32(System.Environment.GetEnvironmentVariable("PERCENTPASSISPASS"));
1819
private int[] _minPercentCPUStaggered_times = null;
1920
private int[] _minPercentCPUStaggered_usage = null;
@@ -94,6 +95,21 @@ public int MaximumTime
9495
}
9596
}
9697

98+
/// <summary>
99+
/// Maximum wait time, in minutes.
100+
/// </summary>
101+
public int MaximumWaitTime
102+
{
103+
get
104+
{
105+
return (_maximumWaitTime);
106+
}
107+
set
108+
{
109+
_maximumWaitTime = value;
110+
}
111+
}
112+
97113
public string FriendlyName
98114
{
99115
get

0 commit comments

Comments
 (0)