cmake/Source/CTest/cmCTestRunTest.cxx

822 lines
30 KiB
C++
Raw Normal View History

2016-10-30 18:24:19 +01:00
/* Distributed under the OSI-approved BSD 3-Clause License. See accompanying
file Copyright.txt or https://cmake.org/licensing for details. */
2009-10-04 10:30:41 +03:00
#include "cmCTestRunTest.h"
2016-07-09 11:21:54 +02:00
2009-10-04 10:30:41 +03:00
#include "cmCTest.h"
2016-07-09 11:21:54 +02:00
#include "cmCTestMemCheckHandler.h"
2018-04-23 21:13:27 +02:00
#include "cmCTestMultiProcessHandler.h"
2016-10-30 18:24:19 +01:00
#include "cmProcess.h"
2009-10-04 10:30:41 +03:00
#include "cmSystemTools.h"
2017-07-20 19:35:53 +02:00
#include "cmWorkingDirectory.h"
#include "cm_zlib.h"
#include "cmsys/Base64.h"
#include "cmsys/RegularExpression.hxx"
2018-04-23 21:13:27 +02:00
#include <chrono>
#include <cmAlgorithms.h>
2018-08-09 18:06:22 +02:00
#include <cstring>
2016-10-30 18:24:19 +01:00
#include <iomanip>
2018-04-23 21:13:27 +02:00
#include <ratio>
2016-10-30 18:24:19 +01:00
#include <sstream>
#include <stdio.h>
#include <utility>
2010-03-17 14:00:29 +02:00
2018-04-23 21:13:27 +02:00
cmCTestRunTest::cmCTestRunTest(cmCTestMultiProcessHandler& multiHandler)
: MultiTestHandler(multiHandler)
2009-10-04 10:30:41 +03:00
{
2018-04-23 21:13:27 +02:00
this->CTest = multiHandler.CTest;
this->TestHandler = multiHandler.TestHandler;
this->TestResult.ExecutionTime = cmDuration::zero();
2009-10-04 10:30:41 +03:00
this->TestResult.ReturnValue = 0;
2010-03-17 14:00:29 +02:00
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
2009-10-04 10:30:41 +03:00
this->TestResult.TestCount = 0;
2018-01-26 17:06:56 +01:00
this->TestResult.Properties = nullptr;
this->ProcessOutput.clear();
this->CompressedOutput.clear();
2010-03-17 14:00:29 +02:00
this->CompressionRatio = 2;
2015-08-17 11:37:30 +02:00
this->NumberOfRunsLeft = 1; // default to 1 run of the test
this->RunUntilFail = false; // default to run the test once
2016-07-09 11:21:54 +02:00
this->RunAgain = false; // default to not having to run again
2009-10-04 10:30:41 +03:00
}
2018-04-23 21:13:27 +02:00
void cmCTestRunTest::CheckOutput(std::string const& line)
2009-10-04 10:30:41 +03:00
{
2018-08-09 18:06:22 +02:00
cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
this->GetIndex() << ": " << line << std::endl);
2018-04-23 21:13:27 +02:00
this->ProcessOutput += line;
this->ProcessOutput += "\n";
// Check for TIMEOUT_AFTER_MATCH property.
if (!this->TestProperties->TimeoutRegularExpressions.empty()) {
for (auto& reg : this->TestProperties->TimeoutRegularExpressions) {
2018-10-28 12:09:07 +01:00
if (reg.first.find(this->ProcessOutput)) {
2018-08-09 18:06:22 +02:00
cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
this->GetIndex()
2018-04-23 21:13:27 +02:00
<< ": "
<< "Test timeout changed to "
<< std::chrono::duration_cast<std::chrono::seconds>(
this->TestProperties->AlternateTimeout)
.count()
<< std::endl);
this->TestProcess->ResetStartTime();
this->TestProcess->ChangeTimeout(
this->TestProperties->AlternateTimeout);
this->TestProperties->TimeoutRegularExpressions.clear();
break;
2009-10-04 10:30:41 +03:00
}
}
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
}
2010-03-17 14:00:29 +02:00
// Streamed compression of test output. The compressed data
// is appended to this->CompressedOutput
void cmCTestRunTest::CompressOutput()
{
int ret;
z_stream strm;
2016-07-09 11:21:54 +02:00
unsigned char* in = reinterpret_cast<unsigned char*>(
2010-03-17 14:00:29 +02:00
const_cast<char*>(this->ProcessOutput.c_str()));
2016-07-09 11:21:54 +02:00
// zlib makes the guarantee that this is the maximum output size
2010-11-13 01:00:53 +02:00
int outSize = static_cast<int>(
static_cast<double>(this->ProcessOutput.size()) * 1.001 + 13.0);
2010-03-17 14:00:29 +02:00
unsigned char* out = new unsigned char[outSize];
strm.zalloc = Z_NULL;
strm.zfree = Z_NULL;
strm.opaque = Z_NULL;
2016-07-09 11:21:54 +02:00
ret = deflateInit(&strm, -1); // default compression level
if (ret != Z_OK) {
2012-02-18 12:40:36 +02:00
delete[] out;
2010-03-17 14:00:29 +02:00
return;
2016-07-09 11:21:54 +02:00
}
2010-03-17 14:00:29 +02:00
strm.avail_in = static_cast<uInt>(this->ProcessOutput.size());
strm.next_in = in;
strm.avail_out = outSize;
strm.next_out = out;
ret = deflate(&strm, Z_FINISH);
2017-04-14 19:02:05 +02:00
if (ret != Z_STREAM_END) {
2016-07-09 11:21:54 +02:00
cmCTestLog(this->CTest, ERROR_MESSAGE,
2017-04-14 19:02:05 +02:00
"Error during output compression. Sending uncompressed output."
2016-07-09 11:21:54 +02:00
<< std::endl);
2012-02-18 12:40:36 +02:00
delete[] out;
2010-03-17 14:00:29 +02:00
return;
2016-07-09 11:21:54 +02:00
}
2010-03-17 14:00:29 +02:00
(void)deflateEnd(&strm);
2013-03-16 19:13:01 +02:00
2016-07-09 11:21:54 +02:00
unsigned char* encoded_buffer =
new unsigned char[static_cast<int>(outSize * 1.5)];
2010-03-17 14:00:29 +02:00
2016-07-09 11:21:54 +02:00
size_t rlen = cmsysBase64_Encode(out, strm.total_out, encoded_buffer, 1);
2010-03-17 14:00:29 +02:00
2017-04-14 19:02:05 +02:00
this->CompressedOutput.clear();
2016-07-09 11:21:54 +02:00
for (size_t i = 0; i < rlen; i++) {
2010-03-17 14:00:29 +02:00
this->CompressedOutput += encoded_buffer[i];
2016-07-09 11:21:54 +02:00
}
2010-03-17 14:00:29 +02:00
2016-07-09 11:21:54 +02:00
if (strm.total_in) {
this->CompressionRatio =
static_cast<double>(strm.total_out) / static_cast<double>(strm.total_in);
}
2010-03-17 14:00:29 +02:00
2016-07-09 11:21:54 +02:00
delete[] encoded_buffer;
delete[] out;
2010-03-17 14:00:29 +02:00
}
2009-10-04 10:30:41 +03:00
bool cmCTestRunTest::EndTest(size_t completed, size_t total, bool started)
{
2011-06-19 15:41:06 +03:00
if ((!this->TestHandler->MemCheck &&
2016-07-09 11:21:54 +02:00
this->CTest->ShouldCompressTestOutput()) ||
2011-06-19 15:41:06 +03:00
(this->TestHandler->MemCheck &&
2017-04-14 19:02:05 +02:00
this->CTest->ShouldCompressTestOutput())) {
2010-03-17 14:00:29 +02:00
this->CompressOutput();
2016-07-09 11:21:54 +02:00
}
2010-03-17 14:00:29 +02:00
2009-10-04 10:30:41 +03:00
this->WriteLogOutputTop(completed, total);
std::string reason;
bool passed = true;
2018-04-23 21:13:27 +02:00
cmProcess::State res =
started ? this->TestProcess->GetProcessStatus() : cmProcess::State::Error;
2018-10-28 12:09:07 +01:00
if (res != cmProcess::State::Expired) {
this->TimeoutIsForStopTime = false;
}
2009-10-04 10:30:41 +03:00
int retVal = this->TestProcess->GetExitValue();
bool forceFail = false;
2017-07-20 19:35:53 +02:00
bool skipped = false;
2009-10-04 10:30:41 +03:00
bool outputTestErrorsToConsole = false;
2016-10-30 18:24:19 +01:00
if (!this->TestProperties->RequiredRegularExpressions.empty() &&
this->FailedDependencies.empty()) {
2009-10-04 10:30:41 +03:00
bool found = false;
2018-01-26 17:06:56 +01:00
for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
2018-10-28 12:09:07 +01:00
if (pass.first.find(this->ProcessOutput)) {
2009-10-04 10:30:41 +03:00
found = true;
reason = "Required regular expression found.";
2013-11-03 12:27:13 +02:00
break;
2009-10-04 10:30:41 +03:00
}
2016-07-09 11:21:54 +02:00
}
if (!found) {
2009-10-04 10:30:41 +03:00
reason = "Required regular expression not found.";
forceFail = true;
2016-07-09 11:21:54 +02:00
}
reason += "Regex=[";
2018-01-26 17:06:56 +01:00
for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
reason += pass.second;
2009-10-04 10:30:41 +03:00
reason += "\n";
}
2016-07-09 11:21:54 +02:00
reason += "]";
}
2016-10-30 18:24:19 +01:00
if (!this->TestProperties->ErrorRegularExpressions.empty() &&
this->FailedDependencies.empty()) {
2018-01-26 17:06:56 +01:00
for (auto& pass : this->TestProperties->ErrorRegularExpressions) {
2018-10-28 12:09:07 +01:00
if (pass.first.find(this->ProcessOutput)) {
2009-10-04 10:30:41 +03:00
reason = "Error regular expression found in output.";
reason += " Regex=[";
2018-01-26 17:06:56 +01:00
reason += pass.second;
2009-10-04 10:30:41 +03:00
reason += "]";
forceFail = true;
2013-11-03 12:27:13 +02:00
break;
2009-10-04 10:30:41 +03:00
}
}
2016-07-09 11:21:54 +02:00
}
2018-10-28 12:09:07 +01:00
std::ostringstream outputStream;
2018-04-23 21:13:27 +02:00
if (res == cmProcess::State::Exited) {
2016-07-09 11:21:54 +02:00
bool success = !forceFail &&
2016-10-30 18:24:19 +01:00
(retVal == 0 ||
!this->TestProperties->RequiredRegularExpressions.empty());
2016-07-09 11:21:54 +02:00
if (this->TestProperties->SkipReturnCode >= 0 &&
this->TestProperties->SkipReturnCode == retVal) {
2014-08-03 19:52:23 +02:00
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
2017-07-20 19:35:53 +02:00
std::ostringstream s;
s << "SKIP_RETURN_CODE=" << this->TestProperties->SkipReturnCode;
this->TestResult.CompletionStatus = s.str();
2014-08-03 19:52:23 +02:00
cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Skipped ");
2017-07-20 19:35:53 +02:00
skipped = true;
2016-07-09 11:21:54 +02:00
} else if ((success && !this->TestProperties->WillFail) ||
(!success && this->TestProperties->WillFail)) {
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::COMPLETED;
2018-10-28 12:09:07 +01:00
outputStream << " Passed ";
2016-07-09 11:21:54 +02:00
} else {
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::FAILED;
2018-10-28 12:09:07 +01:00
outputStream << "***Failed " << reason;
2009-10-04 10:30:41 +03:00
outputTestErrorsToConsole = this->CTest->OutputTestOutputOnTestFailure;
}
2018-04-23 21:13:27 +02:00
} else if (res == cmProcess::State::Expired) {
2018-10-28 12:09:07 +01:00
outputStream << "***Timeout ";
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::TIMEOUT;
outputTestErrorsToConsole = this->CTest->OutputTestOutputOnTestFailure;
2018-04-23 21:13:27 +02:00
} else if (res == cmProcess::State::Exception) {
2009-10-04 10:30:41 +03:00
outputTestErrorsToConsole = this->CTest->OutputTestOutputOnTestFailure;
2018-10-28 12:09:07 +01:00
outputStream << "***Exception: ";
2018-01-26 17:06:56 +01:00
this->TestResult.ExceptionStatus =
this->TestProcess->GetExitExceptionString();
2016-07-09 11:21:54 +02:00
switch (this->TestProcess->GetExitException()) {
2018-04-23 21:13:27 +02:00
case cmProcess::Exception::Fault:
2018-10-28 12:09:07 +01:00
outputStream << "SegFault";
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::SEGFAULT;
break;
2018-04-23 21:13:27 +02:00
case cmProcess::Exception::Illegal:
2018-10-28 12:09:07 +01:00
outputStream << "Illegal";
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::ILLEGAL;
break;
2018-04-23 21:13:27 +02:00
case cmProcess::Exception::Interrupt:
2018-10-28 12:09:07 +01:00
outputStream << "Interrupt";
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::INTERRUPT;
break;
2018-04-23 21:13:27 +02:00
case cmProcess::Exception::Numerical:
2018-10-28 12:09:07 +01:00
outputStream << "Numerical";
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::NUMERICAL;
break;
default:
2018-01-26 17:06:56 +01:00
cmCTestLog(this->CTest, HANDLER_OUTPUT,
this->TestResult.ExceptionStatus);
2009-10-04 10:30:41 +03:00
this->TestResult.Status = cmCTestTestHandler::OTHER_FAULT;
}
2017-07-20 19:35:53 +02:00
} else if ("Disabled" == this->TestResult.CompletionStatus) {
2018-10-28 12:09:07 +01:00
outputStream << "***Not Run (Disabled) ";
2018-04-23 21:13:27 +02:00
} else // cmProcess::State::Error
2016-07-09 11:21:54 +02:00
{
2018-10-28 12:09:07 +01:00
outputStream << "***Not Run ";
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
passed = this->TestResult.Status == cmCTestTestHandler::COMPLETED;
char buf[1024];
2018-04-23 21:13:27 +02:00
sprintf(buf, "%6.2f sec", this->TestProcess->GetTotalTime().count());
2018-10-28 12:09:07 +01:00
outputStream << buf << "\n";
if (this->CTest->GetTestProgressOutput()) {
if (!passed) {
// If the test did not pass, reprint test name and error
std::string output = GetTestPrefix(completed, total);
std::string testName = this->TestProperties->Name;
const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
testName.resize(maxTestNameWidth + 4, '.');
output += testName;
output += outputStream.str();
outputStream.str("");
outputStream.clear();
outputStream << output;
cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, "\n"); // flush
}
if (completed == total) {
std::string testName =
GetTestPrefix(completed, total) + this->TestProperties->Name + "\n";
cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, testName);
}
}
if (!this->CTest->GetTestProgressOutput() || !passed) {
cmCTestLog(this->CTest, HANDLER_OUTPUT, outputStream.str());
}
2009-10-04 10:30:41 +03:00
2016-07-09 11:21:54 +02:00
if (outputTestErrorsToConsole) {
cmCTestLog(this->CTest, HANDLER_OUTPUT, this->ProcessOutput << std::endl);
}
2009-10-04 10:30:41 +03:00
2016-07-09 11:21:54 +02:00
if (this->TestHandler->LogFile) {
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile << "Test time = " << buf << std::endl;
2016-07-09 11:21:54 +02:00
}
2010-11-13 01:00:53 +02:00
2018-08-09 18:06:22 +02:00
this->DartProcessing();
2010-11-13 01:00:53 +02:00
2009-10-04 10:30:41 +03:00
// if this is doing MemCheck then all the output needs to be put into
// Output since that is what is parsed by cmCTestMemCheckHandler
2016-07-09 11:21:54 +02:00
if (!this->TestHandler->MemCheck && started) {
this->TestHandler->CleanTestOutput(
this->ProcessOutput,
static_cast<size_t>(
this->TestResult.Status == cmCTestTestHandler::COMPLETED
? this->TestHandler->CustomMaximumPassedTestOutputSize
: this->TestHandler->CustomMaximumFailedTestOutputSize));
}
2009-10-04 10:30:41 +03:00
this->TestResult.Reason = reason;
2016-07-09 11:21:54 +02:00
if (this->TestHandler->LogFile) {
2009-10-04 10:30:41 +03:00
bool pass = true;
const char* reasonType = "Test Pass Reason";
2016-07-09 11:21:54 +02:00
if (this->TestResult.Status != cmCTestTestHandler::COMPLETED &&
this->TestResult.Status != cmCTestTestHandler::NOT_RUN) {
2009-10-04 10:30:41 +03:00
reasonType = "Test Fail Reason";
pass = false;
2016-07-09 11:21:54 +02:00
}
2018-04-23 21:13:27 +02:00
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);
2009-10-04 10:30:41 +03:00
char buffer[100];
2018-04-23 21:13:27 +02:00
sprintf(buffer, "%02d:%02d:%02d", static_cast<unsigned>(hours.count()),
static_cast<unsigned>(minutes.count()),
static_cast<unsigned>(seconds.count()));
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile
<< "----------------------------------------------------------"
<< std::endl;
2016-07-09 11:21:54 +02:00
if (!this->TestResult.Reason.empty()) {
2013-03-16 19:13:01 +02:00
*this->TestHandler->LogFile << reasonType << ":\n"
2016-07-09 11:21:54 +02:00
<< this->TestResult.Reason << "\n";
} else {
if (pass) {
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile << "Test Passed.\n";
2016-07-09 11:21:54 +02:00
} else {
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile << "Test Failed.\n";
}
2016-07-09 11:21:54 +02:00
}
*this->TestHandler->LogFile
<< "\"" << this->TestProperties->Name
2009-10-04 10:30:41 +03:00
<< "\" end time: " << this->CTest->CurrentTime() << std::endl
2016-07-09 11:21:54 +02:00
<< "\"" << this->TestProperties->Name << "\" time elapsed: " << buffer
<< std::endl
2009-10-04 10:30:41 +03:00
<< "----------------------------------------------------------"
2016-07-09 11:21:54 +02:00
<< std::endl
<< std::endl;
}
2013-03-16 19:13:01 +02:00
// if the test actually started and ran
// record the results in TestResult
2016-07-09 11:21:54 +02:00
if (started) {
2011-06-19 15:41:06 +03:00
bool compress = !this->TestHandler->MemCheck &&
2016-07-09 11:21:54 +02:00
this->CompressionRatio < 1 && this->CTest->ShouldCompressTestOutput();
this->TestResult.Output =
compress ? this->CompressedOutput : this->ProcessOutput;
2010-03-17 14:00:29 +02:00
this->TestResult.CompressOutput = compress;
2009-10-04 10:30:41 +03:00
this->TestResult.ReturnValue = this->TestProcess->GetExitValue();
2017-07-20 19:35:53 +02:00
if (!skipped) {
this->TestResult.CompletionStatus = "Completed";
}
2009-10-04 10:30:41 +03:00
this->TestResult.ExecutionTime = this->TestProcess->GetTotalTime();
this->MemCheckPostProcess();
2010-06-23 01:18:35 +03:00
this->ComputeWeightedCost();
2016-07-09 11:21:54 +02:00
}
2015-08-17 11:37:30 +02:00
// If the test does not need to rerun push the current TestResult onto the
2010-03-17 14:00:29 +02:00
// TestHandler vector
2016-07-09 11:21:54 +02:00
if (!this->NeedsToRerun()) {
2015-08-17 11:37:30 +02:00
this->TestHandler->TestResults.push_back(this->TestResult);
2016-07-09 11:21:54 +02:00
}
2018-04-23 21:13:27 +02:00
this->TestProcess.reset();
2017-07-20 19:35:53 +02:00
return passed || skipped;
2009-10-04 10:30:41 +03:00
}
2018-10-28 12:09:07 +01:00
bool cmCTestRunTest::StartAgain(size_t completed)
2015-08-17 11:37:30 +02:00
{
2016-07-09 11:21:54 +02:00
if (!this->RunAgain) {
2015-08-17 11:37:30 +02:00
return false;
2016-07-09 11:21:54 +02:00
}
2015-08-17 11:37:30 +02:00
this->RunAgain = false; // reset
// change to tests directory
2017-07-20 19:35:53 +02:00
cmWorkingDirectory workdir(this->TestProperties->Directory);
2018-08-09 18:06:22 +02:00
if (workdir.Failed()) {
this->StartFailure("Failed to change working directory to " +
this->TestProperties->Directory + " : " +
std::strerror(workdir.GetLastResult()));
return true;
}
2018-10-28 12:09:07 +01:00
this->StartTest(completed, this->TotalNumberOfTests);
2015-08-17 11:37:30 +02:00
return true;
}
bool cmCTestRunTest::NeedsToRerun()
{
this->NumberOfRunsLeft--;
2016-07-09 11:21:54 +02:00
if (this->NumberOfRunsLeft == 0) {
2015-08-17 11:37:30 +02:00
return false;
2016-07-09 11:21:54 +02:00
}
2015-08-17 11:37:30 +02:00
// if number of runs left is not 0, and we are running until
// we find a failed test, then return true so the test can be
// restarted
2016-07-09 11:21:54 +02:00
if (this->RunUntilFail &&
this->TestResult.Status == cmCTestTestHandler::COMPLETED) {
2015-08-17 11:37:30 +02:00
this->RunAgain = true;
return true;
2016-07-09 11:21:54 +02:00
}
2015-08-17 11:37:30 +02:00
return false;
}
2010-06-23 01:18:35 +03:00
void cmCTestRunTest::ComputeWeightedCost()
{
2010-11-13 01:00:53 +02:00
double prev = static_cast<double>(this->TestProperties->PreviousRuns);
double avgcost = static_cast<double>(this->TestProperties->Cost);
2018-04-23 21:13:27 +02:00
double current = this->TestResult.ExecutionTime.count();
2010-06-23 01:18:35 +03:00
2016-07-09 11:21:54 +02:00
if (this->TestResult.Status == cmCTestTestHandler::COMPLETED) {
2010-11-13 01:00:53 +02:00
this->TestProperties->Cost =
static_cast<float>(((prev * avgcost) + current) / (prev + 1.0));
2010-06-23 01:18:35 +03:00
this->TestProperties->PreviousRuns++;
2016-07-09 11:21:54 +02:00
}
2010-06-23 01:18:35 +03:00
}
2009-10-04 10:30:41 +03:00
void cmCTestRunTest::MemCheckPostProcess()
{
2016-07-09 11:21:54 +02:00
if (!this->TestHandler->MemCheck) {
2009-10-04 10:30:41 +03:00
return;
2016-07-09 11:21:54 +02:00
}
2018-08-09 18:06:22 +02:00
cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
this->Index << ": process test output now: "
<< this->TestProperties->Name << " "
<< this->TestResult.Name << std::endl,
2016-07-09 11:21:54 +02:00
this->TestHandler->GetQuiet());
cmCTestMemCheckHandler* handler =
static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
2015-04-27 22:25:09 +02:00
handler->PostProcessTest(this->TestResult, this->Index);
2009-10-04 10:30:41 +03:00
}
2018-08-09 18:06:22 +02:00
void cmCTestRunTest::StartFailure(std::string const& output)
{
// Still need to log the Start message so the test summary records our
// attempt to start this test
2018-10-28 12:09:07 +01:00
if (!this->CTest->GetTestProgressOutput()) {
cmCTestLog(this->CTest, HANDLER_OUTPUT,
std::setw(2 * getNumWidth(this->TotalNumberOfTests) + 8)
<< "Start "
<< std::setw(getNumWidth(this->TestHandler->GetMaxIndex()))
<< this->TestProperties->Index << ": "
<< this->TestProperties->Name << std::endl);
}
2018-08-09 18:06:22 +02:00
this->ProcessOutput.clear();
if (!output.empty()) {
*this->TestHandler->LogFile << output << std::endl;
cmCTestLog(this->CTest, ERROR_MESSAGE, output << std::endl);
}
this->TestResult.Properties = this->TestProperties;
this->TestResult.ExecutionTime = cmDuration::zero();
this->TestResult.CompressOutput = false;
this->TestResult.ReturnValue = -1;
this->TestResult.CompletionStatus = "Failed to start";
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
this->TestResult.TestCount = this->TestProperties->Index;
this->TestResult.Name = this->TestProperties->Name;
this->TestResult.Path = this->TestProperties->Directory;
this->TestResult.Output = output;
this->TestResult.FullCommandLine.clear();
this->TestProcess = cm::make_unique<cmProcess>(*this);
}
2018-10-28 12:09:07 +01:00
std::string cmCTestRunTest::GetTestPrefix(size_t completed, size_t total) const
{
std::ostringstream outputStream;
outputStream << std::setw(getNumWidth(total)) << completed << "/";
outputStream << std::setw(getNumWidth(total)) << total << " ";
if (this->TestHandler->MemCheck) {
outputStream << "MemCheck";
} else {
outputStream << "Test";
}
std::ostringstream indexStr;
indexStr << " #" << this->Index << ":";
outputStream << std::setw(3 + getNumWidth(this->TestHandler->GetMaxIndex()))
<< indexStr.str();
outputStream << " ";
return outputStream.str();
}
2009-10-04 10:30:41 +03:00
// Starts the execution of a test. Returns once it has started
2018-10-28 12:09:07 +01:00
bool cmCTestRunTest::StartTest(size_t completed, size_t total)
2009-10-04 10:30:41 +03:00
{
2015-08-17 11:37:30 +02:00
this->TotalNumberOfTests = total; // save for rerun case
2018-10-28 12:09:07 +01:00
if (!this->CTest->GetTestProgressOutput()) {
cmCTestLog(this->CTest, HANDLER_OUTPUT,
std::setw(2 * getNumWidth(total) + 8)
<< "Start "
<< std::setw(getNumWidth(this->TestHandler->GetMaxIndex()))
<< this->TestProperties->Index << ": "
<< this->TestProperties->Name << std::endl);
} else {
std::string testName =
GetTestPrefix(completed, total) + this->TestProperties->Name + "\n";
cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, testName);
}
2017-04-14 19:02:05 +02:00
this->ProcessOutput.clear();
2017-07-20 19:35:53 +02:00
// Return immediately if test is disabled
if (this->TestProperties->Disabled) {
this->TestResult.Properties = this->TestProperties;
2018-04-23 21:13:27 +02:00
this->TestResult.ExecutionTime = cmDuration::zero();
2017-07-20 19:35:53 +02:00
this->TestResult.CompressOutput = false;
this->TestResult.ReturnValue = -1;
this->TestResult.CompletionStatus = "Disabled";
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
this->TestResult.TestCount = this->TestProperties->Index;
this->TestResult.Name = this->TestProperties->Name;
this->TestResult.Path = this->TestProperties->Directory;
2018-04-23 21:13:27 +02:00
this->TestProcess = cm::make_unique<cmProcess>(*this);
2017-07-20 19:35:53 +02:00
this->TestResult.Output = "Disabled";
2018-01-26 17:06:56 +01:00
this->TestResult.FullCommandLine.clear();
2017-07-20 19:35:53 +02:00
return false;
}
2009-10-04 10:30:41 +03:00
this->TestResult.Properties = this->TestProperties;
2018-04-23 21:13:27 +02:00
this->TestResult.ExecutionTime = cmDuration::zero();
2010-03-17 14:00:29 +02:00
this->TestResult.CompressOutput = false;
2009-10-04 10:30:41 +03:00
this->TestResult.ReturnValue = -1;
2010-03-17 14:00:29 +02:00
this->TestResult.CompletionStatus = "Failed to start";
this->TestResult.Status = cmCTestTestHandler::BAD_COMMAND;
2013-03-16 19:13:01 +02:00
this->TestResult.TestCount = this->TestProperties->Index;
2009-10-04 10:30:41 +03:00
this->TestResult.Name = this->TestProperties->Name;
2016-07-09 11:21:54 +02:00
this->TestResult.Path = this->TestProperties->Directory;
2011-06-19 15:41:06 +03:00
2018-04-23 21:13:27 +02:00
// Check for failed fixture dependencies before we even look at the command
// arguments because if we are not going to run the test, the command and
// its arguments are irrelevant. This matters for the case where a fixture
// dependency might be creating the executable we want to run.
2016-10-30 18:24:19 +01:00
if (!this->FailedDependencies.empty()) {
2018-04-23 21:13:27 +02:00
this->TestProcess = cm::make_unique<cmProcess>(*this);
2016-10-30 18:24:19 +01:00
std::string msg = "Failed test dependencies:";
2018-01-26 17:06:56 +01:00
for (std::string const& failedDep : this->FailedDependencies) {
msg += " " + failedDep;
2016-10-30 18:24:19 +01:00
}
*this->TestHandler->LogFile << msg << std::endl;
cmCTestLog(this->CTest, HANDLER_OUTPUT, msg << std::endl);
this->TestResult.Output = msg;
2018-01-26 17:06:56 +01:00
this->TestResult.FullCommandLine.clear();
2017-07-20 19:35:53 +02:00
this->TestResult.CompletionStatus = "Fixture dependency failed";
2016-10-30 18:24:19 +01:00
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
return false;
}
2018-04-23 21:13:27 +02:00
this->ComputeArguments();
std::vector<std::string>& args = this->TestProperties->Args;
2016-07-09 11:21:54 +02:00
if (args.size() >= 2 && args[1] == "NOT_AVAILABLE") {
2018-04-23 21:13:27 +02:00
this->TestProcess = cm::make_unique<cmProcess>(*this);
2011-06-19 15:41:06 +03:00
std::string msg;
2016-07-09 11:21:54 +02:00
if (this->CTest->GetConfigType().empty()) {
2011-06-19 15:41:06 +03:00
msg = "Test not available without configuration.";
msg += " (Missing \"-C <config>\"?)";
2016-07-09 11:21:54 +02:00
} else {
2011-06-19 15:41:06 +03:00
msg = "Test not available in configuration \"";
msg += this->CTest->GetConfigType();
msg += "\".";
2016-07-09 11:21:54 +02:00
}
2011-06-19 15:41:06 +03:00
*this->TestHandler->LogFile << msg << std::endl;
cmCTestLog(this->CTest, ERROR_MESSAGE, msg << std::endl);
this->TestResult.Output = msg;
2018-01-26 17:06:56 +01:00
this->TestResult.FullCommandLine.clear();
2017-07-20 19:35:53 +02:00
this->TestResult.CompletionStatus = "Missing Configuration";
2011-06-19 15:41:06 +03:00
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
return false;
2016-07-09 11:21:54 +02:00
}
2013-03-16 19:13:01 +02:00
2010-03-17 14:00:29 +02:00
// Check if all required files exist
2018-01-26 17:06:56 +01:00
for (std::string const& file : this->TestProperties->RequiredFiles) {
2018-04-23 21:13:27 +02:00
if (!cmSystemTools::FileExists(file)) {
2016-07-09 11:21:54 +02:00
// Required file was not found
2018-04-23 21:13:27 +02:00
this->TestProcess = cm::make_unique<cmProcess>(*this);
2016-07-09 11:21:54 +02:00
*this->TestHandler->LogFile << "Unable to find required file: " << file
<< std::endl;
cmCTestLog(this->CTest, ERROR_MESSAGE,
"Unable to find required file: " << file << std::endl);
2010-03-17 14:00:29 +02:00
this->TestResult.Output = "Unable to find required file: " + file;
2018-01-26 17:06:56 +01:00
this->TestResult.FullCommandLine.clear();
2017-07-20 19:35:53 +02:00
this->TestResult.CompletionStatus = "Required Files Missing";
2010-03-17 14:00:29 +02:00
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
return false;
}
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
// log and return if we did not find the executable
2018-01-26 17:06:56 +01:00
if (this->ActualCommand.empty()) {
2010-03-17 14:00:29 +02:00
// if the command was not found create a TestResult object
2013-03-16 19:13:01 +02:00
// that has that information
2018-04-23 21:13:27 +02:00
this->TestProcess = cm::make_unique<cmProcess>(*this);
2016-07-09 11:21:54 +02:00
*this->TestHandler->LogFile << "Unable to find executable: " << args[1]
<< std::endl;
cmCTestLog(this->CTest, ERROR_MESSAGE,
"Unable to find executable: " << args[1] << std::endl);
2009-10-04 10:30:41 +03:00
this->TestResult.Output = "Unable to find executable: " + args[1];
2018-01-26 17:06:56 +01:00
this->TestResult.FullCommandLine.clear();
2017-07-20 19:35:53 +02:00
this->TestResult.CompletionStatus = "Unable to find executable";
2010-03-17 14:00:29 +02:00
this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
2009-10-04 10:30:41 +03:00
return false;
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
this->StartTime = this->CTest->CurrentTime();
2018-04-23 21:13:27 +02:00
auto timeout = this->TestProperties->Timeout;
2010-06-23 01:18:35 +03:00
2018-10-28 12:09:07 +01:00
this->TimeoutIsForStopTime = false;
2018-04-23 21:13:27 +02:00
std::chrono::system_clock::time_point stop_time = this->CTest->GetStopTime();
if (stop_time != std::chrono::system_clock::time_point()) {
std::chrono::duration<double> stop_timeout =
(stop_time - std::chrono::system_clock::now()) % std::chrono::hours(24);
if (stop_timeout <= std::chrono::duration<double>::zero()) {
stop_timeout = std::chrono::duration<double>::zero();
}
if (timeout == std::chrono::duration<double>::zero() ||
stop_timeout < timeout) {
2018-10-28 12:09:07 +01:00
this->TimeoutIsForStopTime = true;
2018-04-23 21:13:27 +02:00
timeout = stop_timeout;
}
2016-07-09 11:21:54 +02:00
}
2018-04-23 21:13:27 +02:00
2011-01-16 11:35:12 +01:00
return this->ForkProcess(timeout, this->TestProperties->ExplicitTimeout,
2018-08-09 18:06:22 +02:00
&this->TestProperties->Environment,
&this->TestProperties->Affinity);
2009-10-04 10:30:41 +03:00
}
void cmCTestRunTest::ComputeArguments()
{
2018-08-09 18:06:22 +02:00
this->Arguments.clear(); // reset because this might be a rerun
2010-06-23 01:18:35 +03:00
std::vector<std::string>::const_iterator j =
2009-10-04 10:30:41 +03:00
this->TestProperties->Args.begin();
++j; // skip test name
// find the test executable
2016-07-09 11:21:54 +02:00
if (this->TestHandler->MemCheck) {
cmCTestMemCheckHandler* handler =
static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
this->ActualCommand = handler->MemoryTester;
2010-06-23 01:18:35 +03:00
this->TestProperties->Args[1] = this->TestHandler->FindTheExecutable(
this->TestProperties->Args[1].c_str());
2016-07-09 11:21:54 +02:00
} else {
this->ActualCommand = this->TestHandler->FindTheExecutable(
2009-10-04 10:30:41 +03:00
this->TestProperties->Args[1].c_str());
2016-07-09 11:21:54 +02:00
++j; // skip the executable (it will be actualCommand)
}
std::string testCommand =
2018-04-23 21:13:27 +02:00
cmSystemTools::ConvertToOutputPath(this->ActualCommand);
2009-10-04 10:30:41 +03:00
2016-07-09 11:21:54 +02:00
// Prepends memcheck args to our command string
2013-11-03 12:27:13 +02:00
this->TestHandler->GenerateTestCommand(this->Arguments, this->Index);
2018-01-26 17:06:56 +01:00
for (std::string const& arg : this->Arguments) {
2010-11-13 01:00:53 +02:00
testCommand += " \"";
2018-01-26 17:06:56 +01:00
testCommand += arg;
2010-11-13 01:00:53 +02:00
testCommand += "\"";
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
2016-07-09 11:21:54 +02:00
for (; j != this->TestProperties->Args.end(); ++j) {
2010-11-13 01:00:53 +02:00
testCommand += " \"";
testCommand += *j;
testCommand += "\"";
2009-10-04 10:30:41 +03:00
this->Arguments.push_back(*j);
2016-07-09 11:21:54 +02:00
}
2010-11-13 01:00:53 +02:00
this->TestResult.FullCommandLine = testCommand;
2009-10-04 10:30:41 +03:00
2015-08-17 11:37:30 +02:00
// Print the test command in verbose mode
2018-08-09 18:06:22 +02:00
cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
std::endl
2016-07-09 11:21:54 +02:00
<< this->Index << ": "
<< (this->TestHandler->MemCheck ? "MemCheck" : "Test")
<< " command: " << testCommand << std::endl);
2015-08-17 11:37:30 +02:00
// Print any test-specific env vars in verbose mode
2016-10-30 18:24:19 +01:00
if (!this->TestProperties->Environment.empty()) {
2018-08-09 18:06:22 +02:00
cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
this->Index << ": "
<< "Environment variables: " << std::endl);
2016-07-09 11:21:54 +02:00
}
2018-01-26 17:06:56 +01:00
for (std::string const& env : this->TestProperties->Environment) {
2018-08-09 18:06:22 +02:00
cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
this->Index << ": " << env << std::endl);
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
}
void cmCTestRunTest::DartProcessing()
{
2013-03-16 19:13:01 +02:00
if (!this->ProcessOutput.empty() &&
2017-07-20 19:35:53 +02:00
this->ProcessOutput.find("<DartMeasurement") != std::string::npos) {
2018-10-28 12:09:07 +01:00
if (this->TestHandler->DartStuff.find(this->ProcessOutput)) {
2015-08-17 11:37:30 +02:00
this->TestResult.DartString = this->TestHandler->DartStuff.match(1);
2009-10-04 10:30:41 +03:00
// keep searching and replacing until none are left
2018-10-28 12:09:07 +01:00
while (this->TestHandler->DartStuff1.find(this->ProcessOutput)) {
2009-10-04 10:30:41 +03:00
// replace the exact match for the string
2016-07-09 11:21:54 +02:00
cmSystemTools::ReplaceString(
this->ProcessOutput, this->TestHandler->DartStuff1.match(1).c_str(),
"");
2009-10-04 10:30:41 +03:00
}
}
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
}
2018-04-23 21:13:27 +02:00
bool cmCTestRunTest::ForkProcess(cmDuration testTimeOut, bool explicitTimeout,
2018-08-09 18:06:22 +02:00
std::vector<std::string>* environment,
std::vector<size_t>* affinity)
2009-10-04 10:30:41 +03:00
{
2018-04-23 21:13:27 +02:00
this->TestProcess = cm::make_unique<cmProcess>(*this);
2009-10-04 10:30:41 +03:00
this->TestProcess->SetId(this->Index);
this->TestProcess->SetWorkingDirectory(
2016-07-09 11:21:54 +02:00
this->TestProperties->Directory.c_str());
2009-10-04 10:30:41 +03:00
this->TestProcess->SetCommand(this->ActualCommand.c_str());
this->TestProcess->SetCommandArguments(this->Arguments);
// determine how much time we have
2018-04-23 21:13:27 +02:00
cmDuration timeout = this->CTest->GetRemainingTimeAllowed();
if (timeout != cmCTest::MaxDuration()) {
timeout -= std::chrono::minutes(2);
}
if (this->CTest->GetTimeOut() > cmDuration::zero() &&
this->CTest->GetTimeOut() < timeout) {
2009-10-04 10:30:41 +03:00
timeout = this->CTest->GetTimeOut();
2016-07-09 11:21:54 +02:00
}
2018-04-23 21:13:27 +02:00
if (testTimeOut > cmDuration::zero() &&
2016-07-09 11:21:54 +02:00
testTimeOut < this->CTest->GetRemainingTimeAllowed()) {
2009-10-04 10:30:41 +03:00
timeout = testTimeOut;
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
// always have at least 1 second if we got to here
2018-04-23 21:13:27 +02:00
if (timeout <= cmDuration::zero()) {
timeout = std::chrono::seconds(1);
2016-07-09 11:21:54 +02:00
}
2011-01-16 11:35:12 +01:00
// handle timeout explicitly set to 0
2018-04-23 21:13:27 +02:00
if (testTimeOut == cmDuration::zero() && explicitTimeout) {
timeout = cmDuration::zero();
2016-07-09 11:21:54 +02:00
}
2018-08-09 18:06:22 +02:00
cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
this->Index << ": "
<< "Test timeout computed to be: "
<< cmDurationTo<unsigned int>(timeout)
<< "\n",
2016-07-09 11:21:54 +02:00
this->TestHandler->GetQuiet());
2009-10-04 10:30:41 +03:00
this->TestProcess->SetTimeout(timeout);
2010-06-23 01:18:35 +03:00
#ifdef CMAKE_BUILD_WITH_CMAKE
cmSystemTools::SaveRestoreEnvironment sre;
#endif
2016-07-09 11:21:54 +02:00
if (environment && !environment->empty()) {
2012-06-27 20:52:58 +03:00
cmSystemTools::AppendEnv(*environment);
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
2018-08-09 18:06:22 +02:00
return this->TestProcess->StartProcess(this->MultiTestHandler.Loop,
affinity);
2009-10-04 10:30:41 +03:00
}
void cmCTestRunTest::WriteLogOutputTop(size_t completed, size_t total)
{
2018-10-28 12:09:07 +01:00
std::ostringstream outputStream;
// If this is the last or only run of this test, or progress output is
// requested, then print out completed / total.
2015-08-17 11:37:30 +02:00
// Only issue is if a test fails and we are running until fail
// then it will never print out the completed / total, same would
// got for run until pass. Trick is when this is called we don't
// yet know if we are passing or failing.
2018-10-28 12:09:07 +01:00
if (this->NumberOfRunsLeft == 1 || this->CTest->GetTestProgressOutput()) {
outputStream << std::setw(getNumWidth(total)) << completed << "/";
outputStream << std::setw(getNumWidth(total)) << total << " ";
2016-07-09 11:21:54 +02:00
}
2015-08-17 11:37:30 +02:00
// if this is one of several runs of a test just print blank space
// to keep things neat
2016-07-09 11:21:54 +02:00
else {
2018-10-28 12:09:07 +01:00
outputStream << std::setw(getNumWidth(total)) << " ";
outputStream << std::setw(getNumWidth(total)) << " ";
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
2016-07-09 11:21:54 +02:00
if (this->TestHandler->MemCheck) {
2018-10-28 12:09:07 +01:00
outputStream << "MemCheck";
2016-07-09 11:21:54 +02:00
} else {
2018-10-28 12:09:07 +01:00
outputStream << "Test";
2016-07-09 11:21:54 +02:00
}
2009-10-04 10:30:41 +03:00
2015-04-27 22:25:09 +02:00
std::ostringstream indexStr;
2009-10-04 10:30:41 +03:00
indexStr << " #" << this->Index << ":";
2018-10-28 12:09:07 +01:00
outputStream << std::setw(3 + getNumWidth(this->TestHandler->GetMaxIndex()))
<< indexStr.str();
outputStream << " ";
2009-10-04 10:30:41 +03:00
const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
std::string outname = this->TestProperties->Name + " ";
outname.resize(maxTestNameWidth + 4, '.');
2018-10-28 12:09:07 +01:00
outputStream << outname;
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile << this->TestProperties->Index << "/"
2016-07-09 11:21:54 +02:00
<< this->TestHandler->TotalNumberOfTests
<< " Testing: " << this->TestProperties->Name
<< std::endl;
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile << this->TestProperties->Index << "/"
2016-07-09 11:21:54 +02:00
<< this->TestHandler->TotalNumberOfTests
<< " Test: " << this->TestProperties->Name
<< std::endl;
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile << "Command: \"" << this->ActualCommand << "\"";
2013-03-16 19:13:01 +02:00
2018-01-26 17:06:56 +01:00
for (std::string const& arg : this->Arguments) {
*this->TestHandler->LogFile << " \"" << arg << "\"";
2016-07-09 11:21:54 +02:00
}
*this->TestHandler->LogFile
<< std::endl
2009-10-04 10:30:41 +03:00
<< "Directory: " << this->TestProperties->Directory << std::endl
2016-07-09 11:21:54 +02:00
<< "\"" << this->TestProperties->Name
<< "\" start time: " << this->StartTime << std::endl;
2009-10-04 10:30:41 +03:00
*this->TestHandler->LogFile
<< "Output:" << std::endl
<< "----------------------------------------------------------"
<< std::endl;
2016-07-09 11:21:54 +02:00
*this->TestHandler->LogFile << this->ProcessOutput << "<end of output>"
<< std::endl;
2009-10-04 10:30:41 +03:00
2018-10-28 12:09:07 +01:00
if (!this->CTest->GetTestProgressOutput()) {
cmCTestLog(this->CTest, HANDLER_OUTPUT, outputStream.str());
}
2018-08-09 18:06:22 +02:00
cmCTestLog(this->CTest, DEBUG,
"Testing " << this->TestProperties->Name << " ... ");
2009-10-04 10:30:41 +03:00
}
2018-04-23 21:13:27 +02:00
void cmCTestRunTest::FinalizeTest()
{
this->MultiTestHandler.FinishTestProcess(this, true);
}