Source/CTest/cmCTestRunTest.cxx

   1 /* Distributed under the OSI-approved BSD 3-Clause License.  See accompanying
   2    file Copyright.txt or https://cmake.org/licensing for details.  */
   3 #include "cmCTestRunTest.h"
   4
   5 #include <algorithm>
   6 #include <chrono>
   7 #include <cstddef> // IWYU pragma: keep
   8 #include <cstdint>
   9 #include <cstdio>
  10 #include <cstring>
  11 #include <iomanip>
  12 #include <ratio>
  13 #include <sstream>
  14 #include <utility>
  15
  16 #include <cm/memory>
  17
  18 #include "cmsys/RegularExpression.hxx"
  19
  20 #include "cmCTest.h"
  21 #include "cmCTestMemCheckHandler.h"
  22 #include "cmCTestMultiProcessHandler.h"
  23 #include "cmProcess.h"
  24 #include "cmStringAlgorithms.h"
  25 #include "cmSystemTools.h"
  26 #include "cmWorkingDirectory.h"
  27
  28 cmCTestRunTest::cmCTestRunTest(cmCTestMultiProcessHandler& multiHandler)
  29   : MultiTestHandler(multiHandler)
  30 {
  31   this->CTest = multiHandler.CTest;
  32   this->TestHandler = multiHandler.TestHandler;
  33   this->TestResult.ExecutionTime = cmDuration::zero();
  34   this->TestResult.ReturnValue = 0;
  35   this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  36   this->TestResult.TestCount = 0;
  37   this->TestResult.Properties = nullptr;
  38 }
  39
  40 void cmCTestRunTest::CheckOutput(std::string const& line)
  41 {
  42   cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  43              this->GetIndex() << ": " << line << std::endl);
  44
  45   // Check for special CTest XML tags in this line of output.
  46   // If any are found, this line is excluded from ProcessOutput.
  47   if (!line.empty() && line.find("<CTest") != std::string::npos) {
  48     bool ctest_tag_found = false;
  49     if (this->TestHandler->CustomCompletionStatusRegex.find(line)) {
  50       ctest_tag_found = true;
  51       this->TestResult.CustomCompletionStatus =
  52         this->TestHandler->CustomCompletionStatusRegex.match(1);
  53       cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  54                  this->GetIndex() << ": "
  55                                   << "Test Details changed to '"
  56                                   << this->TestResult.CustomCompletionStatus
  57                                   << "'" << std::endl);
  58     } else if (this->TestHandler->CustomLabelRegex.find(line)) {
  59       ctest_tag_found = true;
  60       auto label = this->TestHandler->CustomLabelRegex.match(1);
  61       auto& labels = this->TestProperties->Labels;
  62       if (std::find(labels.begin(), labels.end(), label) == labels.end()) {
  63         labels.push_back(label);
  64         std::sort(labels.begin(), labels.end());
  65         cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  66                    this->GetIndex()
  67                      << ": "
  68                      << "Test Label added: '" << label << "'" << std::endl);
  69       }
  70     }
  71     if (ctest_tag_found) {
  72       return;
  73     }
  74   }
  75
  76   this->ProcessOutput += line;
  77   this->ProcessOutput += "\n";
  78
  79   // Check for TIMEOUT_AFTER_MATCH property.
  80   if (!this->TestProperties->TimeoutRegularExpressions.empty()) {
  81     for (auto& reg : this->TestProperties->TimeoutRegularExpressions) {
  82       if (reg.first.find(this->ProcessOutput)) {
  83         cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  84                    this->GetIndex()
  85                      << ": "
  86                      << "Test timeout changed to "
  87                      << std::chrono::duration_cast<std::chrono::seconds>(
  88                           this->TestProperties->AlternateTimeout)
  89                           .count()
  90                      << std::endl);
  91         this->TestProcess->ResetStartTime();
  92         this->TestProcess->ChangeTimeout(
  93           this->TestProperties->AlternateTimeout);
  94         this->TestProperties->TimeoutRegularExpressions.clear();
  95         break;
  96       }
  97     }
  98   }
  99 }
 100
 101 bool cmCTestRunTest::EndTest(size_t completed, size_t total, bool started)
 102 {
 103   this->WriteLogOutputTop(completed, total);
 104   std::string reason;
 105   bool passed = true;
 106   cmProcess::State res =
 107     started ? this->TestProcess->GetProcessStatus() : cmProcess::State::Error;
 108   if (res != cmProcess::State::Expired) {
 109     this->TimeoutIsForStopTime = false;
 110   }
 111   std::int64_t retVal = this->TestProcess->GetExitValue();
 112   bool forceFail = false;
 113   bool forceSkip = false;
 114   bool skipped = false;
 115   bool outputTestErrorsToConsole = false;
 116   if (!this->TestProperties->RequiredRegularExpressions.empty() &&
 117       this->FailedDependencies.empty()) {
 118     bool found = false;
 119     for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
 120       if (pass.first.find(this->ProcessOutput)) {
 121         found = true;
 122         reason = cmStrCat("Required regular expression found. Regex=[",
 123                           pass.second, ']');
 124         break;
 125       }
 126     }
 127     if (!found) {
 128       reason = "Required regular expression not found. Regex=[";
 129       for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
 130         reason += pass.second;
 131         reason += "\n";
 132       }
 133       reason += "]";
 134       forceFail = true;
 135     }
 136   }
 137   if (!this->TestProperties->ErrorRegularExpressions.empty() &&
 138       this->FailedDependencies.empty()) {
 139     for (auto& fail : this->TestProperties->ErrorRegularExpressions) {
 140       if (fail.first.find(this->ProcessOutput)) {
 141         reason = cmStrCat("Error regular expression found in output. Regex=[",
 142                           fail.second, ']');
 143         forceFail = true;
 144         break;
 145       }
 146     }
 147   }
 148   if (!this->TestProperties->SkipRegularExpressions.empty() &&
 149       this->FailedDependencies.empty()) {
 150     for (auto& skip : this->TestProperties->SkipRegularExpressions) {
 151       if (skip.first.find(this->ProcessOutput)) {
 152         reason = cmStrCat("Skip regular expression found in output. Regex=[",
 153                           skip.second, ']');
 154         forceSkip = true;
 155         break;
 156       }
 157     }
 158   }
 159   std::ostringstream outputStream;
 160   if (res == cmProcess::State::Exited) {
 161     bool success = !forceFail &&
 162       (retVal == 0 ||
 163        !this->TestProperties->RequiredRegularExpressions.empty());
 164     if ((this->TestProperties->SkipReturnCode >= 0 &&
 165          this->TestProperties->SkipReturnCode == retVal) ||
 166         forceSkip) {
 167       this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 168       std::ostringstream s;
 169       if (forceSkip) {
 170         s << "SKIP_REGULAR_EXPRESSION_MATCHED";
 171       } else {
 172         s << "SKIP_RETURN_CODE=" << this->TestProperties->SkipReturnCode;
 173       }
 174       this->TestResult.CompletionStatus = s.str();
 175       outputStream << "***Skipped ";
 176       skipped = true;
 177     } else if (success != this->TestProperties->WillFail) {
 178       this->TestResult.Status = cmCTestTestHandler::COMPLETED;
 179       outputStream << "   Passed  ";
 180     } else {
 181       this->TestResult.Status = cmCTestTestHandler::FAILED;
 182       outputStream << "***Failed  " << reason;
 183       outputTestErrorsToConsole =
 184         this->CTest->GetOutputTestOutputOnTestFailure();
 185     }
 186   } else if (res == cmProcess::State::Expired) {
 187     outputStream << "***Timeout ";
 188     this->TestResult.Status = cmCTestTestHandler::TIMEOUT;
 189     outputTestErrorsToConsole =
 190       this->CTest->GetOutputTestOutputOnTestFailure();
 191   } else if (res == cmProcess::State::Exception) {
 192     outputTestErrorsToConsole =
 193       this->CTest->GetOutputTestOutputOnTestFailure();
 194     outputStream << "***Exception: ";
 195     this->TestResult.ExceptionStatus =
 196       this->TestProcess->GetExitExceptionString();
 197     switch (this->TestProcess->GetExitException()) {
 198       case cmProcess::Exception::Fault:
 199         outputStream << "SegFault";
 200         this->TestResult.Status = cmCTestTestHandler::SEGFAULT;
 201         break;
 202       case cmProcess::Exception::Illegal:
 203         outputStream << "Illegal";
 204         this->TestResult.Status = cmCTestTestHandler::ILLEGAL;
 205         break;
 206       case cmProcess::Exception::Interrupt:
 207         outputStream << "Interrupt";
 208         this->TestResult.Status = cmCTestTestHandler::INTERRUPT;
 209         break;
 210       case cmProcess::Exception::Numerical:
 211         outputStream << "Numerical";
 212         this->TestResult.Status = cmCTestTestHandler::NUMERICAL;
 213         break;
 214       default:
 215         cmCTestLog(this->CTest, HANDLER_OUTPUT,
 216                    this->TestResult.ExceptionStatus);
 217         this->TestResult.Status = cmCTestTestHandler::OTHER_FAULT;
 218     }
 219   } else if ("Disabled" == this->TestResult.CompletionStatus) {
 220     outputStream << "***Not Run (Disabled) ";
 221   } else // cmProcess::State::Error
 222   {
 223     outputStream << "***Not Run ";
 224   }
 225
 226   passed = this->TestResult.Status == cmCTestTestHandler::COMPLETED;
 227   char buf[1024];
 228   snprintf(buf, sizeof(buf), "%6.2f sec",
 229            this->TestProcess->GetTotalTime().count());
 230   outputStream << buf << "\n";
 231
 232   bool passedOrSkipped = passed || skipped;
 233   if (this->CTest->GetTestProgressOutput()) {
 234     if (!passedOrSkipped) {
 235       // If the test did not pass, reprint test name and error
 236       std::string output = this->GetTestPrefix(completed, total);
 237       std::string testName = this->TestProperties->Name;
 238       const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
 239       testName.resize(maxTestNameWidth + 4, '.');
 240
 241       output += testName;
 242       output += outputStream.str();
 243       outputStream.str("");
 244       outputStream.clear();
 245       outputStream << output;
 246       cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, "\n"); // flush
 247     }
 248     if (completed == total) {
 249       std::string testName = this->GetTestPrefix(completed, total) +
 250         this->TestProperties->Name + "\n";
 251       cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, testName);
 252     }
 253   }
 254   if (!this->CTest->GetTestProgressOutput() || !passedOrSkipped) {
 255     cmCTestLog(this->CTest, HANDLER_OUTPUT, outputStream.str());
 256   }
 257
 258   if (outputTestErrorsToConsole) {
 259     cmCTestLog(this->CTest, HANDLER_OUTPUT, this->ProcessOutput << std::endl);
 260   }
 261
 262   if (this->TestHandler->LogFile) {
 263     *this->TestHandler->LogFile << "Test time = " << buf << std::endl;
 264   }
 265
 266   this->ParseOutputForMeasurements();
 267
 268   // if this is doing MemCheck then all the output needs to be put into
 269   // Output since that is what is parsed by cmCTestMemCheckHandler
 270   if (!this->TestHandler->MemCheck && started) {
 271     this->TestHandler->CleanTestOutput(
 272       this->ProcessOutput,
 273       static_cast<size_t>(
 274         this->TestResult.Status == cmCTestTestHandler::COMPLETED
 275           ? this->TestHandler->CustomMaximumPassedTestOutputSize
 276           : this->TestHandler->CustomMaximumFailedTestOutputSize),
 277       this->TestHandler->TestOutputTruncation);
 278   }
 279   this->TestResult.Reason = reason;
 280   if (this->TestHandler->LogFile) {
 281     bool pass = true;
 282     const char* reasonType = "Test Pass Reason";
 283     if (this->TestResult.Status != cmCTestTestHandler::COMPLETED &&
 284         this->TestResult.Status != cmCTestTestHandler::NOT_RUN) {
 285       reasonType = "Test Fail Reason";
 286       pass = false;
 287     }
 288     auto ttime = this->TestProcess->GetTotalTime();
 289     auto hours = std::chrono::duration_cast<std::chrono::hours>(ttime);
 290     ttime -= hours;
 291     auto minutes = std::chrono::duration_cast<std::chrono::minutes>(ttime);
 292     ttime -= minutes;
 293     auto seconds = std::chrono::duration_cast<std::chrono::seconds>(ttime);
 294     char buffer[100];
 295     snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d",
 296              static_cast<unsigned>(hours.count()),
 297              static_cast<unsigned>(minutes.count()),
 298              static_cast<unsigned>(seconds.count()));
 299     *this->TestHandler->LogFile
 300       << "----------------------------------------------------------"
 301       << std::endl;
 302     if (!this->TestResult.Reason.empty()) {
 303       *this->TestHandler->LogFile << reasonType << ":\n"
 304                                   << this->TestResult.Reason << "\n";
 305     } else {
 306       if (pass) {
 307         *this->TestHandler->LogFile << "Test Passed.\n";
 308       } else {
 309         *this->TestHandler->LogFile << "Test Failed.\n";
 310       }
 311     }
 312     *this->TestHandler->LogFile
 313       << "\"" << this->TestProperties->Name
 314       << "\" end time: " << this->CTest->CurrentTime() << std::endl
 315       << "\"" << this->TestProperties->Name << "\" time elapsed: " << buffer
 316       << std::endl
 317       << "----------------------------------------------------------"
 318       << std::endl
 319       << std::endl;
 320   }
 321   // if the test actually started and ran
 322   // record the results in TestResult
 323   if (started) {
 324     std::string compressedOutput;
 325     if (!this->TestHandler->MemCheck &&
 326         this->CTest->ShouldCompressTestOutput()) {
 327       std::string str = this->ProcessOutput;
 328       if (this->CTest->CompressString(str)) {
 329         compressedOutput = std::move(str);
 330       }
 331     }
 332     bool compress = !compressedOutput.empty() &&
 333       compressedOutput.length() < this->ProcessOutput.length();
 334     this->TestResult.Output =
 335       compress ? compressedOutput : this->ProcessOutput;
 336     this->TestResult.CompressOutput = compress;
 337     this->TestResult.ReturnValue = this->TestProcess->GetExitValue();
 338     if (!skipped) {
 339       this->TestResult.CompletionStatus = "Completed";
 340     }
 341     this->TestResult.ExecutionTime = this->TestProcess->GetTotalTime();
 342     this->MemCheckPostProcess();
 343     this->ComputeWeightedCost();
 344   }
 345   // If the test does not need to rerun push the current TestResult onto the
 346   // TestHandler vector
 347   if (!this->NeedsToRepeat()) {
 348     this->TestHandler->TestResults.push_back(this->TestResult);
 349   }
 350   this->TestProcess.reset();
 351   return passed || skipped;
 352 }
 353
 354 bool cmCTestRunTest::StartAgain(std::unique_ptr<cmCTestRunTest> runner,
 355                                 size_t completed)
 356 {
 357   auto* testRun = runner.get();
 358
 359   if (!testRun->RunAgain) {
 360     return false;
 361   }
 362   testRun->RunAgain = false; // reset
 363   testRun->TestProcess = cm::make_unique<cmProcess>(std::move(runner));
 364   // change to tests directory
 365   cmWorkingDirectory workdir(testRun->TestProperties->Directory);
 366   if (workdir.Failed()) {
 367     testRun->StartFailure("Failed to change working directory to " +
 368                             testRun->TestProperties->Directory + " : " +
 369                             std::strerror(workdir.GetLastResult()),
 370                           "Failed to change working directory");
 371     return true;
 372   }
 373
 374   testRun->StartTest(completed, testRun->TotalNumberOfTests);
 375   return true;
 376 }
 377
 378 bool cmCTestRunTest::NeedsToRepeat()
 379 {
 380   this->NumberOfRunsLeft--;
 381   if (this->NumberOfRunsLeft == 0) {
 382     return false;
 383   }
 384   // If a test is marked as NOT_RUN it will not be repeated
 385   // no matter the repeat settings, so just record it as-is.
 386   if (this->TestResult.Status == cmCTestTestHandler::NOT_RUN) {
 387     return false;
 388   }
 389   // if number of runs left is not 0, and we are running until
 390   // we find a failed (or passed) test, then return true so the test can be
 391   // restarted
 392   if ((this->RepeatMode == cmCTest::Repeat::UntilFail &&
 393        this->TestResult.Status == cmCTestTestHandler::COMPLETED) ||
 394       (this->RepeatMode == cmCTest::Repeat::UntilPass &&
 395        this->TestResult.Status != cmCTestTestHandler::COMPLETED) ||
 396       (this->RepeatMode == cmCTest::Repeat::AfterTimeout &&
 397        this->TestResult.Status == cmCTestTestHandler::TIMEOUT)) {
 398     this->RunAgain = true;
 399     return true;
 400   }
 401   return false;
 402 }
 403 void cmCTestRunTest::ComputeWeightedCost()
 404 {
 405   double prev = static_cast<double>(this->TestProperties->PreviousRuns);
 406   double avgcost = static_cast<double>(this->TestProperties->Cost);
 407   double current = this->TestResult.ExecutionTime.count();
 408
 409   if (this->TestResult.Status == cmCTestTestHandler::COMPLETED) {
 410     this->TestProperties->Cost =
 411       static_cast<float>(((prev * avgcost) + current) / (prev + 1.0));
 412     this->TestProperties->PreviousRuns++;
 413   }
 414 }
 415
 416 void cmCTestRunTest::MemCheckPostProcess()
 417 {
 418   if (!this->TestHandler->MemCheck) {
 419     return;
 420   }
 421   cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 422                      this->Index << ": process test output now: "
 423                                  << this->TestProperties->Name << " "
 424                                  << this->TestResult.Name << std::endl,
 425                      this->TestHandler->GetQuiet());
 426   cmCTestMemCheckHandler* handler =
 427     static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
 428   handler->PostProcessTest(this->TestResult, this->Index);
 429 }
 430
 431 void cmCTestRunTest::StartFailure(std::unique_ptr<cmCTestRunTest> runner,
 432                                   std::string const& output,
 433                                   std::string const& detail)
 434 {
 435   auto* testRun = runner.get();
 436
 437   testRun->TestProcess = cm::make_unique<cmProcess>(std::move(runner));
 438   testRun->StartFailure(output, detail);
 439
 440   testRun->FinalizeTest(false);
 441 }
 442
 443 void cmCTestRunTest::StartFailure(std::string const& output,
 444                                   std::string const& detail)
 445 {
 446   // Still need to log the Start message so the test summary records our
 447   // attempt to start this test
 448   if (!this->CTest->GetTestProgressOutput()) {
 449     cmCTestLog(this->CTest, HANDLER_OUTPUT,
 450                std::setw(2 * getNumWidth(this->TotalNumberOfTests) + 8)
 451                  << "Start "
 452                  << std::setw(getNumWidth(this->TestHandler->GetMaxIndex()))
 453                  << this->TestProperties->Index << ": "
 454                  << this->TestProperties->Name << std::endl);
 455   }
 456
 457   this->ProcessOutput.clear();
 458   if (!output.empty()) {
 459     *this->TestHandler->LogFile << output << std::endl;
 460     cmCTestLog(this->CTest, ERROR_MESSAGE, output << std::endl);
 461   }
 462
 463   this->TestResult.Properties = this->TestProperties;
 464   this->TestResult.ExecutionTime = cmDuration::zero();
 465   this->TestResult.CompressOutput = false;
 466   this->TestResult.ReturnValue = -1;
 467   this->TestResult.CompletionStatus = detail;
 468   this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 469   this->TestResult.TestCount = this->TestProperties->Index;
 470   this->TestResult.Name = this->TestProperties->Name;
 471   this->TestResult.Path = this->TestProperties->Directory;
 472   this->TestResult.Output = output;
 473   this->TestResult.FullCommandLine.clear();
 474   this->TestResult.Environment.clear();
 475 }
 476
 477 std::string cmCTestRunTest::GetTestPrefix(size_t completed, size_t total) const
 478 {
 479   std::ostringstream outputStream;
 480   outputStream << std::setw(getNumWidth(total)) << completed << "/";
 481   outputStream << std::setw(getNumWidth(total)) << total << " ";
 482
 483   if (this->TestHandler->MemCheck) {
 484     outputStream << "MemCheck";
 485   } else {
 486     outputStream << "Test";
 487   }
 488
 489   std::ostringstream indexStr;
 490   indexStr << " #" << this->Index << ":";
 491   outputStream << std::setw(3 + getNumWidth(this->TestHandler->GetMaxIndex()))
 492                << indexStr.str();
 493   outputStream << " ";
 494
 495   return outputStream.str();
 496 }
 497
 498 bool cmCTestRunTest::StartTest(std::unique_ptr<cmCTestRunTest> runner,
 499                                size_t completed, size_t total)
 500 {
 501   auto* testRun = runner.get();
 502
 503   testRun->TestProcess = cm::make_unique<cmProcess>(std::move(runner));
 504
 505   if (!testRun->StartTest(completed, total)) {
 506     testRun->FinalizeTest(false);
 507     return false;
 508   }
 509
 510   return true;
 511 }
 512
 513 // Starts the execution of a test.  Returns once it has started
 514 bool cmCTestRunTest::StartTest(size_t completed, size_t total)
 515 {
 516   this->TotalNumberOfTests = total; // save for rerun case
 517   if (!this->CTest->GetTestProgressOutput()) {
 518     cmCTestLog(this->CTest, HANDLER_OUTPUT,
 519                std::setw(2 * getNumWidth(total) + 8)
 520                  << "Start "
 521                  << std::setw(getNumWidth(this->TestHandler->GetMaxIndex()))
 522                  << this->TestProperties->Index << ": "
 523                  << this->TestProperties->Name << std::endl);
 524   } else {
 525     std::string testName = this->GetTestPrefix(completed, total) +
 526       this->TestProperties->Name + "\n";
 527     cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, testName);
 528   }
 529
 530   this->ProcessOutput.clear();
 531
 532   this->TestResult.Properties = this->TestProperties;
 533   this->TestResult.ExecutionTime = cmDuration::zero();
 534   this->TestResult.CompressOutput = false;
 535   this->TestResult.ReturnValue = -1;
 536   this->TestResult.TestCount = this->TestProperties->Index;
 537   this->TestResult.Name = this->TestProperties->Name;
 538   this->TestResult.Path = this->TestProperties->Directory;
 539
 540   // Return immediately if test is disabled
 541   if (this->TestProperties->Disabled) {
 542     this->TestResult.CompletionStatus = "Disabled";
 543     this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 544     this->TestResult.Output = "Disabled";
 545     this->TestResult.FullCommandLine.clear();
 546     this->TestResult.Environment.clear();
 547     return false;
 548   }
 549
 550   this->TestResult.CompletionStatus = "Failed to start";
 551   this->TestResult.Status = cmCTestTestHandler::BAD_COMMAND;
 552
 553   // Check for failed fixture dependencies before we even look at the command
 554   // arguments because if we are not going to run the test, the command and
 555   // its arguments are irrelevant. This matters for the case where a fixture
 556   // dependency might be creating the executable we want to run.
 557   if (!this->FailedDependencies.empty()) {
 558     std::string msg = "Failed test dependencies:";
 559     for (std::string const& failedDep : this->FailedDependencies) {
 560       msg += " " + failedDep;
 561     }
 562     *this->TestHandler->LogFile << msg << std::endl;
 563     cmCTestLog(this->CTest, HANDLER_OUTPUT, msg << std::endl);
 564     this->TestResult.Output = msg;
 565     this->TestResult.FullCommandLine.clear();
 566     this->TestResult.Environment.clear();
 567     this->TestResult.CompletionStatus = "Fixture dependency failed";
 568     this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 569     return false;
 570   }
 571
 572   this->ComputeArguments();
 573   std::vector<std::string>& args = this->TestProperties->Args;
 574   if (args.size() >= 2 && args[1] == "NOT_AVAILABLE") {
 575     std::string msg;
 576     if (this->CTest->GetConfigType().empty()) {
 577       msg = "Test not available without configuration.  (Missing \"-C "
 578             "<config>\"?)";
 579     } else {
 580       msg = cmStrCat("Test not available in configuration \"",
 581                      this->CTest->GetConfigType(), "\".");
 582     }
 583     *this->TestHandler->LogFile << msg << std::endl;
 584     cmCTestLog(this->CTest, ERROR_MESSAGE, msg << std::endl);
 585     this->TestResult.Output = msg;
 586     this->TestResult.FullCommandLine.clear();
 587     this->TestResult.Environment.clear();
 588     this->TestResult.CompletionStatus = "Missing Configuration";
 589     this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 590     return false;
 591   }
 592
 593   // Check if all required files exist
 594   for (std::string const& file : this->TestProperties->RequiredFiles) {
 595     if (!cmSystemTools::FileExists(file)) {
 596       // Required file was not found
 597       *this->TestHandler->LogFile << "Unable to find required file: " << file
 598                                   << std::endl;
 599       cmCTestLog(this->CTest, ERROR_MESSAGE,
 600                  "Unable to find required file: " << file << std::endl);
 601       this->TestResult.Output = "Unable to find required file: " + file;
 602       this->TestResult.FullCommandLine.clear();
 603       this->TestResult.Environment.clear();
 604       this->TestResult.CompletionStatus = "Required Files Missing";
 605       this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 606       return false;
 607     }
 608   }
 609   // log and return if we did not find the executable
 610   if (this->ActualCommand.empty()) {
 611     // if the command was not found create a TestResult object
 612     // that has that information
 613     *this->TestHandler->LogFile << "Unable to find executable: " << args[1]
 614                                 << std::endl;
 615     cmCTestLog(this->CTest, ERROR_MESSAGE,
 616                "Unable to find executable: " << args[1] << std::endl);
 617     this->TestResult.Output = "Unable to find executable: " + args[1];
 618     this->TestResult.FullCommandLine.clear();
 619     this->TestResult.Environment.clear();
 620     this->TestResult.CompletionStatus = "Unable to find executable";
 621     this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
 622     return false;
 623   }
 624   this->StartTime = this->CTest->CurrentTime();
 625
 626   auto timeout = this->TestProperties->Timeout;
 627
 628   this->TimeoutIsForStopTime = false;
 629   std::chrono::system_clock::time_point stop_time = this->CTest->GetStopTime();
 630   if (stop_time != std::chrono::system_clock::time_point()) {
 631     std::chrono::duration<double> stop_timeout =
 632       (stop_time - std::chrono::system_clock::now()) % std::chrono::hours(24);
 633
 634     if (stop_timeout <= std::chrono::duration<double>::zero()) {
 635       stop_timeout = std::chrono::duration<double>::zero();
 636     }
 637     if (timeout == std::chrono::duration<double>::zero() ||
 638         stop_timeout < timeout) {
 639       this->TimeoutIsForStopTime = true;
 640       timeout = stop_timeout;
 641     }
 642   }
 643
 644   return this->ForkProcess(timeout, this->TestProperties->ExplicitTimeout,
 645                            &this->TestProperties->Environment,
 646                            &this->TestProperties->EnvironmentModification,
 647                            &this->TestProperties->Affinity);
 648 }
 649
 650 void cmCTestRunTest::ComputeArguments()
 651 {
 652   this->Arguments.clear(); // reset because this might be a rerun
 653   auto j = this->TestProperties->Args.begin();
 654   ++j; // skip test name
 655   // find the test executable
 656   if (this->TestHandler->MemCheck) {
 657     cmCTestMemCheckHandler* handler =
 658       static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
 659     this->ActualCommand = handler->MemoryTester;
 660     this->TestProperties->Args[1] =
 661       this->TestHandler->FindTheExecutable(this->TestProperties->Args[1]);
 662   } else {
 663     this->ActualCommand =
 664       this->TestHandler->FindTheExecutable(this->TestProperties->Args[1]);
 665     ++j; // skip the executable (it will be actualCommand)
 666   }
 667   std::string testCommand =
 668     cmSystemTools::ConvertToOutputPath(this->ActualCommand);
 669
 670   // Prepends memcheck args to our command string
 671   this->TestHandler->GenerateTestCommand(this->Arguments, this->Index);
 672   for (std::string const& arg : this->Arguments) {
 673     testCommand += " \"";
 674     testCommand += arg;
 675     testCommand += "\"";
 676   }
 677
 678   for (; j != this->TestProperties->Args.end(); ++j) {
 679     testCommand += " \"";
 680     testCommand += *j;
 681     testCommand += "\"";
 682     this->Arguments.push_back(*j);
 683   }
 684   this->TestResult.FullCommandLine = testCommand;
 685
 686   // Print the test command in verbose mode
 687   cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 688              std::endl
 689                << this->Index << ": "
 690                << (this->TestHandler->MemCheck ? "MemCheck" : "Test")
 691                << " command: " << testCommand << std::endl);
 692
 693   // Print any test-specific env vars in verbose mode
 694   if (!this->TestProperties->Directory.empty()) {
 695     cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 696                this->Index << ": "
 697                            << "Working Directory: "
 698                            << this->TestProperties->Directory << std::endl);
 699   }
 700
 701   // Print any test-specific env vars in verbose mode
 702   if (!this->TestProperties->Environment.empty()) {
 703     cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 704                this->Index << ": "
 705                            << "Environment variables: " << std::endl);
 706   }
 707   for (std::string const& env : this->TestProperties->Environment) {
 708     cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 709                this->Index << ":  " << env << std::endl);
 710   }
 711   if (!this->TestProperties->EnvironmentModification.empty()) {
 712     cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 713                this->Index << ": "
 714                            << "Environment variable modifications: "
 715                            << std::endl);
 716   }
 717   for (std::string const& envmod :
 718        this->TestProperties->EnvironmentModification) {
 719     cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 720                this->Index << ":  " << envmod << std::endl);
 721   }
 722 }
 723
 724 void cmCTestRunTest::ParseOutputForMeasurements()
 725 {
 726   if (!this->ProcessOutput.empty() &&
 727       (this->ProcessOutput.find("<DartMeasurement") != std::string::npos ||
 728        this->ProcessOutput.find("<CTestMeasurement") != std::string::npos)) {
 729     if (this->TestHandler->AllTestMeasurementsRegex.find(
 730           this->ProcessOutput)) {
 731       this->TestResult.TestMeasurementsOutput =
 732         this->TestHandler->AllTestMeasurementsRegex.match(1);
 733       // keep searching and replacing until none are left
 734       while (this->TestHandler->SingleTestMeasurementRegex.find(
 735         this->ProcessOutput)) {
 736         // replace the exact match for the string
 737         cmSystemTools::ReplaceString(
 738           this->ProcessOutput,
 739           this->TestHandler->SingleTestMeasurementRegex.match(1).c_str(), "");
 740       }
 741     }
 742   }
 743 }
 744
 745 bool cmCTestRunTest::ForkProcess(
 746   cmDuration testTimeOut, bool explicitTimeout,
 747   std::vector<std::string>* environment,
 748   std::vector<std::string>* environment_modification,
 749   std::vector<size_t>* affinity)
 750 {
 751   this->TestProcess->SetId(this->Index);
 752   this->TestProcess->SetWorkingDirectory(this->TestProperties->Directory);
 753   this->TestProcess->SetCommand(this->ActualCommand);
 754   this->TestProcess->SetCommandArguments(this->Arguments);
 755
 756   // determine how much time we have
 757   cmDuration timeout = this->CTest->GetRemainingTimeAllowed();
 758   if (timeout != cmCTest::MaxDuration()) {
 759     timeout -= std::chrono::minutes(2);
 760   }
 761   if (this->CTest->GetTimeOut() > cmDuration::zero() &&
 762       this->CTest->GetTimeOut() < timeout) {
 763     timeout = this->CTest->GetTimeOut();
 764   }
 765   if (testTimeOut > cmDuration::zero() &&
 766       testTimeOut < this->CTest->GetRemainingTimeAllowed()) {
 767     timeout = testTimeOut;
 768   }
 769   // always have at least 1 second if we got to here
 770   if (timeout <= cmDuration::zero()) {
 771     timeout = std::chrono::seconds(1);
 772   }
 773   // handle timeout explicitly set to 0
 774   if (testTimeOut == cmDuration::zero() && explicitTimeout) {
 775     timeout = cmDuration::zero();
 776   }
 777   cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
 778                      this->Index << ": "
 779                                  << "Test timeout computed to be: "
 780                                  << cmDurationTo<unsigned int>(timeout)
 781                                  << "\n",
 782                      this->TestHandler->GetQuiet());
 783
 784   this->TestProcess->SetTimeout(timeout);
 785
 786   cmSystemTools::SaveRestoreEnvironment sre;
 787   std::ostringstream envMeasurement;
 788
 789   // We split processing ENVIRONMENT and ENVIRONMENT_MODIFICATION into two
 790   // phases to ensure that MYVAR=reset: in the latter phase resets to the
 791   // former phase's settings, rather than to the original environment.
 792   if (environment && !environment->empty()) {
 793     cmSystemTools::EnvDiff diff;
 794     diff.AppendEnv(*environment);
 795     diff.ApplyToCurrentEnv(&envMeasurement);
 796   }
 797
 798   if (environment_modification && !environment_modification->empty()) {
 799     cmSystemTools::EnvDiff diff;
 800     bool env_ok = true;
 801
 802     for (auto const& envmod : *environment_modification) {
 803       env_ok &= diff.ParseOperation(envmod);
 804     }
 805
 806     if (!env_ok) {
 807       return false;
 808     }
 809
 810     diff.ApplyToCurrentEnv(&envMeasurement);
 811   }
 812
 813   if (this->UseAllocatedResources) {
 814     std::vector<std::string> envLog;
 815     this->SetupResourcesEnvironment(&envLog);
 816     for (auto const& var : envLog) {
 817       envMeasurement << var << std::endl;
 818     }
 819   } else {
 820     cmSystemTools::UnsetEnv("CTEST_RESOURCE_GROUP_COUNT");
 821     // Signify that this variable is being actively unset
 822     envMeasurement << "#CTEST_RESOURCE_GROUP_COUNT=" << std::endl;
 823   }
 824
 825   this->TestResult.Environment = envMeasurement.str();
 826   // Remove last newline
 827   this->TestResult.Environment.erase(this->TestResult.Environment.length() -
 828                                      1);
 829
 830   return this->TestProcess->StartProcess(this->MultiTestHandler.Loop,
 831                                          affinity);
 832 }
 833
 834 void cmCTestRunTest::SetupResourcesEnvironment(std::vector<std::string>* log)
 835 {
 836   std::string processCount = "CTEST_RESOURCE_GROUP_COUNT=";
 837   processCount += std::to_string(this->AllocatedResources.size());
 838   cmSystemTools::PutEnv(processCount);
 839   if (log) {
 840     log->push_back(processCount);
 841   }
 842
 843   std::size_t i = 0;
 844   for (auto const& process : this->AllocatedResources) {
 845     std::string prefix = "CTEST_RESOURCE_GROUP_";
 846     prefix += std::to_string(i);
 847     std::string resourceList = prefix + '=';
 848     prefix += '_';
 849     bool firstType = true;
 850     for (auto const& it : process) {
 851       if (!firstType) {
 852         resourceList += ',';
 853       }
 854       firstType = false;
 855       auto resourceType = it.first;
 856       resourceList += resourceType;
 857       std::string var = prefix + cmSystemTools::UpperCase(resourceType) + '=';
 858       bool firstName = true;
 859       for (auto const& it2 : it.second) {
 860         if (!firstName) {
 861           var += ';';
 862         }
 863         firstName = false;
 864         var += "id:" + it2.Id + ",slots:" + std::to_string(it2.Slots);
 865       }
 866       cmSystemTools::PutEnv(var);
 867       if (log) {
 868         log->push_back(var);
 869       }
 870     }
 871     cmSystemTools::PutEnv(resourceList);
 872     if (log) {
 873       log->push_back(resourceList);
 874     }
 875     ++i;
 876   }
 877 }
 878
 879 void cmCTestRunTest::WriteLogOutputTop(size_t completed, size_t total)
 880 {
 881   std::ostringstream outputStream;
 882
 883   // If this is the last or only run of this test, or progress output is
 884   // requested, then print out completed / total.
 885   // Only issue is if a test fails and we are running until fail
 886   // then it will never print out the completed / total, same would
 887   // got for run until pass.  Trick is when this is called we don't
 888   // yet know if we are passing or failing.
 889   bool const progressOnLast =
 890     (this->RepeatMode != cmCTest::Repeat::UntilPass &&
 891      this->RepeatMode != cmCTest::Repeat::AfterTimeout);
 892   if ((progressOnLast && this->NumberOfRunsLeft == 1) ||
 893       (!progressOnLast && this->NumberOfRunsLeft == this->NumberOfRunsTotal) ||
 894       this->CTest->GetTestProgressOutput()) {
 895     outputStream << std::setw(getNumWidth(total)) << completed << "/";
 896     outputStream << std::setw(getNumWidth(total)) << total << " ";
 897   }
 898   // if this is one of several runs of a test just print blank space
 899   // to keep things neat
 900   else {
 901     outputStream << std::setw(getNumWidth(total)) << "  ";
 902     outputStream << std::setw(getNumWidth(total)) << "  ";
 903   }
 904
 905   if (this->TestHandler->MemCheck) {
 906     outputStream << "MemCheck";
 907   } else {
 908     outputStream << "Test";
 909   }
 910
 911   std::ostringstream indexStr;
 912   indexStr << " #" << this->Index << ":";
 913   outputStream << std::setw(3 + getNumWidth(this->TestHandler->GetMaxIndex()))
 914                << indexStr.str();
 915   outputStream << " ";
 916
 917   const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
 918   std::string outname = this->TestProperties->Name + " ";
 919   outname.resize(maxTestNameWidth + 4, '.');
 920   outputStream << outname;
 921
 922   *this->TestHandler->LogFile << this->TestProperties->Index << "/"
 923                               << this->TestHandler->TotalNumberOfTests
 924                               << " Testing: " << this->TestProperties->Name
 925                               << std::endl;
 926   *this->TestHandler->LogFile << this->TestProperties->Index << "/"
 927                               << this->TestHandler->TotalNumberOfTests
 928                               << " Test: " << this->TestProperties->Name
 929                               << std::endl;
 930   *this->TestHandler->LogFile << "Command: \"" << this->ActualCommand << "\"";
 931
 932   for (std::string const& arg : this->Arguments) {
 933     *this->TestHandler->LogFile << " \"" << arg << "\"";
 934   }
 935   *this->TestHandler->LogFile
 936     << std::endl
 937     << "Directory: " << this->TestProperties->Directory << std::endl
 938     << "\"" << this->TestProperties->Name
 939     << "\" start time: " << this->StartTime << std::endl;
 940
 941   *this->TestHandler->LogFile
 942     << "Output:" << std::endl
 943     << "----------------------------------------------------------"
 944     << std::endl;
 945   *this->TestHandler->LogFile << this->ProcessOutput << "<end of output>"
 946                               << std::endl;
 947
 948   if (!this->CTest->GetTestProgressOutput()) {
 949     cmCTestLog(this->CTest, HANDLER_OUTPUT, outputStream.str());
 950   }
 951
 952   cmCTestLog(this->CTest, DEBUG,
 953              "Testing " << this->TestProperties->Name << " ... ");
 954 }
 955
 956 void cmCTestRunTest::FinalizeTest(bool started)
 957 {
 958   this->MultiTestHandler.FinishTestProcess(this->TestProcess->GetRunner(),
 959                                            started);
 960 }