cmCTestRunTest.cxx 35 KB

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