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