cmCTestRunTest.cxx 39 KB

1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859606162636465666768697071727374757677787980818283848586878889909192939495969798991001011021031041051061071081091101111121131141151161171181191201211221231241251261271281291301311321331341351361371381391401411421431441451461471481491501511521531541551561571581591601611621631641651661671681691701711721731741751761771781791801811821831841851861871881891901911921931941951961971981992002012022032042052062072082092102112122132142152162172182192202212222232242252262272282292302312322332342352362372382392402412422432442452462472482492502512522532542552562572582592602612622632642652662672682692702712722732742752762772782792802812822832842852862872882892902912922932942952962972982993003013023033043053063073083093103113123133143153163173183193203213223233243253263273283293303313323333343353363373383393403413423433443453463473483493503513523533543553563573583593603613623633643653663673683693703713723733743753763773783793803813823833843853863873883893903913923933943953963973983994004014024034044054064074084094104114124134144154164174184194204214224234244254264274284294304314324334344354364374384394404414424434444454464474484494504514524534544554564574584594604614624634644654664674684694704714724734744754764774784794804814824834844854864874884894904914924934944954964974984995005015025035045055065075085095105115125135145155165175185195205215225235245255265275285295305315325335345355365375385395405415425435445455465475485495505515525535545555565575585595605615625635645655665675685695705715725735745755765775785795805815825835845855865875885895905915925935945955965975985996006016026036046056066076086096106116126136146156166176186196206216226236246256266276286296306316326336346356366376386396406416426436446456466476486496506516526536546556566576586596606616626636646656666676686696706716726736746756766776786796806816826836846856866876886896906916926936946956966976986997007017027037047057067077087097107117127137147157167177187197207217227237247257267277287297307317327337347357367377387397407417427437447457467477487497507517527537547557567577587597607617627637647657667677687697707717727737747757767777787797807817827837847857867877887897907917927937947957967977987998008018028038048058068078088098108118128138148158168178188198208218228238248258268278288298308318328338348358368378388398408418428438448458468478488498508518528538548558568578588598608618628638648658668678688698708718728738748758768778788798808818828838848858868878888898908918928938948958968978988999009019029039049059069079089099109119129139149159169179189199209219229239249259269279289299309319329339349359369379389399409419429439449459469479489499509519529539549559569579589599609619629639649659669679689699709719729739749759769779789799809819829839849859869879889899909919929939949959969979989991000100110021003100410051006100710081009101010111012101310141015101610171018101910201021102210231024102510261027102810291030103110321033103410351036103710381039104010411042104310441045104610471048104910501051105210531054105510561057105810591060106110621063106410651066106710681069107010711072107310741075107610771078107910801081
  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 <functional>
  11. #include <iomanip>
  12. #include <ratio>
  13. #include <sstream>
  14. #include <utility>
  15. #include <cm/memory>
  16. #include <cm/optional>
  17. #include <cm/string_view>
  18. #include <cmext/string_view>
  19. #include "cmsys/RegularExpression.hxx"
  20. #include "cmCTest.h"
  21. #include "cmCTestMemCheckHandler.h"
  22. #include "cmCTestMultiProcessHandler.h"
  23. #include "cmProcess.h"
  24. #include "cmStringAlgorithms.h"
  25. #include "cmSystemTools.h"
  26. #include "cmWorkingDirectory.h"
  27. cmCTestRunTest::cmCTestRunTest(cmCTestMultiProcessHandler& multiHandler)
  28. : MultiTestHandler(multiHandler)
  29. {
  30. this->CTest = multiHandler.CTest;
  31. this->TestHandler = multiHandler.TestHandler;
  32. this->TestResult.ExecutionTime = cmDuration::zero();
  33. this->TestResult.ReturnValue = 0;
  34. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  35. this->TestResult.TestCount = 0;
  36. this->TestResult.Properties = nullptr;
  37. }
  38. void cmCTestRunTest::CheckOutput(std::string const& line)
  39. {
  40. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  41. this->GetIndex() << ": " << line << std::endl);
  42. // Check for special CTest XML tags in this line of output.
  43. // If any are found, this line is excluded from ProcessOutput.
  44. if (!line.empty() && line.find("<CTest") != std::string::npos) {
  45. bool ctest_tag_found = false;
  46. if (this->TestHandler->CustomCompletionStatusRegex.find(line)) {
  47. ctest_tag_found = true;
  48. this->TestResult.CustomCompletionStatus =
  49. this->TestHandler->CustomCompletionStatusRegex.match(1);
  50. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  51. this->GetIndex() << ": "
  52. << "Test Details changed to '"
  53. << this->TestResult.CustomCompletionStatus
  54. << "'" << std::endl);
  55. } else if (this->TestHandler->CustomLabelRegex.find(line)) {
  56. ctest_tag_found = true;
  57. auto label = this->TestHandler->CustomLabelRegex.match(1);
  58. auto& labels = this->TestProperties->Labels;
  59. if (std::find(labels.begin(), labels.end(), label) == labels.end()) {
  60. labels.push_back(label);
  61. std::sort(labels.begin(), labels.end());
  62. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  63. this->GetIndex()
  64. << ": "
  65. << "Test Label added: '" << label << "'" << std::endl);
  66. }
  67. }
  68. if (ctest_tag_found) {
  69. return;
  70. }
  71. }
  72. this->ProcessOutput += line;
  73. this->ProcessOutput += "\n";
  74. // Check for TIMEOUT_AFTER_MATCH property.
  75. if (!this->TestProperties->TimeoutRegularExpressions.empty()) {
  76. for (auto& reg : this->TestProperties->TimeoutRegularExpressions) {
  77. if (reg.first.find(this->ProcessOutput)) {
  78. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  79. this->GetIndex()
  80. << ": "
  81. << "Test timeout changed to "
  82. << std::chrono::duration_cast<std::chrono::seconds>(
  83. this->TestProperties->AlternateTimeout)
  84. .count()
  85. << std::endl);
  86. this->TestProcess->ResetStartTime();
  87. this->TestProcess->ChangeTimeout(
  88. this->TestProperties->AlternateTimeout);
  89. this->TestProperties->TimeoutRegularExpressions.clear();
  90. break;
  91. }
  92. }
  93. }
  94. }
  95. bool cmCTestRunTest::EndTest(size_t completed, size_t total, bool started)
  96. {
  97. this->WriteLogOutputTop(completed, total);
  98. std::string reason;
  99. bool passed = true;
  100. cmProcess::State res =
  101. started ? this->TestProcess->GetProcessStatus() : cmProcess::State::Error;
  102. if (res != cmProcess::State::Expired) {
  103. this->TimeoutIsForStopTime = false;
  104. }
  105. std::int64_t retVal = this->TestProcess->GetExitValue();
  106. bool forceFail = false;
  107. bool forceSkip = false;
  108. bool skipped = false;
  109. bool outputTestErrorsToConsole = false;
  110. if (!this->TestProperties->RequiredRegularExpressions.empty() &&
  111. this->FailedDependencies.empty()) {
  112. bool found = false;
  113. for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
  114. if (pass.first.find(this->ProcessOutput)) {
  115. found = true;
  116. reason = cmStrCat("Required regular expression found. Regex=[",
  117. pass.second, ']');
  118. break;
  119. }
  120. }
  121. if (!found) {
  122. reason = "Required regular expression not found. Regex=[";
  123. for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
  124. reason += pass.second;
  125. reason += "\n";
  126. }
  127. reason += "]";
  128. forceFail = true;
  129. }
  130. }
  131. if (!this->TestProperties->ErrorRegularExpressions.empty() &&
  132. this->FailedDependencies.empty()) {
  133. for (auto& fail : this->TestProperties->ErrorRegularExpressions) {
  134. if (fail.first.find(this->ProcessOutput)) {
  135. reason = cmStrCat("Error regular expression found in output. Regex=[",
  136. fail.second, ']');
  137. forceFail = true;
  138. break;
  139. }
  140. }
  141. }
  142. if (!this->TestProperties->SkipRegularExpressions.empty() &&
  143. this->FailedDependencies.empty()) {
  144. for (auto& skip : this->TestProperties->SkipRegularExpressions) {
  145. if (skip.first.find(this->ProcessOutput)) {
  146. reason = cmStrCat("Skip regular expression found in output. Regex=[",
  147. skip.second, ']');
  148. forceSkip = true;
  149. break;
  150. }
  151. }
  152. }
  153. std::ostringstream outputStream;
  154. if (res == cmProcess::State::Exited) {
  155. bool success = !forceFail &&
  156. (retVal == 0 ||
  157. !this->TestProperties->RequiredRegularExpressions.empty());
  158. if ((this->TestProperties->SkipReturnCode >= 0 &&
  159. this->TestProperties->SkipReturnCode == retVal) ||
  160. forceSkip) {
  161. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  162. std::ostringstream s;
  163. if (forceSkip) {
  164. s << "SKIP_REGULAR_EXPRESSION_MATCHED";
  165. } else {
  166. s << "SKIP_RETURN_CODE=" << this->TestProperties->SkipReturnCode;
  167. }
  168. this->TestResult.CompletionStatus = s.str();
  169. outputStream << "***Skipped ";
  170. skipped = true;
  171. } else if (success != this->TestProperties->WillFail) {
  172. this->TestResult.Status = cmCTestTestHandler::COMPLETED;
  173. outputStream << " Passed ";
  174. } else {
  175. this->TestResult.Status = cmCTestTestHandler::FAILED;
  176. outputStream << "***Failed " << reason;
  177. outputTestErrorsToConsole =
  178. this->CTest->GetOutputTestOutputOnTestFailure();
  179. }
  180. } else if (res == cmProcess::State::Expired) {
  181. outputStream << "***Timeout ";
  182. this->TestResult.Status = cmCTestTestHandler::TIMEOUT;
  183. outputTestErrorsToConsole =
  184. this->CTest->GetOutputTestOutputOnTestFailure();
  185. } else if (res == cmProcess::State::Exception) {
  186. outputTestErrorsToConsole =
  187. this->CTest->GetOutputTestOutputOnTestFailure();
  188. outputStream << "***Exception: ";
  189. this->TestResult.ExceptionStatus =
  190. this->TestProcess->GetExitExceptionString();
  191. switch (this->TestProcess->GetExitException()) {
  192. case cmProcess::Exception::Fault:
  193. outputStream << "SegFault";
  194. this->TestResult.Status = cmCTestTestHandler::SEGFAULT;
  195. break;
  196. case cmProcess::Exception::Illegal:
  197. outputStream << "Illegal";
  198. this->TestResult.Status = cmCTestTestHandler::ILLEGAL;
  199. break;
  200. case cmProcess::Exception::Interrupt:
  201. outputStream << "Interrupt";
  202. this->TestResult.Status = cmCTestTestHandler::INTERRUPT;
  203. break;
  204. case cmProcess::Exception::Numerical:
  205. outputStream << "Numerical";
  206. this->TestResult.Status = cmCTestTestHandler::NUMERICAL;
  207. break;
  208. default:
  209. cmCTestLog(this->CTest, HANDLER_OUTPUT,
  210. this->TestResult.ExceptionStatus);
  211. this->TestResult.Status = cmCTestTestHandler::OTHER_FAULT;
  212. }
  213. } else if ("Disabled" == this->TestResult.CompletionStatus) {
  214. outputStream << "***Not Run (Disabled) ";
  215. } else // cmProcess::State::Error
  216. {
  217. outputStream << "***Not Run ";
  218. }
  219. passed = this->TestResult.Status == cmCTestTestHandler::COMPLETED;
  220. char buf[1024];
  221. snprintf(buf, sizeof(buf), "%6.2f sec",
  222. this->TestProcess->GetTotalTime().count());
  223. outputStream << buf << "\n";
  224. bool passedOrSkipped = passed || skipped;
  225. if (this->CTest->GetTestProgressOutput()) {
  226. if (!passedOrSkipped) {
  227. // If the test did not pass, reprint test name and error
  228. std::string output = this->GetTestPrefix(completed, total);
  229. std::string testName = this->TestProperties->Name;
  230. const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
  231. testName.resize(maxTestNameWidth + 4, '.');
  232. output += testName;
  233. output += outputStream.str();
  234. outputStream.str("");
  235. outputStream.clear();
  236. outputStream << output;
  237. cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, "\n"); // flush
  238. }
  239. if (completed == total) {
  240. std::string testName = this->GetTestPrefix(completed, total) +
  241. this->TestProperties->Name + "\n";
  242. cmCTestLog(this->CTest, HANDLER_TEST_PROGRESS_OUTPUT, testName);
  243. }
  244. }
  245. if (!this->CTest->GetTestProgressOutput() || !passedOrSkipped) {
  246. cmCTestLog(this->CTest, HANDLER_OUTPUT, outputStream.str());
  247. }
  248. if (outputTestErrorsToConsole) {
  249. cmCTestLog(this->CTest, HANDLER_OUTPUT, this->ProcessOutput << std::endl);
  250. }
  251. if (this->TestHandler->LogFile) {
  252. *this->TestHandler->LogFile << "Test time = " << buf << std::endl;
  253. }
  254. this->ParseOutputForMeasurements();
  255. // if this is doing MemCheck then all the output needs to be put into
  256. // Output since that is what is parsed by cmCTestMemCheckHandler
  257. if (!this->TestHandler->MemCheck && started) {
  258. this->TestHandler->CleanTestOutput(
  259. this->ProcessOutput,
  260. static_cast<size_t>(
  261. this->TestResult.Status == cmCTestTestHandler::COMPLETED
  262. ? this->TestHandler->CustomMaximumPassedTestOutputSize
  263. : this->TestHandler->CustomMaximumFailedTestOutputSize));
  264. }
  265. this->TestResult.Reason = reason;
  266. if (this->TestHandler->LogFile) {
  267. bool pass = true;
  268. const char* reasonType = "Test Pass Reason";
  269. if (this->TestResult.Status != cmCTestTestHandler::COMPLETED &&
  270. this->TestResult.Status != cmCTestTestHandler::NOT_RUN) {
  271. reasonType = "Test Fail Reason";
  272. pass = false;
  273. }
  274. auto ttime = this->TestProcess->GetTotalTime();
  275. auto hours = std::chrono::duration_cast<std::chrono::hours>(ttime);
  276. ttime -= hours;
  277. auto minutes = std::chrono::duration_cast<std::chrono::minutes>(ttime);
  278. ttime -= minutes;
  279. auto seconds = std::chrono::duration_cast<std::chrono::seconds>(ttime);
  280. char buffer[100];
  281. snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d",
  282. static_cast<unsigned>(hours.count()),
  283. static_cast<unsigned>(minutes.count()),
  284. static_cast<unsigned>(seconds.count()));
  285. *this->TestHandler->LogFile
  286. << "----------------------------------------------------------"
  287. << std::endl;
  288. if (!this->TestResult.Reason.empty()) {
  289. *this->TestHandler->LogFile << reasonType << ":\n"
  290. << this->TestResult.Reason << "\n";
  291. } else {
  292. if (pass) {
  293. *this->TestHandler->LogFile << "Test Passed.\n";
  294. } else {
  295. *this->TestHandler->LogFile << "Test Failed.\n";
  296. }
  297. }
  298. *this->TestHandler->LogFile
  299. << "\"" << this->TestProperties->Name
  300. << "\" end time: " << this->CTest->CurrentTime() << std::endl
  301. << "\"" << this->TestProperties->Name << "\" time elapsed: " << buffer
  302. << std::endl
  303. << "----------------------------------------------------------"
  304. << std::endl
  305. << std::endl;
  306. }
  307. // if the test actually started and ran
  308. // record the results in TestResult
  309. if (started) {
  310. std::string compressedOutput;
  311. if (!this->TestHandler->MemCheck &&
  312. this->CTest->ShouldCompressTestOutput()) {
  313. std::string str = this->ProcessOutput;
  314. if (this->CTest->CompressString(str)) {
  315. compressedOutput = std::move(str);
  316. }
  317. }
  318. bool compress = !compressedOutput.empty() &&
  319. compressedOutput.length() < this->ProcessOutput.length();
  320. this->TestResult.Output =
  321. compress ? compressedOutput : this->ProcessOutput;
  322. this->TestResult.CompressOutput = compress;
  323. this->TestResult.ReturnValue = this->TestProcess->GetExitValue();
  324. if (!skipped) {
  325. this->TestResult.CompletionStatus = "Completed";
  326. }
  327. this->TestResult.ExecutionTime = this->TestProcess->GetTotalTime();
  328. this->MemCheckPostProcess();
  329. this->ComputeWeightedCost();
  330. }
  331. // If the test does not need to rerun push the current TestResult onto the
  332. // TestHandler vector
  333. if (!this->NeedsToRepeat()) {
  334. this->TestHandler->TestResults.push_back(this->TestResult);
  335. }
  336. this->TestProcess.reset();
  337. return passed || skipped;
  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. auto timeout = this->TestProperties->Timeout;
  584. this->TimeoutIsForStopTime = false;
  585. std::chrono::system_clock::time_point stop_time = this->CTest->GetStopTime();
  586. if (stop_time != std::chrono::system_clock::time_point()) {
  587. std::chrono::duration<double> stop_timeout =
  588. (stop_time - std::chrono::system_clock::now()) % std::chrono::hours(24);
  589. if (stop_timeout <= std::chrono::duration<double>::zero()) {
  590. stop_timeout = std::chrono::duration<double>::zero();
  591. }
  592. if (timeout == std::chrono::duration<double>::zero() ||
  593. stop_timeout < timeout) {
  594. this->TimeoutIsForStopTime = true;
  595. timeout = stop_timeout;
  596. }
  597. }
  598. return this->ForkProcess(timeout, this->TestProperties->ExplicitTimeout,
  599. &this->TestProperties->Environment,
  600. &this->TestProperties->EnvironmentModification,
  601. &this->TestProperties->Affinity);
  602. }
  603. void cmCTestRunTest::ComputeArguments()
  604. {
  605. this->Arguments.clear(); // reset because this might be a rerun
  606. auto j = this->TestProperties->Args.begin();
  607. ++j; // skip test name
  608. // find the test executable
  609. if (this->TestHandler->MemCheck) {
  610. cmCTestMemCheckHandler* handler =
  611. static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
  612. this->ActualCommand = handler->MemoryTester;
  613. this->TestProperties->Args[1] =
  614. this->TestHandler->FindTheExecutable(this->TestProperties->Args[1]);
  615. } else {
  616. this->ActualCommand =
  617. this->TestHandler->FindTheExecutable(this->TestProperties->Args[1]);
  618. ++j; // skip the executable (it will be actualCommand)
  619. }
  620. std::string testCommand =
  621. cmSystemTools::ConvertToOutputPath(this->ActualCommand);
  622. // Prepends memcheck args to our command string
  623. this->TestHandler->GenerateTestCommand(this->Arguments, this->Index);
  624. for (std::string const& arg : this->Arguments) {
  625. testCommand += " \"";
  626. testCommand += arg;
  627. testCommand += "\"";
  628. }
  629. for (; j != this->TestProperties->Args.end(); ++j) {
  630. testCommand += " \"";
  631. testCommand += *j;
  632. testCommand += "\"";
  633. this->Arguments.push_back(*j);
  634. }
  635. this->TestResult.FullCommandLine = testCommand;
  636. // Print the test command in verbose mode
  637. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  638. std::endl
  639. << this->Index << ": "
  640. << (this->TestHandler->MemCheck ? "MemCheck" : "Test")
  641. << " command: " << testCommand << std::endl);
  642. // Print any test-specific env vars in verbose mode
  643. if (!this->TestProperties->Directory.empty()) {
  644. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  645. this->Index << ": "
  646. << "Working Directory: "
  647. << this->TestProperties->Directory << std::endl);
  648. }
  649. // Print any test-specific env vars in verbose mode
  650. if (!this->TestProperties->Environment.empty()) {
  651. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  652. this->Index << ": "
  653. << "Environment variables: " << std::endl);
  654. }
  655. for (std::string const& env : this->TestProperties->Environment) {
  656. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  657. this->Index << ": " << env << std::endl);
  658. }
  659. if (!this->TestProperties->EnvironmentModification.empty()) {
  660. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  661. this->Index << ": "
  662. << "Environment variable modifications: "
  663. << std::endl);
  664. }
  665. for (std::string const& envmod :
  666. this->TestProperties->EnvironmentModification) {
  667. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  668. this->Index << ": " << envmod << std::endl);
  669. }
  670. }
  671. void cmCTestRunTest::ParseOutputForMeasurements()
  672. {
  673. if (!this->ProcessOutput.empty() &&
  674. (this->ProcessOutput.find("<DartMeasurement") != std::string::npos ||
  675. this->ProcessOutput.find("<CTestMeasurement") != std::string::npos)) {
  676. if (this->TestHandler->AllTestMeasurementsRegex.find(
  677. this->ProcessOutput)) {
  678. this->TestResult.TestMeasurementsOutput =
  679. this->TestHandler->AllTestMeasurementsRegex.match(1);
  680. // keep searching and replacing until none are left
  681. while (this->TestHandler->SingleTestMeasurementRegex.find(
  682. this->ProcessOutput)) {
  683. // replace the exact match for the string
  684. cmSystemTools::ReplaceString(
  685. this->ProcessOutput,
  686. this->TestHandler->SingleTestMeasurementRegex.match(1).c_str(), "");
  687. }
  688. }
  689. }
  690. }
  691. bool cmCTestRunTest::ForkProcess(
  692. cmDuration testTimeOut, bool explicitTimeout,
  693. std::vector<std::string>* environment,
  694. std::vector<std::string>* environment_modification,
  695. std::vector<size_t>* affinity)
  696. {
  697. this->TestProcess->SetId(this->Index);
  698. this->TestProcess->SetWorkingDirectory(this->TestProperties->Directory);
  699. this->TestProcess->SetCommand(this->ActualCommand);
  700. this->TestProcess->SetCommandArguments(this->Arguments);
  701. // determine how much time we have
  702. cmDuration timeout = this->CTest->GetRemainingTimeAllowed();
  703. if (timeout != cmCTest::MaxDuration()) {
  704. timeout -= std::chrono::minutes(2);
  705. }
  706. if (this->CTest->GetTimeOut() > cmDuration::zero() &&
  707. this->CTest->GetTimeOut() < timeout) {
  708. timeout = this->CTest->GetTimeOut();
  709. }
  710. if (testTimeOut > cmDuration::zero() &&
  711. testTimeOut < this->CTest->GetRemainingTimeAllowed()) {
  712. timeout = testTimeOut;
  713. }
  714. // always have at least 1 second if we got to here
  715. if (timeout <= cmDuration::zero()) {
  716. timeout = std::chrono::seconds(1);
  717. }
  718. // handle timeout explicitly set to 0
  719. if (testTimeOut == cmDuration::zero() && explicitTimeout) {
  720. timeout = cmDuration::zero();
  721. }
  722. cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
  723. this->Index << ": "
  724. << "Test timeout computed to be: "
  725. << cmDurationTo<unsigned int>(timeout)
  726. << "\n",
  727. this->TestHandler->GetQuiet());
  728. this->TestProcess->SetTimeout(timeout);
  729. #ifndef CMAKE_BOOTSTRAP
  730. cmSystemTools::SaveRestoreEnvironment sre;
  731. #endif
  732. std::ostringstream envMeasurement;
  733. if (environment && !environment->empty()) {
  734. // Environment modification works on the assumption that the environment is
  735. // actually modified here. If another strategy is used, there will need to
  736. // be updates below in `apply_diff`.
  737. cmSystemTools::AppendEnv(*environment);
  738. for (auto const& var : *environment) {
  739. envMeasurement << var << std::endl;
  740. }
  741. }
  742. if (environment_modification && !environment_modification->empty()) {
  743. std::map<std::string, cm::optional<std::string>> env_application;
  744. #ifdef _WIN32
  745. char path_sep = ';';
  746. #else
  747. char path_sep = ':';
  748. #endif
  749. auto apply_diff =
  750. [&env_application](const std::string& name,
  751. std::function<void(std::string&)> const& apply) {
  752. cm::optional<std::string> old_value = env_application[name];
  753. std::string output;
  754. if (old_value) {
  755. output = *old_value;
  756. } else {
  757. // This only works because the environment is actually modified above
  758. // (`AppendEnv`). If CTest ever just creates an environment block
  759. // directly, that block will need to be queried for the subprocess'
  760. // value instead.
  761. const char* curval = cmSystemTools::GetEnv(name);
  762. if (curval) {
  763. output = curval;
  764. }
  765. }
  766. apply(output);
  767. env_application[name] = output;
  768. };
  769. bool err_occurred = false;
  770. for (auto const& envmod : *environment_modification) {
  771. // Split on `=`
  772. auto const eq_loc = envmod.find_first_of('=');
  773. if (eq_loc == std::string::npos) {
  774. cmCTestLog(this->CTest, ERROR_MESSAGE,
  775. "Error: Missing `=` after the variable name in: "
  776. << envmod << std::endl);
  777. err_occurred = true;
  778. continue;
  779. }
  780. auto const name = envmod.substr(0, eq_loc);
  781. // Split value on `:`
  782. auto const op_value_start = eq_loc + 1;
  783. auto const colon_loc = envmod.find_first_of(':', op_value_start);
  784. if (colon_loc == std::string::npos) {
  785. cmCTestLog(this->CTest, ERROR_MESSAGE,
  786. "Error: Missing `:` after the operation in: " << envmod
  787. << std::endl);
  788. err_occurred = true;
  789. continue;
  790. }
  791. auto const op =
  792. envmod.substr(op_value_start, colon_loc - op_value_start);
  793. auto const value_start = colon_loc + 1;
  794. auto const value = envmod.substr(value_start);
  795. // Determine what to do with the operation.
  796. if (op == "reset"_s) {
  797. auto entry = env_application.find(name);
  798. if (entry != env_application.end()) {
  799. env_application.erase(entry);
  800. }
  801. } else if (op == "set"_s) {
  802. env_application[name] = value;
  803. } else if (op == "unset"_s) {
  804. env_application[name] = {};
  805. } else if (op == "string_append"_s) {
  806. apply_diff(name, [&value](std::string& output) { output += value; });
  807. } else if (op == "string_prepend"_s) {
  808. apply_diff(name,
  809. [&value](std::string& output) { output.insert(0, value); });
  810. } else if (op == "path_list_append"_s) {
  811. apply_diff(name, [&value, path_sep](std::string& output) {
  812. if (!output.empty()) {
  813. output += path_sep;
  814. }
  815. output += value;
  816. });
  817. } else if (op == "path_list_prepend"_s) {
  818. apply_diff(name, [&value, path_sep](std::string& output) {
  819. if (!output.empty()) {
  820. output.insert(output.begin(), path_sep);
  821. }
  822. output.insert(0, value);
  823. });
  824. } else if (op == "cmake_list_append"_s) {
  825. apply_diff(name, [&value](std::string& output) {
  826. if (!output.empty()) {
  827. output += ';';
  828. }
  829. output += value;
  830. });
  831. } else if (op == "cmake_list_prepend"_s) {
  832. apply_diff(name, [&value](std::string& output) {
  833. if (!output.empty()) {
  834. output.insert(output.begin(), ';');
  835. }
  836. output.insert(0, value);
  837. });
  838. } else {
  839. cmCTestLog(this->CTest, ERROR_MESSAGE,
  840. "Error: Unrecognized environment manipulation argument: "
  841. << op << std::endl);
  842. err_occurred = true;
  843. continue;
  844. }
  845. }
  846. if (err_occurred) {
  847. return false;
  848. }
  849. for (auto const& env_apply : env_application) {
  850. if (env_apply.second) {
  851. auto const env_update =
  852. cmStrCat(env_apply.first, '=', *env_apply.second);
  853. cmSystemTools::PutEnv(env_update);
  854. envMeasurement << env_update << std::endl;
  855. } else {
  856. cmSystemTools::UnsetEnv(env_apply.first.c_str());
  857. // Signify that this variable is being actively unset
  858. envMeasurement << "#" << env_apply.first << "=" << std::endl;
  859. }
  860. }
  861. }
  862. if (this->UseAllocatedResources) {
  863. std::vector<std::string> envLog;
  864. this->SetupResourcesEnvironment(&envLog);
  865. for (auto const& var : envLog) {
  866. envMeasurement << var << std::endl;
  867. }
  868. } else {
  869. cmSystemTools::UnsetEnv("CTEST_RESOURCE_GROUP_COUNT");
  870. // Signify that this variable is being actively unset
  871. envMeasurement << "#CTEST_RESOURCE_GROUP_COUNT=" << std::endl;
  872. }
  873. this->TestResult.Environment = envMeasurement.str();
  874. // Remove last newline
  875. this->TestResult.Environment.erase(this->TestResult.Environment.length() -
  876. 1);
  877. return this->TestProcess->StartProcess(this->MultiTestHandler.Loop,
  878. affinity);
  879. }
  880. void cmCTestRunTest::SetupResourcesEnvironment(std::vector<std::string>* log)
  881. {
  882. std::string processCount = "CTEST_RESOURCE_GROUP_COUNT=";
  883. processCount += std::to_string(this->AllocatedResources.size());
  884. cmSystemTools::PutEnv(processCount);
  885. if (log) {
  886. log->push_back(processCount);
  887. }
  888. std::size_t i = 0;
  889. for (auto const& process : this->AllocatedResources) {
  890. std::string prefix = "CTEST_RESOURCE_GROUP_";
  891. prefix += std::to_string(i);
  892. std::string resourceList = prefix + '=';
  893. prefix += '_';
  894. bool firstType = true;
  895. for (auto const& it : process) {
  896. if (!firstType) {
  897. resourceList += ',';
  898. }
  899. firstType = false;
  900. auto resourceType = it.first;
  901. resourceList += resourceType;
  902. std::string var = prefix + cmSystemTools::UpperCase(resourceType) + '=';
  903. bool firstName = true;
  904. for (auto const& it2 : it.second) {
  905. if (!firstName) {
  906. var += ';';
  907. }
  908. firstName = false;
  909. var += "id:" + it2.Id + ",slots:" + std::to_string(it2.Slots);
  910. }
  911. cmSystemTools::PutEnv(var);
  912. if (log) {
  913. log->push_back(var);
  914. }
  915. }
  916. cmSystemTools::PutEnv(resourceList);
  917. if (log) {
  918. log->push_back(resourceList);
  919. }
  920. ++i;
  921. }
  922. }
  923. void cmCTestRunTest::WriteLogOutputTop(size_t completed, size_t total)
  924. {
  925. std::ostringstream outputStream;
  926. // If this is the last or only run of this test, or progress output is
  927. // requested, then print out completed / total.
  928. // Only issue is if a test fails and we are running until fail
  929. // then it will never print out the completed / total, same would
  930. // got for run until pass. Trick is when this is called we don't
  931. // yet know if we are passing or failing.
  932. bool const progressOnLast =
  933. (this->RepeatMode != cmCTest::Repeat::UntilPass &&
  934. this->RepeatMode != cmCTest::Repeat::AfterTimeout);
  935. if ((progressOnLast && this->NumberOfRunsLeft == 1) ||
  936. (!progressOnLast && this->NumberOfRunsLeft == this->NumberOfRunsTotal) ||
  937. this->CTest->GetTestProgressOutput()) {
  938. outputStream << std::setw(getNumWidth(total)) << completed << "/";
  939. outputStream << std::setw(getNumWidth(total)) << total << " ";
  940. }
  941. // if this is one of several runs of a test just print blank space
  942. // to keep things neat
  943. else {
  944. outputStream << std::setw(getNumWidth(total)) << " ";
  945. outputStream << std::setw(getNumWidth(total)) << " ";
  946. }
  947. if (this->TestHandler->MemCheck) {
  948. outputStream << "MemCheck";
  949. } else {
  950. outputStream << "Test";
  951. }
  952. std::ostringstream indexStr;
  953. indexStr << " #" << this->Index << ":";
  954. outputStream << std::setw(3 + getNumWidth(this->TestHandler->GetMaxIndex()))
  955. << indexStr.str();
  956. outputStream << " ";
  957. const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
  958. std::string outname = this->TestProperties->Name + " ";
  959. outname.resize(maxTestNameWidth + 4, '.');
  960. outputStream << outname;
  961. *this->TestHandler->LogFile << this->TestProperties->Index << "/"
  962. << this->TestHandler->TotalNumberOfTests
  963. << " Testing: " << this->TestProperties->Name
  964. << std::endl;
  965. *this->TestHandler->LogFile << this->TestProperties->Index << "/"
  966. << this->TestHandler->TotalNumberOfTests
  967. << " Test: " << this->TestProperties->Name
  968. << std::endl;
  969. *this->TestHandler->LogFile << "Command: \"" << this->ActualCommand << "\"";
  970. for (std::string const& arg : this->Arguments) {
  971. *this->TestHandler->LogFile << " \"" << arg << "\"";
  972. }
  973. *this->TestHandler->LogFile
  974. << std::endl
  975. << "Directory: " << this->TestProperties->Directory << std::endl
  976. << "\"" << this->TestProperties->Name
  977. << "\" start time: " << this->StartTime << std::endl;
  978. *this->TestHandler->LogFile
  979. << "Output:" << std::endl
  980. << "----------------------------------------------------------"
  981. << std::endl;
  982. *this->TestHandler->LogFile << this->ProcessOutput << "<end of output>"
  983. << std::endl;
  984. if (!this->CTest->GetTestProgressOutput()) {
  985. cmCTestLog(this->CTest, HANDLER_OUTPUT, outputStream.str());
  986. }
  987. cmCTestLog(this->CTest, DEBUG,
  988. "Testing " << this->TestProperties->Name << " ... ");
  989. }
  990. void cmCTestRunTest::FinalizeTest(bool started)
  991. {
  992. this->MultiTestHandler.FinishTestProcess(this->TestProcess->GetRunner(),
  993. started);
  994. }