cmCTestRunTest.cxx 29 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807
  1. /* Distributed under the OSI-approved BSD 3-Clause License. See accompanying
  2. file Copyright.txt or https://cmake.org/licensing for details. */
  3. #ifdef _WIN32
  4. /* windows.h defines min() and max() macros that interfere. */
  5. #define NOMINMAX
  6. #endif
  7. #include "cmCTestRunTest.h"
  8. #include "cmCTest.h"
  9. #include "cmCTestMemCheckHandler.h"
  10. #include "cmCTestTestHandler.h"
  11. #include "cmProcess.h"
  12. #include "cmSystemTools.h"
  13. #include "cmWorkingDirectory.h"
  14. #include "cm_curl.h"
  15. #include "cm_zlib.h"
  16. #include "cmsys/Base64.h"
  17. #include "cmsys/Process.h"
  18. #include "cmsys/RegularExpression.hxx"
  19. #include <algorithm>
  20. #include <chrono>
  21. #include <iomanip>
  22. #include <sstream>
  23. #include <stdio.h>
  24. #include <time.h>
  25. #include <utility>
  26. cmCTestRunTest::cmCTestRunTest(cmCTestTestHandler* handler)
  27. {
  28. this->CTest = handler->CTest;
  29. this->TestHandler = handler;
  30. this->TestProcess = nullptr;
  31. this->TestResult.ExecutionTime = std::chrono::duration<double>::zero();
  32. this->TestResult.ReturnValue = 0;
  33. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  34. this->TestResult.TestCount = 0;
  35. this->TestResult.Properties = nullptr;
  36. this->ProcessOutput.clear();
  37. this->CompressedOutput.clear();
  38. this->CompressionRatio = 2;
  39. this->StopTimePassed = false;
  40. this->NumberOfRunsLeft = 1; // default to 1 run of the test
  41. this->RunUntilFail = false; // default to run the test once
  42. this->RunAgain = false; // default to not having to run again
  43. }
  44. cmCTestRunTest::~cmCTestRunTest()
  45. {
  46. }
  47. bool cmCTestRunTest::CheckOutput()
  48. {
  49. // Read lines for up to 0.1 seconds of total time.
  50. std::chrono::duration<double> timeout = std::chrono::milliseconds(100);
  51. auto timeEnd = std::chrono::steady_clock::now() + timeout;
  52. std::string line;
  53. while ((timeout = timeEnd - std::chrono::steady_clock::now(),
  54. timeout > std::chrono::seconds(0))) {
  55. int p = this->TestProcess->GetNextOutputLine(line, timeout);
  56. if (p == cmsysProcess_Pipe_None) {
  57. // Process has terminated and all output read.
  58. return false;
  59. }
  60. if (p == cmsysProcess_Pipe_STDOUT) {
  61. // Store this line of output.
  62. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->GetIndex()
  63. << ": " << line << std::endl);
  64. this->ProcessOutput += line;
  65. this->ProcessOutput += "\n";
  66. // Check for TIMEOUT_AFTER_MATCH property.
  67. if (!this->TestProperties->TimeoutRegularExpressions.empty()) {
  68. for (auto& reg : this->TestProperties->TimeoutRegularExpressions) {
  69. if (reg.first.find(this->ProcessOutput.c_str())) {
  70. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->GetIndex()
  71. << ": "
  72. << "Test timeout changed to "
  73. << std::chrono::duration_cast<std::chrono::seconds>(
  74. this->TestProperties->AlternateTimeout)
  75. .count()
  76. << std::endl);
  77. this->TestProcess->ResetStartTime();
  78. this->TestProcess->ChangeTimeout(
  79. this->TestProperties->AlternateTimeout);
  80. this->TestProperties->TimeoutRegularExpressions.clear();
  81. break;
  82. }
  83. }
  84. }
  85. } else { // if(p == cmsysProcess_Pipe_Timeout)
  86. break;
  87. }
  88. }
  89. return true;
  90. }
  91. // Streamed compression of test output. The compressed data
  92. // is appended to this->CompressedOutput
  93. void cmCTestRunTest::CompressOutput()
  94. {
  95. int ret;
  96. z_stream strm;
  97. unsigned char* in = reinterpret_cast<unsigned char*>(
  98. const_cast<char*>(this->ProcessOutput.c_str()));
  99. // zlib makes the guarantee that this is the maximum output size
  100. int outSize = static_cast<int>(
  101. static_cast<double>(this->ProcessOutput.size()) * 1.001 + 13.0);
  102. unsigned char* out = new unsigned char[outSize];
  103. strm.zalloc = Z_NULL;
  104. strm.zfree = Z_NULL;
  105. strm.opaque = Z_NULL;
  106. ret = deflateInit(&strm, -1); // default compression level
  107. if (ret != Z_OK) {
  108. delete[] out;
  109. return;
  110. }
  111. strm.avail_in = static_cast<uInt>(this->ProcessOutput.size());
  112. strm.next_in = in;
  113. strm.avail_out = outSize;
  114. strm.next_out = out;
  115. ret = deflate(&strm, Z_FINISH);
  116. if (ret != Z_STREAM_END) {
  117. cmCTestLog(this->CTest, ERROR_MESSAGE,
  118. "Error during output compression. Sending uncompressed output."
  119. << std::endl);
  120. delete[] out;
  121. return;
  122. }
  123. (void)deflateEnd(&strm);
  124. unsigned char* encoded_buffer =
  125. new unsigned char[static_cast<int>(outSize * 1.5)];
  126. size_t rlen = cmsysBase64_Encode(out, strm.total_out, encoded_buffer, 1);
  127. this->CompressedOutput.clear();
  128. for (size_t i = 0; i < rlen; i++) {
  129. this->CompressedOutput += encoded_buffer[i];
  130. }
  131. if (strm.total_in) {
  132. this->CompressionRatio =
  133. static_cast<double>(strm.total_out) / static_cast<double>(strm.total_in);
  134. }
  135. delete[] encoded_buffer;
  136. delete[] out;
  137. }
  138. bool cmCTestRunTest::EndTest(size_t completed, size_t total, bool started)
  139. {
  140. if ((!this->TestHandler->MemCheck &&
  141. this->CTest->ShouldCompressTestOutput()) ||
  142. (this->TestHandler->MemCheck &&
  143. this->CTest->ShouldCompressTestOutput())) {
  144. this->CompressOutput();
  145. }
  146. this->WriteLogOutputTop(completed, total);
  147. std::string reason;
  148. bool passed = true;
  149. int res =
  150. started ? this->TestProcess->GetProcessStatus() : cmsysProcess_State_Error;
  151. int retVal = this->TestProcess->GetExitValue();
  152. bool forceFail = false;
  153. bool skipped = false;
  154. bool outputTestErrorsToConsole = false;
  155. if (!this->TestProperties->RequiredRegularExpressions.empty() &&
  156. this->FailedDependencies.empty()) {
  157. bool found = false;
  158. for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
  159. if (pass.first.find(this->ProcessOutput.c_str())) {
  160. found = true;
  161. reason = "Required regular expression found.";
  162. break;
  163. }
  164. }
  165. if (!found) {
  166. reason = "Required regular expression not found.";
  167. forceFail = true;
  168. }
  169. reason += "Regex=[";
  170. for (auto& pass : this->TestProperties->RequiredRegularExpressions) {
  171. reason += pass.second;
  172. reason += "\n";
  173. }
  174. reason += "]";
  175. }
  176. if (!this->TestProperties->ErrorRegularExpressions.empty() &&
  177. this->FailedDependencies.empty()) {
  178. for (auto& pass : this->TestProperties->ErrorRegularExpressions) {
  179. if (pass.first.find(this->ProcessOutput.c_str())) {
  180. reason = "Error regular expression found in output.";
  181. reason += " Regex=[";
  182. reason += pass.second;
  183. reason += "]";
  184. forceFail = true;
  185. break;
  186. }
  187. }
  188. }
  189. if (res == cmsysProcess_State_Exited) {
  190. bool success = !forceFail &&
  191. (retVal == 0 ||
  192. !this->TestProperties->RequiredRegularExpressions.empty());
  193. if (this->TestProperties->SkipReturnCode >= 0 &&
  194. this->TestProperties->SkipReturnCode == retVal) {
  195. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  196. std::ostringstream s;
  197. s << "SKIP_RETURN_CODE=" << this->TestProperties->SkipReturnCode;
  198. this->TestResult.CompletionStatus = s.str();
  199. cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Skipped ");
  200. skipped = true;
  201. } else if ((success && !this->TestProperties->WillFail) ||
  202. (!success && this->TestProperties->WillFail)) {
  203. this->TestResult.Status = cmCTestTestHandler::COMPLETED;
  204. cmCTestLog(this->CTest, HANDLER_OUTPUT, " Passed ");
  205. } else {
  206. this->TestResult.Status = cmCTestTestHandler::FAILED;
  207. cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Failed " << reason);
  208. outputTestErrorsToConsole = this->CTest->OutputTestOutputOnTestFailure;
  209. }
  210. } else if (res == cmsysProcess_State_Expired) {
  211. cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Timeout ");
  212. this->TestResult.Status = cmCTestTestHandler::TIMEOUT;
  213. outputTestErrorsToConsole = this->CTest->OutputTestOutputOnTestFailure;
  214. } else if (res == cmsysProcess_State_Exception) {
  215. outputTestErrorsToConsole = this->CTest->OutputTestOutputOnTestFailure;
  216. cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Exception: ");
  217. this->TestResult.ExceptionStatus =
  218. this->TestProcess->GetExitExceptionString();
  219. switch (this->TestProcess->GetExitException()) {
  220. case cmsysProcess_Exception_Fault:
  221. cmCTestLog(this->CTest, HANDLER_OUTPUT, "SegFault");
  222. this->TestResult.Status = cmCTestTestHandler::SEGFAULT;
  223. break;
  224. case cmsysProcess_Exception_Illegal:
  225. cmCTestLog(this->CTest, HANDLER_OUTPUT, "Illegal");
  226. this->TestResult.Status = cmCTestTestHandler::ILLEGAL;
  227. break;
  228. case cmsysProcess_Exception_Interrupt:
  229. cmCTestLog(this->CTest, HANDLER_OUTPUT, "Interrupt");
  230. this->TestResult.Status = cmCTestTestHandler::INTERRUPT;
  231. break;
  232. case cmsysProcess_Exception_Numerical:
  233. cmCTestLog(this->CTest, HANDLER_OUTPUT, "Numerical");
  234. this->TestResult.Status = cmCTestTestHandler::NUMERICAL;
  235. break;
  236. default:
  237. cmCTestLog(this->CTest, HANDLER_OUTPUT,
  238. this->TestResult.ExceptionStatus);
  239. this->TestResult.Status = cmCTestTestHandler::OTHER_FAULT;
  240. }
  241. } else if ("Disabled" == this->TestResult.CompletionStatus) {
  242. cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Not Run (Disabled) ");
  243. } else // cmsysProcess_State_Error
  244. {
  245. cmCTestLog(this->CTest, HANDLER_OUTPUT, "***Not Run ");
  246. }
  247. passed = this->TestResult.Status == cmCTestTestHandler::COMPLETED;
  248. char buf[1024];
  249. sprintf(buf, "%6.2f sec",
  250. double(std::chrono::duration_cast<std::chrono::milliseconds>(
  251. this->TestProcess->GetTotalTime())
  252. .count()) /
  253. 1000.0);
  254. cmCTestLog(this->CTest, HANDLER_OUTPUT, buf << "\n");
  255. if (outputTestErrorsToConsole) {
  256. cmCTestLog(this->CTest, HANDLER_OUTPUT, this->ProcessOutput << std::endl);
  257. }
  258. if (this->TestHandler->LogFile) {
  259. *this->TestHandler->LogFile << "Test time = " << buf << std::endl;
  260. }
  261. // Set the working directory to the tests directory to process Dart files.
  262. {
  263. cmWorkingDirectory workdir(this->TestProperties->Directory);
  264. this->DartProcessing();
  265. }
  266. // if this is doing MemCheck then all the output needs to be put into
  267. // Output since that is what is parsed by cmCTestMemCheckHandler
  268. if (!this->TestHandler->MemCheck && started) {
  269. this->TestHandler->CleanTestOutput(
  270. this->ProcessOutput,
  271. static_cast<size_t>(
  272. this->TestResult.Status == cmCTestTestHandler::COMPLETED
  273. ? this->TestHandler->CustomMaximumPassedTestOutputSize
  274. : this->TestHandler->CustomMaximumFailedTestOutputSize));
  275. }
  276. this->TestResult.Reason = reason;
  277. if (this->TestHandler->LogFile) {
  278. bool pass = true;
  279. const char* reasonType = "Test Pass Reason";
  280. if (this->TestResult.Status != cmCTestTestHandler::COMPLETED &&
  281. this->TestResult.Status != cmCTestTestHandler::NOT_RUN) {
  282. reasonType = "Test Fail Reason";
  283. pass = false;
  284. }
  285. auto ttime = this->TestProcess->GetTotalTime();
  286. auto hours = std::chrono::duration_cast<std::chrono::hours>(ttime);
  287. ttime -= hours;
  288. auto minutes = std::chrono::duration_cast<std::chrono::minutes>(ttime);
  289. ttime -= minutes;
  290. auto seconds = std::chrono::duration_cast<std::chrono::seconds>(ttime);
  291. char buffer[100];
  292. sprintf(buffer, "%02d:%02d:%02d", static_cast<unsigned>(hours.count()),
  293. static_cast<unsigned>(minutes.count()),
  294. static_cast<unsigned>(seconds.count()));
  295. *this->TestHandler->LogFile
  296. << "----------------------------------------------------------"
  297. << std::endl;
  298. if (!this->TestResult.Reason.empty()) {
  299. *this->TestHandler->LogFile << reasonType << ":\n"
  300. << this->TestResult.Reason << "\n";
  301. } else {
  302. if (pass) {
  303. *this->TestHandler->LogFile << "Test Passed.\n";
  304. } else {
  305. *this->TestHandler->LogFile << "Test Failed.\n";
  306. }
  307. }
  308. *this->TestHandler->LogFile
  309. << "\"" << this->TestProperties->Name
  310. << "\" end time: " << this->CTest->CurrentTime() << std::endl
  311. << "\"" << this->TestProperties->Name << "\" time elapsed: " << buffer
  312. << std::endl
  313. << "----------------------------------------------------------"
  314. << std::endl
  315. << std::endl;
  316. }
  317. // if the test actually started and ran
  318. // record the results in TestResult
  319. if (started) {
  320. bool compress = !this->TestHandler->MemCheck &&
  321. this->CompressionRatio < 1 && this->CTest->ShouldCompressTestOutput();
  322. this->TestResult.Output =
  323. compress ? this->CompressedOutput : this->ProcessOutput;
  324. this->TestResult.CompressOutput = compress;
  325. this->TestResult.ReturnValue = this->TestProcess->GetExitValue();
  326. if (!skipped) {
  327. this->TestResult.CompletionStatus = "Completed";
  328. }
  329. this->TestResult.ExecutionTime = this->TestProcess->GetTotalTime();
  330. this->MemCheckPostProcess();
  331. this->ComputeWeightedCost();
  332. }
  333. // If the test does not need to rerun push the current TestResult onto the
  334. // TestHandler vector
  335. if (!this->NeedsToRerun()) {
  336. this->TestHandler->TestResults.push_back(this->TestResult);
  337. }
  338. delete this->TestProcess;
  339. return passed || skipped;
  340. }
  341. bool cmCTestRunTest::StartAgain()
  342. {
  343. if (!this->RunAgain) {
  344. return false;
  345. }
  346. this->RunAgain = false; // reset
  347. // change to tests directory
  348. cmWorkingDirectory workdir(this->TestProperties->Directory);
  349. this->StartTest(this->TotalNumberOfTests);
  350. return true;
  351. }
  352. bool cmCTestRunTest::NeedsToRerun()
  353. {
  354. this->NumberOfRunsLeft--;
  355. if (this->NumberOfRunsLeft == 0) {
  356. return false;
  357. }
  358. // if number of runs left is not 0, and we are running until
  359. // we find a failed test, then return true so the test can be
  360. // restarted
  361. if (this->RunUntilFail &&
  362. this->TestResult.Status == cmCTestTestHandler::COMPLETED) {
  363. this->RunAgain = true;
  364. return true;
  365. }
  366. return false;
  367. }
  368. void cmCTestRunTest::ComputeWeightedCost()
  369. {
  370. double prev = static_cast<double>(this->TestProperties->PreviousRuns);
  371. double avgcost = static_cast<double>(this->TestProperties->Cost);
  372. double current =
  373. double(std::chrono::duration_cast<std::chrono::milliseconds>(
  374. this->TestResult.ExecutionTime)
  375. .count()) /
  376. 1000.0;
  377. if (this->TestResult.Status == cmCTestTestHandler::COMPLETED) {
  378. this->TestProperties->Cost =
  379. static_cast<float>(((prev * avgcost) + current) / (prev + 1.0));
  380. this->TestProperties->PreviousRuns++;
  381. }
  382. }
  383. void cmCTestRunTest::MemCheckPostProcess()
  384. {
  385. if (!this->TestHandler->MemCheck) {
  386. return;
  387. }
  388. cmCTestOptionalLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->Index
  389. << ": process test output now: "
  390. << this->TestProperties->Name << " "
  391. << this->TestResult.Name << std::endl,
  392. this->TestHandler->GetQuiet());
  393. cmCTestMemCheckHandler* handler =
  394. static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
  395. handler->PostProcessTest(this->TestResult, this->Index);
  396. }
  397. // Starts the execution of a test. Returns once it has started
  398. bool cmCTestRunTest::StartTest(size_t total)
  399. {
  400. this->TotalNumberOfTests = total; // save for rerun case
  401. cmCTestLog(this->CTest, HANDLER_OUTPUT, std::setw(2 * getNumWidth(total) + 8)
  402. << "Start "
  403. << std::setw(getNumWidth(this->TestHandler->GetMaxIndex()))
  404. << this->TestProperties->Index << ": "
  405. << this->TestProperties->Name << std::endl);
  406. this->ProcessOutput.clear();
  407. // Return immediately if test is disabled
  408. if (this->TestProperties->Disabled) {
  409. this->TestResult.Properties = this->TestProperties;
  410. this->TestResult.ExecutionTime = std::chrono::duration<double>::zero();
  411. this->TestResult.CompressOutput = false;
  412. this->TestResult.ReturnValue = -1;
  413. this->TestResult.CompletionStatus = "Disabled";
  414. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  415. this->TestResult.TestCount = this->TestProperties->Index;
  416. this->TestResult.Name = this->TestProperties->Name;
  417. this->TestResult.Path = this->TestProperties->Directory;
  418. this->TestProcess = new cmProcess;
  419. this->TestResult.Output = "Disabled";
  420. this->TestResult.FullCommandLine.clear();
  421. return false;
  422. }
  423. this->TestResult.Properties = this->TestProperties;
  424. this->TestResult.ExecutionTime = std::chrono::duration<double>::zero();
  425. this->TestResult.CompressOutput = false;
  426. this->TestResult.ReturnValue = -1;
  427. this->TestResult.CompletionStatus = "Failed to start";
  428. this->TestResult.Status = cmCTestTestHandler::BAD_COMMAND;
  429. this->TestResult.TestCount = this->TestProperties->Index;
  430. this->TestResult.Name = this->TestProperties->Name;
  431. this->TestResult.Path = this->TestProperties->Directory;
  432. // Check for failed fixture dependencies before we even look at the command
  433. // arguments because if we are not going to run the test, the command and
  434. // its arguments are irrelevant. This matters for the case where a fixture
  435. // dependency might be creating the executable we want to run.
  436. if (!this->FailedDependencies.empty()) {
  437. this->TestProcess = new cmProcess;
  438. std::string msg = "Failed test dependencies:";
  439. for (std::string const& failedDep : this->FailedDependencies) {
  440. msg += " " + failedDep;
  441. }
  442. *this->TestHandler->LogFile << msg << std::endl;
  443. cmCTestLog(this->CTest, HANDLER_OUTPUT, msg << std::endl);
  444. this->TestResult.Output = msg;
  445. this->TestResult.FullCommandLine.clear();
  446. this->TestResult.CompletionStatus = "Fixture dependency failed";
  447. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  448. return false;
  449. }
  450. this->ComputeArguments();
  451. std::vector<std::string>& args = this->TestProperties->Args;
  452. if (args.size() >= 2 && args[1] == "NOT_AVAILABLE") {
  453. this->TestProcess = new cmProcess;
  454. std::string msg;
  455. if (this->CTest->GetConfigType().empty()) {
  456. msg = "Test not available without configuration.";
  457. msg += " (Missing \"-C <config>\"?)";
  458. } else {
  459. msg = "Test not available in configuration \"";
  460. msg += this->CTest->GetConfigType();
  461. msg += "\".";
  462. }
  463. *this->TestHandler->LogFile << msg << std::endl;
  464. cmCTestLog(this->CTest, ERROR_MESSAGE, msg << std::endl);
  465. this->TestResult.Output = msg;
  466. this->TestResult.FullCommandLine.clear();
  467. this->TestResult.CompletionStatus = "Missing Configuration";
  468. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  469. return false;
  470. }
  471. // Check if all required files exist
  472. for (std::string const& file : this->TestProperties->RequiredFiles) {
  473. if (!cmSystemTools::FileExists(file.c_str())) {
  474. // Required file was not found
  475. this->TestProcess = new cmProcess;
  476. *this->TestHandler->LogFile << "Unable to find required file: " << file
  477. << std::endl;
  478. cmCTestLog(this->CTest, ERROR_MESSAGE,
  479. "Unable to find required file: " << file << std::endl);
  480. this->TestResult.Output = "Unable to find required file: " + file;
  481. this->TestResult.FullCommandLine.clear();
  482. this->TestResult.CompletionStatus = "Required Files Missing";
  483. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  484. return false;
  485. }
  486. }
  487. // log and return if we did not find the executable
  488. if (this->ActualCommand.empty()) {
  489. // if the command was not found create a TestResult object
  490. // that has that information
  491. this->TestProcess = new cmProcess;
  492. *this->TestHandler->LogFile << "Unable to find executable: " << args[1]
  493. << std::endl;
  494. cmCTestLog(this->CTest, ERROR_MESSAGE,
  495. "Unable to find executable: " << args[1] << std::endl);
  496. this->TestResult.Output = "Unable to find executable: " + args[1];
  497. this->TestResult.FullCommandLine.clear();
  498. this->TestResult.CompletionStatus = "Unable to find executable";
  499. this->TestResult.Status = cmCTestTestHandler::NOT_RUN;
  500. return false;
  501. }
  502. this->StartTime = this->CTest->CurrentTime();
  503. auto timeout = this->ResolveTimeout();
  504. if (this->StopTimePassed) {
  505. return false;
  506. }
  507. return this->ForkProcess(timeout, this->TestProperties->ExplicitTimeout,
  508. &this->TestProperties->Environment);
  509. }
  510. void cmCTestRunTest::ComputeArguments()
  511. {
  512. this->Arguments.clear(); // reset becaue this might be a rerun
  513. std::vector<std::string>::const_iterator j =
  514. this->TestProperties->Args.begin();
  515. ++j; // skip test name
  516. // find the test executable
  517. if (this->TestHandler->MemCheck) {
  518. cmCTestMemCheckHandler* handler =
  519. static_cast<cmCTestMemCheckHandler*>(this->TestHandler);
  520. this->ActualCommand = handler->MemoryTester;
  521. this->TestProperties->Args[1] = this->TestHandler->FindTheExecutable(
  522. this->TestProperties->Args[1].c_str());
  523. } else {
  524. this->ActualCommand = this->TestHandler->FindTheExecutable(
  525. this->TestProperties->Args[1].c_str());
  526. ++j; // skip the executable (it will be actualCommand)
  527. }
  528. std::string testCommand =
  529. cmSystemTools::ConvertToOutputPath(this->ActualCommand.c_str());
  530. // Prepends memcheck args to our command string
  531. this->TestHandler->GenerateTestCommand(this->Arguments, this->Index);
  532. for (std::string const& arg : this->Arguments) {
  533. testCommand += " \"";
  534. testCommand += arg;
  535. testCommand += "\"";
  536. }
  537. for (; j != this->TestProperties->Args.end(); ++j) {
  538. testCommand += " \"";
  539. testCommand += *j;
  540. testCommand += "\"";
  541. this->Arguments.push_back(*j);
  542. }
  543. this->TestResult.FullCommandLine = testCommand;
  544. // Print the test command in verbose mode
  545. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT, std::endl
  546. << this->Index << ": "
  547. << (this->TestHandler->MemCheck ? "MemCheck" : "Test")
  548. << " command: " << testCommand << std::endl);
  549. // Print any test-specific env vars in verbose mode
  550. if (!this->TestProperties->Environment.empty()) {
  551. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->Index
  552. << ": "
  553. << "Environment variables: " << std::endl);
  554. }
  555. for (std::string const& env : this->TestProperties->Environment) {
  556. cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT, this->Index << ": " << env
  557. << std::endl);
  558. }
  559. }
  560. void cmCTestRunTest::DartProcessing()
  561. {
  562. if (!this->ProcessOutput.empty() &&
  563. this->ProcessOutput.find("<DartMeasurement") != std::string::npos) {
  564. if (this->TestHandler->DartStuff.find(this->ProcessOutput.c_str())) {
  565. this->TestResult.DartString = this->TestHandler->DartStuff.match(1);
  566. // keep searching and replacing until none are left
  567. while (this->TestHandler->DartStuff1.find(this->ProcessOutput.c_str())) {
  568. // replace the exact match for the string
  569. cmSystemTools::ReplaceString(
  570. this->ProcessOutput, this->TestHandler->DartStuff1.match(1).c_str(),
  571. "");
  572. }
  573. }
  574. }
  575. }
  576. std::chrono::duration<double> cmCTestRunTest::ResolveTimeout()
  577. {
  578. auto timeout = this->TestProperties->Timeout;
  579. if (this->CTest->GetStopTime().empty()) {
  580. return timeout;
  581. }
  582. struct tm* lctime;
  583. time_t current_time = time(nullptr);
  584. lctime = gmtime(&current_time);
  585. int gm_hour = lctime->tm_hour;
  586. time_t gm_time = mktime(lctime);
  587. lctime = localtime(&current_time);
  588. int local_hour = lctime->tm_hour;
  589. int tzone_offset = local_hour - gm_hour;
  590. if (gm_time > current_time && gm_hour < local_hour) {
  591. // this means gm_time is on the next day
  592. tzone_offset -= 24;
  593. } else if (gm_time < current_time && gm_hour > local_hour) {
  594. // this means gm_time is on the previous day
  595. tzone_offset += 24;
  596. }
  597. tzone_offset *= 100;
  598. char buf[1024];
  599. // add todays year day and month to the time in str because
  600. // curl_getdate no longer assumes the day is today
  601. sprintf(buf, "%d%02d%02d %s %+05i", lctime->tm_year + 1900,
  602. lctime->tm_mon + 1, lctime->tm_mday,
  603. this->CTest->GetStopTime().c_str(), tzone_offset);
  604. time_t stop_time_t = curl_getdate(buf, &current_time);
  605. if (stop_time_t == -1) {
  606. return timeout;
  607. }
  608. auto stop_time = std::chrono::system_clock::from_time_t(stop_time_t);
  609. // the stop time refers to the next day
  610. if (this->CTest->NextDayStopTime) {
  611. stop_time += std::chrono::hours(24);
  612. }
  613. auto stop_timeout =
  614. (stop_time - std::chrono::system_clock::from_time_t(current_time)) %
  615. std::chrono::hours(24);
  616. this->CTest->LastStopTimeout = stop_timeout;
  617. if (stop_timeout <= std::chrono::duration<double>::zero() ||
  618. stop_timeout > this->CTest->LastStopTimeout) {
  619. cmCTestLog(this->CTest, ERROR_MESSAGE, "The stop time has been passed. "
  620. "Stopping all tests."
  621. << std::endl);
  622. this->StopTimePassed = true;
  623. return std::chrono::duration<double>::zero();
  624. }
  625. return timeout == std::chrono::duration<double>::zero()
  626. ? stop_timeout
  627. : (timeout < stop_timeout ? timeout : stop_timeout);
  628. }
  629. bool cmCTestRunTest::ForkProcess(std::chrono::duration<double> testTimeOut,
  630. bool explicitTimeout,
  631. std::vector<std::string>* environment)
  632. {
  633. this->TestProcess = new cmProcess;
  634. this->TestProcess->SetId(this->Index);
  635. this->TestProcess->SetWorkingDirectory(
  636. this->TestProperties->Directory.c_str());
  637. this->TestProcess->SetCommand(this->ActualCommand.c_str());
  638. this->TestProcess->SetCommandArguments(this->Arguments);
  639. // determine how much time we have
  640. std::chrono::duration<double> timeout =
  641. std::min<std::chrono::duration<double>>(
  642. this->CTest->GetRemainingTimeAllowed(), std::chrono::minutes(2));
  643. if (this->CTest->GetTimeOut() > std::chrono::duration<double>::zero() &&
  644. this->CTest->GetTimeOut() < timeout) {
  645. timeout = this->CTest->GetTimeOut();
  646. }
  647. if (testTimeOut > std::chrono::duration<double>::zero() &&
  648. testTimeOut < this->CTest->GetRemainingTimeAllowed()) {
  649. timeout = testTimeOut;
  650. }
  651. // always have at least 1 second if we got to here
  652. if (timeout <= std::chrono::duration<double>::zero()) {
  653. timeout = std::chrono::seconds(1);
  654. }
  655. // handle timeout explicitly set to 0
  656. if (testTimeOut == std::chrono::duration<double>::zero() &&
  657. explicitTimeout) {
  658. timeout = std::chrono::duration<double>::zero();
  659. }
  660. cmCTestOptionalLog(
  661. this->CTest, HANDLER_VERBOSE_OUTPUT, this->Index
  662. << ": "
  663. << "Test timeout computed to be: "
  664. << (timeout == std::chrono::duration<double>::max()
  665. ? std::string("infinite")
  666. : std::to_string(
  667. std::chrono::duration_cast<std::chrono::seconds>(timeout)
  668. .count()))
  669. << "\n",
  670. this->TestHandler->GetQuiet());
  671. this->TestProcess->SetTimeout(timeout);
  672. #ifdef CMAKE_BUILD_WITH_CMAKE
  673. cmSystemTools::SaveRestoreEnvironment sre;
  674. #endif
  675. if (environment && !environment->empty()) {
  676. cmSystemTools::AppendEnv(*environment);
  677. }
  678. return this->TestProcess->StartProcess();
  679. }
  680. void cmCTestRunTest::WriteLogOutputTop(size_t completed, size_t total)
  681. {
  682. // if this is the last or only run of this test
  683. // then print out completed / total
  684. // Only issue is if a test fails and we are running until fail
  685. // then it will never print out the completed / total, same would
  686. // got for run until pass. Trick is when this is called we don't
  687. // yet know if we are passing or failing.
  688. if (this->NumberOfRunsLeft == 1) {
  689. cmCTestLog(this->CTest, HANDLER_OUTPUT, std::setw(getNumWidth(total))
  690. << completed << "/");
  691. cmCTestLog(this->CTest, HANDLER_OUTPUT, std::setw(getNumWidth(total))
  692. << total << " ");
  693. }
  694. // if this is one of several runs of a test just print blank space
  695. // to keep things neat
  696. else {
  697. cmCTestLog(this->CTest, HANDLER_OUTPUT, std::setw(getNumWidth(total))
  698. << " "
  699. << " ");
  700. cmCTestLog(this->CTest, HANDLER_OUTPUT, std::setw(getNumWidth(total))
  701. << " "
  702. << " ");
  703. }
  704. if (this->TestHandler->MemCheck) {
  705. cmCTestLog(this->CTest, HANDLER_OUTPUT, "MemCheck");
  706. } else {
  707. cmCTestLog(this->CTest, HANDLER_OUTPUT, "Test");
  708. }
  709. std::ostringstream indexStr;
  710. indexStr << " #" << this->Index << ":";
  711. cmCTestLog(this->CTest, HANDLER_OUTPUT,
  712. std::setw(3 + getNumWidth(this->TestHandler->GetMaxIndex()))
  713. << indexStr.str());
  714. cmCTestLog(this->CTest, HANDLER_OUTPUT, " ");
  715. const int maxTestNameWidth = this->CTest->GetMaxTestNameWidth();
  716. std::string outname = this->TestProperties->Name + " ";
  717. outname.resize(maxTestNameWidth + 4, '.');
  718. *this->TestHandler->LogFile << this->TestProperties->Index << "/"
  719. << this->TestHandler->TotalNumberOfTests
  720. << " Testing: " << this->TestProperties->Name
  721. << std::endl;
  722. *this->TestHandler->LogFile << this->TestProperties->Index << "/"
  723. << this->TestHandler->TotalNumberOfTests
  724. << " Test: " << this->TestProperties->Name
  725. << std::endl;
  726. *this->TestHandler->LogFile << "Command: \"" << this->ActualCommand << "\"";
  727. for (std::string const& arg : this->Arguments) {
  728. *this->TestHandler->LogFile << " \"" << arg << "\"";
  729. }
  730. *this->TestHandler->LogFile
  731. << std::endl
  732. << "Directory: " << this->TestProperties->Directory << std::endl
  733. << "\"" << this->TestProperties->Name
  734. << "\" start time: " << this->StartTime << std::endl;
  735. *this->TestHandler->LogFile
  736. << "Output:" << std::endl
  737. << "----------------------------------------------------------"
  738. << std::endl;
  739. *this->TestHandler->LogFile << this->ProcessOutput << "<end of output>"
  740. << std::endl;
  741. cmCTestLog(this->CTest, HANDLER_OUTPUT, outname.c_str());
  742. cmCTestLog(this->CTest, DEBUG, "Testing " << this->TestProperties->Name
  743. << " ... ");
  744. }