cmCTestRunTest.cxx 37 KB

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