Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Recover from random hanging unit test script #5719

Merged
merged 2 commits into from
Oct 20, 2023
Merged

Recover from random hanging unit test script #5719

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
b6f47c7
Shorten glacial unit test max time and recover from hanging script error
bmarchant Oct 18, 2023
331f49b
Kill hanging test and retry one time before failing
bmarchant Oct 18, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion conf/core/ConfigOptions.asciidoc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6053,7 +6053,7 @@ potential projections change over time. Very handy in unit tests.
=== test.script.max.exec.time

* Data Type: int
* Default Value: `900`
* Default Value: `600`

For script test debugging only. Sets a maximum allowed time, in seconds, for a script test to run.
If the script runs longer than the specified time, then it is forcefully stopped by the system. If
Expand Down
11 changes: 4 additions & 7 deletions hoot-test/src/main/cpp/hoot/test/ProcessPool.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
* This will properly maintain the copyright information. Maxar
* copyrights will be updated automatically.
*
* @copyright Copyright (C) 2017, 2018, 2019, 2020, 2021 Maxar (http://www.maxar.com/)
* @copyright Copyright (C) 2017-2023 Maxar (http://www.maxar.com/)
*/
#include "ProcessPool.h"

Expand Down Expand Up @@ -68,8 +68,7 @@ void JobQueue::push(const QString& job)

QString JobQueue::toString() const
{
return "Name: " + _name + "; Size: " + QString::number(_jobs.size()) + "; Jobs: " +
hoot::StringUtils::setToString(_jobs);
return QString("Name: %1; Size: %2; Jobs: %3").arg(_name, QString::number(_jobs.size()), hoot::StringUtils::setToString(_jobs));
}

ProcessThread::ProcessThread(int threadId, int maxThreads, bool showTestName, bool suppressFailureDetail, bool printDiff,
Expand Down Expand Up @@ -111,8 +110,7 @@ QProcess* ProcessThread::createProcess()
QString suppressFailureDetail = (_suppressFailureDetail ? "--suppress-failure-detail" : "");
QString diff = (_printDiff ? "--diff" : "");

proc->start(QString("HootTest %1 %2 %3 --listen %4")
.arg(names, suppressFailureDetail, diff).arg((int)_waitTime));
proc->start(QString("HootTest %1 %2 %3 --listen %4").arg(names, suppressFailureDetail, diff).arg((int)_waitTime));
return proc;
}

Expand Down Expand Up @@ -178,8 +176,7 @@ void ProcessThread::processJobs(JobQueue* queue)
if (output != "" && output != "." && !output.endsWith("\n"))
output.append("\n");
}
else if ((line.contains(" ERROR ") || line.contains("Failure: ")) &&
!_disableFailureRetries)
else if ((line.contains(" ERROR ") || line.contains("Failure: ")) && !_disableFailureRetries)
{
++_failures;
line.append("\n");
Expand Down
87 changes: 52 additions & 35 deletions hoot-test/src/main/cpp/hoot/test/ScriptTest.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
* This will properly maintain the copyright information. Maxar
* copyrights will be updated automatically.
*
* @copyright Copyright (C) 2015, 2017, 2018, 2019, 2020, 2021, 2022 Maxar (http://www.maxar.com/)
* @copyright Copyright (C) 2015-2023 Maxar (http://www.maxar.com/)
*/

#include "ScriptTest.h"
Expand All @@ -47,8 +47,8 @@ using namespace std;
namespace hoot
{

QRegularExpression ScriptTest::_regWarn("[0-9:\\.]+ WARN .*\\( *-?[0-9]+\\) ");
QRegularExpression ScriptTest::_regError("[0-9:\\.]+ ERROR .*\\( *-?[0-9]+\\) ");
QRegularExpression ScriptTest::_regWarn("[0-9:\\.]+ WARN .*\\( *-?[0-9]+\\) ", QRegularExpression::OptimizeOnFirstUsageOption);
QRegularExpression ScriptTest::_regError("[0-9:\\.]+ ERROR .*\\( *-?[0-9]+\\) ", QRegularExpression::OptimizeOnFirstUsageOption);


ScriptTest::ScriptTest(const QString& script, bool printDiff, bool suppressFailureDetail, int waitToFinishTime)
Expand All @@ -57,7 +57,8 @@ ScriptTest::ScriptTest(const QString& script, bool printDiff, bool suppressFailu
_suppressFailureDetail(suppressFailureDetail),
_script(script),
_waitToFinishTime(waitToFinishTime),
_scriptTestTimeOutSeconds(ConfigOptions(conf()).getTestScriptMaxExecTime())
_scriptTestTimeOutSeconds(ConfigOptions(conf()).getTestScriptMaxExecTime()),
_retry(0)
{
}

Expand All @@ -84,7 +85,7 @@ QString ScriptTest::_removeIgnoredSubstrings(const QString& input) const
QStringList outLines;
QStringList inLines = input.split("\n");

for (auto line : inLines)
for (auto line : qAsConst(inLines))
{
if (!line.contains(" STATUS ") && !line.contains(" INFO ") &&
!line.contains(" DEBUG ") && !line.contains(" elapsed: ") &&
Expand Down Expand Up @@ -126,15 +127,15 @@ void ScriptTest::runTest()

if (QFile(_script + ".stdout").exists() == false || QFile(_script + ".stderr").exists() == false)
{
LOG_ERROR("STDOUT or STDERR doesn't exist for " + _script +
LOG_ERROR("STDOUT or STDERR doesn't exist for " << _script <<
"\n*************************\n"
" This can be resolved by reviewing the output for correctness and then creating a new baseline.\n"
" Verify the changes in the output are satisfactory: \n"
" less " + _script + ".stdout.first\n"
" less " + _script + ".stderr.first\n"
" less " << _script << ".stdout.first\n"
" less " << _script << ".stderr.first\n"
" Make a new baseline for the output:\n"
" mv " + _script + ".stdout.first " + _script + ".stdout\n"
" mv " + _script + ".stderr.first " + _script + ".stderr\n"
" mv " << _script + ".stdout.first " << _script + ".stdout\n"
" mv " << _script + ".stderr.first " << _script + ".stderr\n"
"*************************");

_baseStderr = "<invalid/>";
Expand Down Expand Up @@ -167,22 +168,22 @@ void ScriptTest::runTest()

if (!_suppressFailureDetail)
{
QString msg = "STDOUT does not match for:\n" + _script + ".stdout" + " " + _script + ".stdout.failed";
QString msg = "STDOUT does not match for:\n" + _script + ".stdout " + _script + ".stdout.failed";
if (_printDiff)
{
LOG_ERROR(msg);
_runDiff(_script + ".stdout.stripped", _script + ".stdout.failed.stripped");
}
else
{
msg += "\n"
"\n*************************\n"
" This can be resolved by reviewing the output for correctness and then creating a new baseline.\n"
" Verify the changes in the output are satisfactory: \n"
" diff " + _script + ".stdout.stripped " + _script + ".stdout.failed.stripped\n"
" Make a new baseline for the output:\n"
" mv " + _script + ".stdout.failed " + _script + ".stdout\n"
"*************************";
LOG_ERROR(msg << "\n"
"\n*************************\n"
" This can be resolved by reviewing the output for correctness and then creating a new baseline.\n"
" Verify the changes in the output are satisfactory: \n"
" diff " << _script << ".stdout.stripped " << _script << ".stdout.failed.stripped\n"
" Make a new baseline for the output:\n"
" mv " << _script << ".stdout.failed " << _script << ".stdout\n"
"*************************");
LOG_ERROR(msg);
}
}
Expand All @@ -206,15 +207,14 @@ void ScriptTest::runTest()
}
else
{
msg += "\n"
"\n*************************\n"
" This can be resolved by reviewing the output for correctness and then creating a new baseline.\n"
" Verify the changes in the output are satisfactory: \n"
" diff " + _script + ".stderr.stripped " + _script + ".stderr.failed.stripped\n"
" Make a new baseline for the output:\n"
" mv " + _script + ".stderr.failed " + _script + ".stderr\n"
"*************************";
LOG_ERROR(msg);
LOG_ERROR(msg << "\n"
"\n*************************\n"
" This can be resolved by reviewing the output for correctness and then creating a new baseline.\n"
" Verify the changes in the output are satisfactory: \n"
" diff " << _script << ".stderr.stripped " << _script << ".stderr.failed.stripped\n"
" Make a new baseline for the output:\n"
" mv " << _script << ".stderr.failed " << _script << ".stderr\n"
"*************************");
}
}
failed = true;
Expand All @@ -227,11 +227,13 @@ void ScriptTest::runTest()
void ScriptTest::_runDiff(const QString& file1, const QString& file2)
{
QProcess p;
p.setProcessChannelMode(QProcess::SeparateChannels);
p.setProcessEnvironment(QProcessEnvironment::systemEnvironment());
p.start("diff", QStringList() << file1 << file2, QProcess::ReadOnly);

while (p.waitForStarted(500) == false)
{
LOG_WARN("Waiting for diff process to start for: " + _script);
LOG_WARN("Waiting for diff process to start for: " << _script);
}

bool scriptTimeOutSpecified = false;
Expand All @@ -250,17 +252,17 @@ void ScriptTest::_runDiff(const QString& file1, const QString& file2)
{
// Throw an endl in there so the dots in the test list don't look funny.
cout << endl;
LOG_WARN("Waiting for diff process to finish for: " + _script);
LOG_WARN("Waiting for diff process to finish for: " << _script);
first = false;
}

// If the process hangs, this will allow us to get out.
const qint64 timeElapsedSeconds = timer.elapsed() / 1000;
if (scriptTimeOutSpecified && timeElapsedSeconds >= _scriptTestTimeOutSeconds)
{
LOG_ERROR(
"Forcefully ending diff command for: " << _script << " after " << timeElapsedSeconds <<
" seconds.");
LOG_ERROR("Forcefully ending diff command for: " << _script << " after " << timeElapsedSeconds << " seconds.");
// Terminate the process
p.terminate();
break;
}
}
Expand All @@ -276,11 +278,13 @@ void ScriptTest::_runProcess()
// It would be nice if we could specify Testing.conf here to avoid having to specify it in every
// test file (#3823).
QProcess p;
p.setProcessChannelMode(QProcess::SeparateChannels);
p.setProcessEnvironment(QProcessEnvironment::systemEnvironment());
p.start(_script, QProcess::ReadOnly);

while (p.waitForStarted(500) == false)
{
LOG_WARN("Waiting for process to start: " + _script);
LOG_WARN("Waiting for process to start: " << _script);
}

bool scriptTimeOutSpecified = false;
Expand All @@ -299,15 +303,28 @@ void ScriptTest::_runProcess()
{
// Throw an endl in there so the dots in the test list don't look funny.
cout << endl;
LOG_WARN("Waiting for process to finish: " + _script);
LOG_WARN("Waiting for process to finish: " << _script);
first = false;
}

// If the process hangs, this will allows us to get out.
const qint64 timeElapsedSeconds = timer.elapsed() / 1000;
if (scriptTimeOutSpecified && timeElapsedSeconds >= _scriptTestTimeOutSeconds)
{
// Retry the process after killing it
if (_retry == 0)
{
++_retry;
p.terminate();
LOG_WARN("Test script (" << _script << ") hanging, restarting.");
p.waitForFinished();
_runProcess();
return;
}
// Terminate the process
p.terminate();
LOG_ERROR("Forcefully ending test script test after " << timeElapsedSeconds << " seconds.");
p.waitForFinished();
break;
}
}
Expand Down
3 changes: 2 additions & 1 deletion hoot-test/src/main/cpp/hoot/test/ScriptTest.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
* This will properly maintain the copyright information. Maxar
* copyrights will be updated automatically.
*
* @copyright Copyright (C) 2015, 2017, 2019, 2021, 2022 Maxar (http://www.maxar.com/)
* @copyright Copyright (C) 2015-2023 Maxar (http://www.maxar.com/)
*/
#ifndef SCRIPTTEST_H
#define SCRIPTTEST_H
Expand Down Expand Up @@ -70,6 +70,7 @@ class ScriptTest : public CppUnit::TestCase
/** Timeout before emitting warning "Waiting for process to finish" in msecs */
int _waitToFinishTime;
int _scriptTestTimeOutSeconds;
int _retry;

static QRegularExpression _regWarn;
static QRegularExpression _regError;
Expand Down
4 changes: 2 additions & 2 deletions hoot-test/src/main/cpp/hoot/test/main.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
* This will properly maintain the copyright information. Maxar
* copyrights will be updated automatically.
*
* @copyright Copyright (C) 2015, 2016, 2017, 2018, 2019, 2020, 2021, 2022 Maxar (http://www.maxar.com/)
* @copyright Copyright (C) 2015-2023 Maxar (http://www.maxar.com/)
*/

// GDAL
Expand Down Expand Up @@ -763,9 +763,9 @@ int main(int argc, char* argv[])

string testName;
cin >> testName;
populateTests(GLACIAL, vAllTests, printDiff, suppressFailureDetail, true);
while (testName != HOOT_TEST_FINISHED)
{
populateTests(GLACIAL, vAllTests, printDiff, suppressFailureDetail, true);
CppUnit::Test* t = findTest(vAllTests, testName);
if (t != 0)
{
Expand Down