cmCTestRunTest.cxx 37 KB

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