Commit 66419bc0 authored by Wouter Klouwen's avatar Wouter Klouwen Committed by Brad King
Browse files

CTest: convert timeouts to std::chrono::duration

This commit continues the refactoring of CTest to adopt std::chrono.
After the last sets of changes that introduced std::chrono::steady_clock
and std::chrono::system_clock respectively, it makes sense to have all
the timeouts be stored as std::chrono::duration.

No functional change intended.
parent 923b8fad
......@@ -337,7 +337,7 @@ int cmCTestBuildAndTestHandler::RunCMakeAndTest(std::string* outstring)
}
int runTestRes = this->CTest->RunTest(testCommand, &outs, &retval, nullptr,
remainingTime.count(), nullptr);
remainingTime, nullptr);
if (runTestRes != cmsysProcess_State_Exited || retval != 0) {
out << "Test command failed: " << testCommand[0] << "\n";
......
......@@ -282,7 +282,7 @@ int cmCTestBuildHandler::ProcessHandler()
this->Quiet);
// do we have time for this
if (this->CTest->GetRemainingTimeAllowed() < 120) {
if (this->CTest->GetRemainingTimeAllowed() < std::chrono::minutes(2)) {
return 0;
}
......
......@@ -62,8 +62,9 @@ int cmCTestConfigureHandler::ProcessHandler()
cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
"Configure with command: " << cCommand << std::endl,
this->Quiet);
res = this->CTest->RunMakeCommand(cCommand.c_str(), output, &retVal,
buildDirectory.c_str(), 0, ofs);
res = this->CTest->RunMakeCommand(
cCommand.c_str(), output, &retVal, buildDirectory.c_str(),
std::chrono::duration<double>::zero(), ofs);
if (ofs) {
ofs.close();
......
......@@ -11,6 +11,7 @@
#include "cmParseGTMCoverage.h"
#include "cmParseJacocoCoverage.h"
#include "cmParsePHPCoverage.h"
#include "cmProcess.h"
#include "cmSystemTools.h"
#include "cmWorkingDirectory.h"
#include "cmXMLWriter.h"
......@@ -40,7 +41,7 @@ public:
{
this->Process = cmsysProcess_New();
this->PipeState = -1;
this->TimeOut = -1;
this->TimeOut = std::chrono::duration<double>(-1);
}
~cmCTestRunProcess()
{
......@@ -64,7 +65,7 @@ public:
}
}
void SetWorkingDirectory(const char* dir) { this->WorkingDirectory = dir; }
void SetTimeout(double t) { this->TimeOut = t; }
void SetTimeout(std::chrono::duration<double> t) { this->TimeOut = t; }
bool StartProcess()
{
std::vector<const char*> args;
......@@ -79,7 +80,7 @@ public:
}
cmsysProcess_SetOption(this->Process, cmsysProcess_Option_HideWindow, 1);
if (this->TimeOut != -1) {
if (this->TimeOut >= std::chrono::duration<double>::zero()) {
cmsysProcess_SetTimeout(this->Process, this->TimeOut);
}
cmsysProcess_Execute(this->Process);
......@@ -108,7 +109,7 @@ private:
cmsysProcess* Process;
std::vector<std::string> CommandLineStrings;
std::string WorkingDirectory;
double TimeOut;
std::chrono::duration<double> TimeOut;
};
cmCTestCoverageHandler::cmCTestCoverageHandler()
......@@ -276,7 +277,7 @@ int cmCTestCoverageHandler::ProcessHandler()
this->CTest->ClearSubmitFiles(cmCTest::PartCoverage);
int error = 0;
// do we have time for this
if (this->CTest->GetRemainingTimeAllowed() < 120) {
if (this->CTest->GetRemainingTimeAllowed() < std::chrono::minutes(2)) {
return error;
}
......@@ -1022,8 +1023,9 @@ int cmCTestCoverageHandler::HandleGCovCoverage(
int retVal = 0;
*cont->OFS << "* Run coverage for: " << fileDir << std::endl;
*cont->OFS << " Command: " << command << std::endl;
int res = this->CTest->RunCommand(covargs, &output, &errors, &retVal,
tempDir.c_str(), 0 /*this->TimeOut*/);
int res = this->CTest->RunCommand(
covargs, &output, &errors, &retVal, tempDir.c_str(),
std::chrono::duration<double>::zero() /*this->TimeOut*/);
*cont->OFS << " Output: " << output << std::endl;
*cont->OFS << " Errors: " << errors << std::endl;
......@@ -1386,8 +1388,9 @@ int cmCTestCoverageHandler::HandleLCovCoverage(
int retVal = 0;
*cont->OFS << "* Run coverage for: " << fileDir << std::endl;
*cont->OFS << " Command: " << command << std::endl;
int res = this->CTest->RunCommand(covargs, &output, &errors, &retVal,
fileDir.c_str(), 0 /*this->TimeOut*/);
int res = this->CTest->RunCommand(
covargs, &output, &errors, &retVal, fileDir.c_str(),
std::chrono::duration<double>::zero() /*this->TimeOut*/);
*cont->OFS << " Output: " << output << std::endl;
*cont->OFS << " Errors: " << errors << std::endl;
......
/* Distributed under the OSI-approved BSD 3-Clause License. See accompanying
file Copyright.txt or https://cmake.org/licensing for details. */
#ifdef _WIN32
/* windows.h defines min() and max() macros that interfere. */
#define NOMINMAX
#endif
#include "cmCTestRunTest.h"
#include "cmCTest.h"
......@@ -14,6 +18,7 @@
#include "cmsys/Base64.h"
#include "cmsys/Process.h"
#include "cmsys/RegularExpression.hxx"
#include <algorithm>
#include <chrono>
#include <iomanip>
#include <sstream>
......@@ -26,7 +31,7 @@ cmCTestRunTest::cmCTestRunTest(cmCTestTestHandler* handler)
this->CTest = handler->CTest;
this->TestHandler = handler;
this->TestProcess = nullptr;
this->TestResult.ExecutionTime = 0;
this->TestResult.ExecutionTime = std::chrono::duration<double>::zero();
this->TestResult.ReturnValue = 0;
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
this->TestResult.TestCount = 0;
......@@ -52,7 +57,7 @@ bool cmCTestRunTest::CheckOutput()
std::string line;
while ((timeout = timeEnd - std::chrono::steady_clock::now(),
timeout > std::chrono::seconds(0))) {
int p = this->TestProcess->GetNextOutputLine(line, timeout.count());
int p = this->TestProcess->GetNextOutputLine(line, timeout);
if (p == cmsysProcess_Pipe_None) {
// Process has terminated and all output read.
return false;
......@@ -71,7 +76,9 @@ bool cmCTestRunTest::CheckOutput()
cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->GetIndex()
<< ": "
<< "Test timeout changed to "
<< this->TestProperties->AlternateTimeout
<< std::chrono::duration_cast<std::chrono::seconds>(
this->TestProperties->AlternateTimeout)
.count()
<< std::endl);
this->TestProcess->ResetStartTime();
this->TestProcess->ChangeTimeout(
......@@ -259,7 +266,11 @@ bool cmCTestRunTest::EndTest(size_t completed, size_t total, bool started)
passed = this->TestResult.Status == cmCTestTestHandler::COMPLETED;
char buf[1024];
sprintf(buf, "%6.2f sec", this->TestProcess->GetTotalTime());
sprintf(buf, "%6.2f sec",
double(std::chrono::duration_cast<std::chrono::milliseconds>(
this->TestProcess->GetTotalTime())
.count()) /
1000.0);
cmCTestLog(this->CTest, HANDLER_OUTPUT, buf << "\n");
if (outputTestErrorsToConsole) {
......@@ -295,12 +306,16 @@ bool cmCTestRunTest::EndTest(size_t completed, size_t total, bool started)
reasonType = "Test Fail Reason";
pass = false;
}
double ttime = this->TestProcess->GetTotalTime();
int hours = static_cast<int>(ttime / (60 * 60));
int minutes = static_cast<int>(ttime / 60) % 60;
int seconds = static_cast<int>(ttime) % 60;
auto ttime = this->TestProcess->GetTotalTime();
auto hours = std::chrono::duration_cast<std::chrono::hours>(ttime);
ttime -= hours;
auto minutes = std::chrono::duration_cast<std::chrono::minutes>(ttime);
ttime -= minutes;
auto seconds = std::chrono::duration_cast<std::chrono::seconds>(ttime);
char buffer[100];
sprintf(buffer, "%02d:%02d:%02d", hours, minutes, seconds);
sprintf(buffer, "%02d:%02d:%02d", static_cast<unsigned>(hours.count()),
static_cast<unsigned>(minutes.count()),
static_cast<unsigned>(seconds.count()));
*this->TestHandler->LogFile
<< "----------------------------------------------------------"
<< std::endl;
......@@ -380,7 +395,11 @@ void cmCTestRunTest::ComputeWeightedCost()
{
double prev = static_cast<double>(this->TestProperties->PreviousRuns);
double avgcost = static_cast<double>(this->TestProperties->Cost);
double current = this->TestResult.ExecutionTime;
double current =
double(std::chrono::duration_cast<std::chrono::milliseconds>(
this->TestResult.ExecutionTime)
.count()) /
1000.0;
if (this->TestResult.Status == cmCTestTestHandler::COMPLETED) {
this->TestProperties->Cost =
......@@ -418,7 +437,7 @@ bool cmCTestRunTest::StartTest(size_t total)
// Return immediately if test is disabled
if (this->TestProperties->Disabled) {
this->TestResult.Properties = this->TestProperties;
this->TestResult.ExecutionTime = 0;
this->TestResult.ExecutionTime = std::chrono::duration<double>::zero();
this->TestResult.CompressOutput = false;
this->TestResult.ReturnValue = -1;
this->TestResult.CompletionStatus = "Disabled";
......@@ -435,7 +454,7 @@ bool cmCTestRunTest::StartTest(size_t total)
this->ComputeArguments();
std::vector<std::string>& args = this->TestProperties->Args;
this->TestResult.Properties = this->TestProperties;
this->TestResult.ExecutionTime = 0;
this->TestResult.ExecutionTime = std::chrono::duration<double>::zero();
this->TestResult.CompressOutput = false;
this->TestResult.ReturnValue = -1;
this->TestResult.CompletionStatus = "Failed to start";
......@@ -512,7 +531,7 @@ bool cmCTestRunTest::StartTest(size_t total)
}
this->StartTime = this->CTest->CurrentTime();
double timeout = this->ResolveTimeout();
auto timeout = this->ResolveTimeout();
if (this->StopTimePassed) {
return false;
......@@ -593,9 +612,9 @@ void cmCTestRunTest::DartProcessing()
}
}
double cmCTestRunTest::ResolveTimeout()
std::chrono::duration<double> cmCTestRunTest::ResolveTimeout()
{
double timeout = this->TestProperties->Timeout;
auto timeout = this->TestProperties->Timeout;
if (this->CTest->GetStopTime().empty()) {
return timeout;
......@@ -625,31 +644,37 @@ double cmCTestRunTest::ResolveTimeout()
lctime->tm_mon + 1, lctime->tm_mday,
this->CTest->GetStopTime().c_str(), tzone_offset);
time_t stop_time = curl_getdate(buf, &current_time);
if (stop_time == -1) {
time_t stop_time_t = curl_getdate(buf, &current_time);
if (stop_time_t == -1) {
return timeout;
}
auto stop_time = std::chrono::system_clock::from_time_t(stop_time_t);
// the stop time refers to the next day
if (this->CTest->NextDayStopTime) {
stop_time += 24 * 60 * 60;
stop_time += std::chrono::hours(24);
}
int stop_timeout =
static_cast<int>(stop_time - current_time) % (24 * 60 * 60);
auto stop_timeout =
(stop_time - std::chrono::system_clock::from_time_t(current_time)) %
std::chrono::hours(24);
this->CTest->LastStopTimeout = stop_timeout;
if (stop_timeout <= 0 || stop_timeout > this->CTest->LastStopTimeout) {
if (stop_timeout <= std::chrono::duration<double>::zero() ||
stop_timeout > this->CTest->LastStopTimeout) {
cmCTestLog(this->CTest, ERROR_MESSAGE, "The stop time has been passed. "
"Stopping all tests."
<< std::endl);
this->StopTimePassed = true;
return 0;
return std::chrono::duration<double>::zero();
}
return timeout == 0 ? stop_timeout
: (timeout < stop_timeout ? timeout : stop_timeout);
return timeout == std::chrono::duration<double>::zero()
? stop_timeout
: (timeout < stop_timeout ? timeout : stop_timeout);
}
bool cmCTestRunTest::ForkProcess(double testTimeOut, bool explicitTimeout,
bool cmCTestRunTest::ForkProcess(std::chrono::duration<double> testTimeOut,
bool explicitTimeout,
std::vector<std::string>* environment)
{
this->TestProcess = new cmProcess;
......@@ -660,26 +685,37 @@ bool cmCTestRunTest::ForkProcess(double testTimeOut, bool explicitTimeout,
this->TestProcess->SetCommandArguments(this->Arguments);
// determine how much time we have
double timeout = this->CTest->GetRemainingTimeAllowed() - 120;
if (this->CTest->GetTimeOut() > 0 && this->CTest->GetTimeOut() < timeout) {
std::chrono::duration<double> timeout =
std::min<std::chrono::duration<double>>(
this->CTest->GetRemainingTimeAllowed(), std::chrono::minutes(2));
if (this->CTest->GetTimeOut() > std::chrono::duration<double>::zero() &&
this->CTest->GetTimeOut() < timeout) {
timeout = this->CTest->GetTimeOut();
}
if (testTimeOut > 0 &&
if (testTimeOut > std::chrono::duration<double>::zero() &&
testTimeOut < this->CTest->GetRemainingTimeAllowed()) {
timeout = testTimeOut;
}
// always have at least 1 second if we got to here
if (timeout <= 0) {
timeout = 1;
if (timeout <= std::chrono::duration<double>::zero()) {
timeout = std::chrono::seconds(1);
}
// handle timeout explicitly set to 0
if (testTimeOut == 0 && explicitTimeout) {
timeout = 0;
}
cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->Index
<< ": "
<< "Test timeout computed to be: " << timeout << "\n",
this->TestHandler->GetQuiet());
if (testTimeOut == std::chrono::duration<double>::zero() &&
explicitTimeout) {
timeout = std::chrono::duration<double>::zero();
}
cmCTestOptionalLog(
this->CTest, HANDLER_VERBOSE_OUTPUT, this->Index
<< ": "
<< "Test timeout computed to be: "
<< (timeout == std::chrono::duration<double>::max()
? std::string("infinite")
: std::to_string(
std::chrono::duration_cast<std::chrono::seconds>(timeout)
.count()))
<< "\n",
this->TestHandler->GetQuiet());
this->TestProcess->SetTimeout(timeout);
......
......@@ -5,6 +5,7 @@
#include "cmConfigure.h" // IWYU pragma: keep
#include <chrono>
#include <set>
#include <stddef.h>
#include <string>
......@@ -78,8 +79,9 @@ private:
void DartProcessing();
void ExeNotFound(std::string exe);
// Figures out a final timeout which is min(STOP_TIME, NOW+TIMEOUT)
double ResolveTimeout();
bool ForkProcess(double testTimeOut, bool explicitTimeout,
std::chrono::duration<double> ResolveTimeout();
bool ForkProcess(std::chrono::duration<double> testTimeOut,
bool explicitTimeout,
std::vector<std::string>* environment);
void WriteLogOutputTop(size_t completed, size_t total);
// Run post processing of the process output for MemCheck
......
/* Distributed under the OSI-approved BSD 3-Clause License. See accompanying
file Copyright.txt or https://cmake.org/licensing for details. */
#ifdef _WIN32
/* windows.h defines min() and max() macros, unless told to otherwise. This
* interferes with std::min() and std::max() at the very least. */
#define NOMINMAX
#endif
#include "cmCTestScriptHandler.h"
#include "cmsys/Directory.hxx"
......@@ -960,21 +967,21 @@ bool cmCTestScriptHandler::TryToRemoveBinaryDirectoryOnce(
return cmSystemTools::RemoveADirectory(directoryPath);
}
double cmCTestScriptHandler::GetRemainingTimeAllowed()
std::chrono::duration<double> cmCTestScriptHandler::GetRemainingTimeAllowed()
{
if (!this->Makefile) {
return 1.0e7;
return std::chrono::duration<double>::max();
}
const char* timelimitS = this->Makefile->GetDefinition("CTEST_TIME_LIMIT");
if (!timelimitS) {
return 1.0e7;
return std::chrono::duration<double>::max();
}
auto timelimit = std::chrono::duration<double>(atof(timelimitS));
auto duration = std::chrono::duration_cast<std::chrono::duration<double>>(
std::chrono::steady_clock::now() - this->ScriptStartTime);
return (timelimit - duration).count();
return (timelimit - duration);
}
......@@ -94,9 +94,9 @@ public:
/**
* Return the time remaianing that the script is allowed to run in
* seconds if the user has set the variable CTEST_TIME_LIMIT. If that has
* not been set it returns 1e7 seconds
* not been set it returns a very large value.
*/
double GetRemainingTimeAllowed();
std::chrono::duration<double> GetRemainingTimeAllowed();
cmCTestScriptHandler();
~cmCTestScriptHandler() override;
......
......@@ -7,6 +7,7 @@
#include "cmMakefile.h"
#include "cmSystemTools.h"
#include <chrono>
#include <sstream>
#include <stdlib.h>
#include <vector>
......@@ -36,14 +37,14 @@ cmCTestGenericHandler* cmCTestTestCommand::InitializeHandler()
const char* ctestTimeout =
this->Makefile->GetDefinition("CTEST_TEST_TIMEOUT");
double timeout;
std::chrono::duration<double> timeout;
if (ctestTimeout) {
timeout = atof(ctestTimeout);
timeout = std::chrono::duration<double>(atof(ctestTimeout));
} else {
timeout = this->CTest->GetTimeOut();
if (timeout <= 0) {
if (timeout <= std::chrono::duration<double>::zero()) {
// By default use timeout of 10 minutes
timeout = 600;
timeout = std::chrono::minutes(10);
}
}
this->CTest->SetTimeOut(timeout);
......
......@@ -653,7 +653,11 @@ void cmCTestTestHandler::PrintLabelOrSubprojectSummary(bool doSubProject)
for (std::string const& l : p.Labels) {
// only use labels found in labels
if (labels.find(l) != labels.end()) {
labelTimes[l] += result.ExecutionTime * result.Properties->Processors;
labelTimes[l] +=
double(std::chrono::duration_cast<std::chrono::milliseconds>(
result.ExecutionTime)
.count()) /
1000.0 * result.Properties->Processors;
++labelCounts[l];
}
}
......@@ -1239,7 +1243,9 @@ void cmCTestTestHandler::ProcessDirectory(std::vector<std::string>& passed,
p.Cost = static_cast<float>(rand());
}
if (p.Timeout == 0 && this->CTest->GetGlobalTimeout() != 0) {
if (p.Timeout == std::chrono::duration<double>::zero() &&
this->CTest->GetGlobalTimeout() !=
std::chrono::duration<double>::zero()) {
p.Timeout = this->CTest->GetGlobalTimeout();
}
......@@ -1321,7 +1327,11 @@ void cmCTestTestHandler::GenerateDartOutput(cmXMLWriter& xml)
xml.StartElement("NamedMeasurement");
xml.Attribute("type", "numeric/double");
xml.Attribute("name", "Execution Time");
xml.Element("Value", result.ExecutionTime);
xml.Element("Value",
double(std::chrono::duration_cast<std::chrono::milliseconds>(
result.ExecutionTime)
.count()) /
1000.0);
xml.EndElement(); // NamedMeasurement
if (!result.Reason.empty()) {
const char* reasonType = "Pass Reason";
......@@ -2142,7 +2152,7 @@ bool cmCTestTestHandler::SetTestsProperties(
rt.FixturesRequired.insert(lval.begin(), lval.end());
}
if (key == "TIMEOUT") {
rt.Timeout = atof(val.c_str());
rt.Timeout = std::chrono::duration<double>(atof(val.c_str()));
rt.ExplicitTimeout = true;
}
if (key == "COST") {
......@@ -2222,7 +2232,8 @@ bool cmCTestTestHandler::SetTestsProperties(
"TIMEOUT_AFTER_MATCH expects two arguments, found "
<< propArgs.size() << std::endl);
} else {
rt.AlternateTimeout = atof(propArgs[0].c_str());
rt.AlternateTimeout =
std::chrono::duration<double>(atof(propArgs[0].c_str()));
std::vector<std::string> lval;
cmSystemTools::ExpandListArgument(propArgs[1], lval);
for (std::string const& cr : lval) {
......@@ -2340,7 +2351,7 @@ bool cmCTestTestHandler::AddTest(const std::vector<std::string>& args)
test.WillFail = false;
test.Disabled = false;
test.RunSerial = false;
test.Timeout = 0;
test.Timeout = std::chrono::duration<double>::zero();
test.ExplicitTimeout = false;
test.Cost = 0;
test.Processors = 1;
......
......@@ -124,9 +124,9 @@ public:
float Cost;
int PreviousRuns;
bool RunSerial;
double Timeout;
std::chrono::duration<double> Timeout;
bool ExplicitTimeout;
double AlternateTimeout;
std::chrono::duration<double> AlternateTimeout;
int Index;
// Requested number of process slots
int Processors;
......@@ -147,7 +147,7 @@ public:
std::string Path;
std::string Reason;
std::string FullCommandLine;
double ExecutionTime;
std::chrono::duration<double> ExecutionTime;
int ReturnValue;
int Status;
std::string ExceptionStatus;
......
......@@ -5,11 +5,21 @@
#include "cmProcessOutput.h"
#include <iostream>
void cmsysProcess_SetTimeout(cmsysProcess* process,
std::chrono::duration<double> timeout)
{
cmsysProcess_SetTimeout(
process,
double(
std::chrono::duration_cast<std::chrono::milliseconds>(timeout).count()) /
1000.0);
};
cmProcess::cmProcess()
{
this->Process = nullptr;
this->Timeout = 0;
this->TotalTime = 0;
this->Timeout = std::chrono::duration<double>::zero();
this->TotalTime = std::chrono::duration<double>::zero();
this->ExitValue = 0;
this->Id = 0;
this->StartTime = std::chrono::steady_clock::time_point();
......@@ -100,10 +110,15 @@ bool cmProcess::Buffer::GetLast(std::string& line)
return false;
}
int cmProcess::GetNextOutputLine(std::string& line, double timeout)
int cmProcess::GetNextOutputLine(std::string& line,
std::chrono::duration<double> timeout)
{
cmProcessOutput processOutput(cmProcessOutput::UTF8);
std::string strdata;
double waitTimeout =
double(
std::chrono::duration_cast<std::chrono::milliseconds>(timeout).count()) /
1000.0;
for (;;) {
// Look for lines already buffered.
if (this->Output.GetLine(line)) {
......@@ -113,7 +128,8 @@ int cmProcess::GetNextOutputLine(std::string& line, double timeout)
// Check for more data from the process.
char* data;
int length;
int p = cmsysProcess_WaitForData(this->Process, &data, &length, &timeout);
int p =
cmsysProcess_WaitForData(this->Process, &data, &length, &waitTimeout);
if (p == cmsysProcess_Pipe_Timeout) {
return cmsysProcess_Pipe_Timeout;
}
......@@ -136,23 +152,19 @@ int cmProcess::GetNextOutputLine(std::string& line, double timeout)
}
// No more data. Wait for process exit.
if (!cmsysProcess_WaitForExit(this->Process, &timeout)) {
if (!cmsysProcess_WaitForExit(this->Process, &waitTimeout)) {
return cmsysProcess_Pipe_Timeout;
}
// Record exit information.
this->ExitValue = cmsysProcess_GetExitValue(this->Process);
this->TotalTime =
static_cast<double>(std::chrono::duration_cast<std::chrono::milliseconds>(
std::chrono::steady_clock::now() - this->StartTime)
.count()) /
1000.0;
this->TotalTime = std::chrono::steady_clock::now() - this->StartTime;
// Because of a processor clock scew the runtime may become slightly
// negative. If someone changed the system clock while the process was
// running this may be even more. Make sure not to report a negative
// duration here.
if (this->TotalTime <= 0.0) {