cmCTestRunTest.cxx 35 KB

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