1 /** 2 Copyright: Copyright (c) 2020, Joakim Brännström. All rights reserved. 3 License: MPL-2 4 Author: Joakim Brännström (joakim.brannstrom@gmx.com) 5 6 This Source Code Form is subject to the terms of the Mozilla Public License, 7 v.2.0. If a copy of the MPL was not distributed with this file, You can obtain 8 one at http://mozilla.org/MPL/2.0/. 9 10 Common functionality used both by source and schemata testing of a mutant. 11 */ 12 module dextool.plugin.mutate.backend.test_mutant.common; 13 14 import logger = std.experimental.logger; 15 import std.algorithm : map, filter; 16 import std.array : empty, array; 17 import std.datetime : Duration, dur; 18 import std.exception : collectException; 19 import std.path : buildPath; 20 import std.typecons : Flag, No; 21 22 import blob_model : Blob; 23 import my.named_type; 24 import my.set; 25 import proc : DrainElement; 26 import sumtype; 27 28 import dextool.plugin.mutate.backend.database : MutationId; 29 import dextool.plugin.mutate.backend.interface_; 30 import dextool.plugin.mutate.backend.test_mutant.test_case_analyze : GatherTestCase; 31 import dextool.plugin.mutate.backend.test_mutant.test_cmd_runner; 32 import dextool.plugin.mutate.config; 33 import dextool.plugin.mutate.type : TestCaseAnalyzeBuiltin, ShellCommand; 34 import dextool.type : AbsolutePath, Path; 35 36 public import dextool.plugin.mutate.backend.type : Mutation, TestCase, 37 ExitStatus, MutantTimeProfile; 38 39 version (unittest) { 40 import unit_threaded.assertions; 41 } 42 43 @safe: 44 45 /// The result of running the test suite on one mutant. 46 struct MutationTestResult { 47 import std.datetime : Duration; 48 import dextool.plugin.mutate.backend.database : MutationStatusId, MutationId; 49 import dextool.plugin.mutate.backend.type : Mutation, TestCase, ExitStatus; 50 51 MutationId mutId; 52 MutationStatusId id; 53 Mutation.Status status; 54 MutantTimeProfile profile; 55 TestCase[] testCases; 56 ExitStatus exitStatus; 57 } 58 59 /** Analyze stdout/stderr output from a test suite for test cases that failed 60 * (killed) a mutant, which test cases that exists and if any of them are 61 * unstable. 62 */ 63 struct TestCaseAnalyzer { 64 private { 65 ShellCommand[] externalAnalysers; 66 TestCaseAnalyzeBuiltin[] builtins; 67 AutoCleanup cleanup; 68 } 69 70 static struct Success { 71 TestCase[] failed; 72 TestCase[] testCmd; 73 TestCase[] found; 74 } 75 76 static struct Unstable { 77 TestCase[] unstable; 78 TestCase[] found; 79 } 80 81 static struct Failed { 82 } 83 84 alias Result = SumType!(Success, Unstable, Failed); 85 86 this(TestCaseAnalyzeBuiltin[] builtins, ShellCommand[] externalAnalyzers, AutoCleanup cleanup) { 87 this.externalAnalysers = externalAnalyzers; 88 this.builtins = builtins; 89 this.cleanup = cleanup; 90 } 91 92 Result analyze(ShellCommand testCmd, DrainElement[] data, 93 Flag!"allFound" allFound = No.allFound) { 94 import dextool.plugin.mutate.backend.test_mutant.test_case_analyze : GatherTestCase; 95 96 GatherTestCase gather; 97 98 // the post processer must succeeed for the data to be stored. It is 99 // considered a major error that may corrupt existing data if it fails. 100 bool success = true; 101 102 if (!externalAnalysers.empty) { 103 foreach (cmd; externalAnalysers) { 104 success = success && externalProgram(cmd, data, gather, cleanup); 105 } 106 } 107 if (!builtins.empty) { 108 builtin(testCmd, data, builtins, gather); 109 } 110 111 if (!gather.unstable.empty) { 112 return Result(Unstable(gather.unstable.toArray, allFound ? gather.found.toArray : null)); 113 } 114 115 if (success) { 116 return Result(Success(gather.failed.toArray, 117 gather.testCmd.toArray, allFound ? gather.found.toArray : null)); 118 } 119 120 return Result(Failed.init); 121 } 122 123 /// Returns: true if there are no analyzers setup. 124 bool empty() @safe pure nothrow const @nogc { 125 return externalAnalysers.empty && builtins.empty; 126 } 127 } 128 129 /** Analyze the output from the test suite with one of the builtin analyzers. 130 */ 131 void builtin(ShellCommand cmd, DrainElement[] output, 132 const(TestCaseAnalyzeBuiltin)[] tc_analyze_builtin, ref GatherTestCase app) @safe nothrow { 133 import dextool.plugin.mutate.backend.test_mutant.ctest_post_analyze; 134 import dextool.plugin.mutate.backend.test_mutant.gtest_post_analyze; 135 import dextool.plugin.mutate.backend.test_mutant.makefile_post_analyze; 136 137 GtestParser gtest; 138 CtestParser ctest; 139 MakefileParser makefile; 140 141 void analyzeLine(const(char)[] line) { 142 // this is a magic number that felt good. Why would there be a line in a test case log that is longer than this? 143 immutable magic_nr = 2048; 144 if (line.length > magic_nr) { 145 // The byLine split may fail and thus result in one huge line. 146 // The result of this is that regex's that use backtracking become really slow. 147 // By skipping these lines dextool at list doesn't hang. 148 logger.warningf("Line in test case log is too long to analyze (%s > %s). Skipping...", 149 line.length, magic_nr); 150 return; 151 } 152 153 foreach (const p; tc_analyze_builtin) { 154 final switch (p) { 155 case TestCaseAnalyzeBuiltin.gtest: 156 gtest.process(line, app); 157 break; 158 case TestCaseAnalyzeBuiltin.ctest: 159 ctest.process(line, app); 160 break; 161 case TestCaseAnalyzeBuiltin.makefile: 162 makefile.process(line, app); 163 break; 164 case TestCaseAnalyzeBuiltin.test_cmd: 165 break; 166 } 167 } 168 } 169 170 foreach (l; LineRange(output)) { 171 try { 172 analyzeLine(l); 173 } catch (Exception e) { 174 logger.warning("A error encountered when trying to analyze the output from the test suite. Ignoring the offending line.") 175 .collectException; 176 logger.warning(e.msg).collectException; 177 } 178 } 179 180 foreach (const p; tc_analyze_builtin) { 181 final switch (p) { 182 case TestCaseAnalyzeBuiltin.gtest: 183 gtest.finalize(app); 184 break; 185 case TestCaseAnalyzeBuiltin.ctest: 186 break; 187 case TestCaseAnalyzeBuiltin.makefile: 188 break; 189 case TestCaseAnalyzeBuiltin.test_cmd: 190 app.reportTestCmd(TestCase(cmd.toShortString)); 191 break; 192 } 193 } 194 } 195 196 struct LineRange { 197 DrainElement[] elems; 198 const(char)[] buf; 199 const(char)[] line; 200 201 const(char)[] front() @safe pure nothrow { 202 assert(!empty, "Can't get front of an empty range"); 203 return line; 204 } 205 206 void popFront() @safe nothrow { 207 assert(!empty, "Can't pop front of an empty range"); 208 import std.algorithm : countUntil; 209 210 static auto nextLine(ref const(char)[] buf) @safe nothrow { 211 const(char)[] line; 212 213 try { 214 const idx = buf.countUntil('\n'); 215 if (idx != -1) { 216 line = buf[0 .. idx]; 217 if (idx < buf.length) { 218 buf = buf[idx + 1 .. $]; 219 } else { 220 buf = null; 221 } 222 } 223 } catch (Exception e) { 224 logger.warning(e.msg).collectException; 225 logger.warning("Unable to parse the buffered data for a newline. Ignoring the rest.") 226 .collectException; 227 buf = null; 228 } 229 230 return line; 231 } 232 233 line = null; 234 while (!elems.empty && line.empty) { 235 try { 236 auto tmp = elems[0].byUTF8.array; 237 buf ~= tmp; 238 } catch (Exception e) { 239 logger.warning(e.msg).collectException; 240 logger.warning( 241 "A error encountered when trying to parse the output as UTF-8. Ignoring the offending data.") 242 .collectException; 243 } 244 elems = elems[1 .. $]; 245 line = nextLine(buf); 246 } 247 248 const s = buf.length; 249 // there are data in the buffer that may contain lines 250 if (elems.empty && !buf.empty && line.empty) { 251 line = nextLine(buf); 252 } 253 254 // the last data in the buffer. This is a special case if an 255 // application write data but do not end the last block of data with a 256 // newline. 257 // `s == buf.length` handles the case wherein there is an empty line. 258 if (elems.empty && !buf.empty && line.empty && (s == buf.length)) { 259 line = buf; 260 buf = null; 261 } 262 } 263 264 bool empty() @safe pure nothrow const @nogc { 265 return elems.empty && buf.empty && line.empty; 266 } 267 } 268 269 @("shall end the parsing of DrainElements even if the last is missing a newline") 270 unittest { 271 import std.algorithm : copy; 272 import std.array : appender; 273 274 auto app = appender!(DrainElement[])(); 275 ["foo", "bar\n", "smurf"].map!(a => DrainElement(DrainElement.Type.stdout, 276 cast(const(ubyte)[]) a)).copy(app); 277 278 auto r = LineRange(app.data); 279 280 r.empty.shouldBeFalse; 281 r.popFront; 282 r.front.shouldEqual("foobar"); 283 284 r.empty.shouldBeFalse; 285 r.popFront; 286 r.front.shouldEqual("smurf"); 287 288 r.empty.shouldBeFalse; 289 r.popFront; 290 r.empty.shouldBeTrue; 291 } 292 293 /** Run an external program that analyze the output from the test suite for 294 * test cases that failed. 295 * 296 * Params: 297 * cmd = user analyze command to execute on the output 298 * output = output from the test command to be passed on to the analyze command 299 * report = the result is stored in the report 300 * 301 * Returns: True if it successfully analyzed the output 302 */ 303 bool externalProgram(ShellCommand cmd, DrainElement[] output, 304 ref GatherTestCase report, AutoCleanup cleanup) @safe nothrow { 305 import std.datetime : dur; 306 import std.algorithm : copy; 307 import std.ascii : newline; 308 import std..string : strip, startsWith; 309 import proc; 310 311 immutable passed = "passed:"; 312 immutable failed = "failed:"; 313 immutable unstable = "unstable:"; 314 315 auto tmpdir = createTmpDir(); 316 if (tmpdir.empty) { 317 return false; 318 } 319 320 ShellCommand writeOutput(ShellCommand cmd) @safe { 321 import std.stdio : File; 322 323 const stdoutPath = buildPath(tmpdir, "stdout.log"); 324 const stderrPath = buildPath(tmpdir, "stderr.log"); 325 auto stdout = File(stdoutPath, "w"); 326 auto stderr = File(stderrPath, "w"); 327 328 foreach (a; output) { 329 final switch (a.type) { 330 case DrainElement.Type.stdout: 331 stdout.rawWrite(a.data); 332 break; 333 case DrainElement.Type.stderr: 334 stderr.rawWrite(a.data); 335 break; 336 } 337 } 338 339 cmd.value ~= [stdoutPath, stderrPath]; 340 return cmd; 341 } 342 343 try { 344 cleanup.add(tmpdir.Path.AbsolutePath); 345 cmd = writeOutput(cmd); 346 auto p = pipeProcess(cmd.value).sandbox.rcKill; 347 foreach (l; p.process.drainByLineCopy().map!(a => a.strip) 348 .filter!(a => !a.empty)) { 349 if (l.startsWith(passed)) 350 report.reportFound(TestCase(l[passed.length .. $].strip.idup)); 351 else if (l.startsWith(failed)) 352 report.reportFailed(TestCase(l[failed.length .. $].strip.idup)); 353 else if (l.startsWith(unstable)) 354 report.reportUnstable(TestCase(l[unstable.length .. $].strip.idup)); 355 } 356 357 if (p.wait == 0) { 358 return true; 359 } 360 361 logger.warningf("Failed to analyze the test case output with command '%-(%s %)'", cmd); 362 } catch (Exception e) { 363 logger.warning(e.msg).collectException; 364 } 365 366 return false; 367 } 368 369 /// Returns: path to a tmp directory or null on failure. 370 string createTmpDir() @safe nothrow { 371 import std.random : uniform; 372 import std.format : format; 373 import std.file : mkdir; 374 375 string test_tmp_output; 376 377 // try 5 times or bailout 378 foreach (const _; 0 .. 5) { 379 try { 380 auto tmp = format!"dextool_tmp_id_%s"(uniform!ulong); 381 mkdir(tmp); 382 test_tmp_output = AbsolutePath(Path(tmp)); 383 break; 384 } catch (Exception e) { 385 logger.warning(e.msg).collectException; 386 } 387 } 388 389 if (test_tmp_output.length == 0) { 390 logger.warning("Unable to create a temporary directory to store stdout/stderr in") 391 .collectException; 392 } 393 394 return test_tmp_output; 395 } 396 397 /** Paths stored will be removed automatically either when manually called or 398 * goes out of scope. 399 */ 400 class AutoCleanup { 401 private string[] remove_dirs; 402 403 void add(AbsolutePath p) @safe nothrow { 404 remove_dirs ~= cast(string) p; 405 } 406 407 // trusted: the paths are forced to be valid paths. 408 void cleanup() @trusted nothrow { 409 import std.file : rmdirRecurse, exists; 410 411 foreach (ref p; remove_dirs.filter!(a => !a.empty)) { 412 try { 413 if (exists(p)) 414 rmdirRecurse(p); 415 if (!exists(p)) 416 p = null; 417 } catch (Exception e) { 418 logger.info(e.msg).collectException; 419 } 420 } 421 422 remove_dirs = remove_dirs.filter!(a => !a.empty).array; 423 } 424 } 425 426 alias CompileResult = SumType!(Mutation.Status, bool); 427 alias PrintCompileOnFailure = NamedType!(bool, Tag!"CompileActionOnFailure", 428 bool.init, TagStringable, ImplicitConvertable); 429 430 CompileResult compile(ShellCommand cmd, Duration timeout, PrintCompileOnFailure printOnFailure) @trusted nothrow { 431 import proc; 432 import std.datetime : Clock; 433 import std.stdio : write, writeln; 434 435 const auto started = Clock.currTime; 436 // every minute print something to indicate that the process is still 437 // alive. Otherwise e.g. Jenkins may determine that it is dead. 438 auto nextTick = Clock.currTime + 1.dur!"minutes"; 439 void tick() { 440 const now = Clock.currTime; 441 if (now > nextTick) { 442 nextTick = now + 1.dur!"minutes"; 443 writeln("compiling... ", now - started); 444 } 445 } 446 447 int runCompilation(bool print) { 448 auto p = () { 449 if (cmd.value.length == 1) { 450 return pipeShell(cmd.value[0]).sandbox.timeout(timeout).rcKill; 451 } 452 return pipeProcess(cmd.value).sandbox.timeout(timeout).rcKill; 453 }(); 454 455 ulong bytes; 456 foreach (a; p.process.drain) { 457 if (!a.empty && print) { 458 write(a.byUTF8); 459 } else if (!print) { 460 tick(); 461 } 462 } 463 464 return p.wait; 465 } 466 467 try { 468 auto exitStatus = runCompilation(false); 469 if (exitStatus != 0 && printOnFailure) 470 exitStatus = runCompilation(true); 471 472 if (exitStatus != 0) 473 return CompileResult(Mutation.Status.killedByCompiler); 474 } catch (Exception e) { 475 logger.warning("Unknown error when executing the build command").collectException; 476 logger.warning(cmd.value).collectException; 477 logger.warning(e.msg).collectException; 478 return CompileResult(Mutation.Status.unknown); 479 } 480 481 return CompileResult(true); 482 } 483 484 struct TestResult { 485 Mutation.Status status; 486 ExitStatus exitStatus; 487 DrainElement[][ShellCommand] output; 488 } 489 490 /** Run the test suite to verify a mutation. 491 * 492 * Returns: the result of testing the mutant. 493 */ 494 TestResult runTester(Args...)(ref TestRunner runner, auto ref Args args) nothrow { 495 import proc; 496 497 TestResult rval; 498 try { 499 auto res = runner.run(args); 500 rval.output = res.output; 501 rval.exitStatus = res.exitStatus; 502 503 final switch (res.status) with ( 504 dextool.plugin.mutate.backend.test_mutant.test_cmd_runner.TestResult.Status) { 505 case passed: 506 rval.status = Mutation.Status.alive; 507 break; 508 case failed: 509 rval.status = Mutation.Status.killed; 510 break; 511 case timeout: 512 rval.status = Mutation.Status.timeout; 513 break; 514 case error: 515 rval.status = Mutation.Status.unknown; 516 break; 517 } 518 } catch (Exception e) { 519 // unable to for example execute the test suite 520 logger.warning(e.msg).collectException; 521 rval.status = Mutation.Status.unknown; 522 } 523 524 return rval; 525 } 526 527 void restoreFiles(AbsolutePath[] files, FilesysIO fio) { 528 foreach (a; files) { 529 fio.makeOutput(a).write(fio.makeInput(a)); 530 } 531 } 532 533 /// The conditions for when to stop mutation testing. 534 /// Intended to be re-used by both the main FSM and the sub-FSMs. 535 struct TestStopCheck { 536 import std.format : format; 537 import std.datetime.systime : Clock, SysTime; 538 import my.optional; 539 import dextool.plugin.mutate.config : ConfigMutationTest; 540 541 enum HaltReason { 542 none, 543 maxRuntime, 544 aliveTested, 545 overloaded, 546 } 547 548 private { 549 typeof(ConfigMutationTest.loadBehavior) loadBehavior; 550 typeof(ConfigMutationTest.loadThreshold) baseLoadThreshold; 551 typeof(ConfigMutationTest.loadThreshold) loadThreshold; 552 553 Optional!int maxAlive; 554 555 /// Max time to run the mutation testing for. 556 SysTime stopAt; 557 Duration maxRuntime; 558 559 long aliveMutants_; 560 } 561 562 this(ConfigMutationTest conf) { 563 loadBehavior = conf.loadBehavior; 564 loadThreshold = conf.loadThreshold; 565 baseLoadThreshold = conf.loadThreshold; 566 if (!conf.maxAlive.isNull) 567 maxAlive = some(conf.maxAlive.get); 568 stopAt = Clock.currTime + conf.maxRuntime; 569 maxRuntime = conf.maxRuntime; 570 } 571 572 void incrAliveMutants() @safe pure nothrow @nogc { 573 ++aliveMutants_; 574 } 575 576 long aliveMutants() @safe pure nothrow const @nogc { 577 return aliveMutants_; 578 } 579 580 /// A halt conditions has occured. Mutation testing should stop. 581 HaltReason isHalt() @safe nothrow { 582 if (isMaxRuntime) 583 return HaltReason.maxRuntime; 584 585 if (isAliveTested) 586 return HaltReason.aliveTested; 587 588 if (loadBehavior == ConfigMutationTest.LoadBehavior.halt && load15 > baseLoadThreshold.get) 589 return HaltReason.overloaded; 590 591 return HaltReason.none; 592 } 593 594 /// The system is overloaded and the user has configured the tool to slowdown. 595 bool isOverloaded() @safe nothrow const @nogc { 596 if (loadBehavior == ConfigMutationTest.LoadBehavior.slowdown && load15 > loadThreshold.get) 597 return true; 598 599 return false; 600 } 601 602 bool isAliveTested() @safe pure nothrow @nogc { 603 return maxAlive.hasValue && aliveMutants_ >= maxAlive.orElse(0); 604 } 605 606 bool isMaxRuntime() @safe nothrow const { 607 return Clock.currTime > stopAt; 608 } 609 610 double load15() nothrow const @nogc @trusted { 611 import my.libc : getloadavg; 612 613 double[3] load; 614 const nr = getloadavg(&load[0], 3); 615 if (nr <= 0 || nr > load.length) { 616 return 0.0; 617 } 618 return load[nr - 1]; 619 }; 620 621 /// Pause the current thread by sleeping. 622 void pause() @trusted nothrow { 623 import core.thread : Thread; 624 import std.algorithm : max; 625 626 const sleepFor = 30.dur!"seconds"; 627 logger.infof("Sleeping %s", sleepFor).collectException; 628 Thread.sleep(sleepFor); 629 630 // make it more sensitive if the system is still overloaded. 631 if (load15 > loadThreshold.get) 632 loadThreshold.get = max(1, baseLoadThreshold.get - 1); 633 else 634 loadThreshold = baseLoadThreshold; 635 } 636 637 string overloadToString() @safe const { 638 return format!"Detected overload (%s > %s)"(load15, loadThreshold.get); 639 } 640 641 string maxRuntimeToString() @safe const { 642 return format!"Max runtime of %s reached at %s"(maxRuntime, Clock.currTime); 643 } 644 } 645 646 struct HashFile { 647 import my.hash : Checksum64; 648 649 Checksum64 cs; 650 Path file; 651 } 652 653 auto hashFiles(RangeT)(RangeT files) { 654 import my.hash : makeCrc64Iso, checksum; 655 import my.file : existsAnd, isFile; 656 657 return files.filter!(a => existsAnd!isFile(Path(a))) 658 .map!((a) { 659 auto p = AbsolutePath(a); 660 auto cs = checksum!makeCrc64Iso(p); 661 return HashFile(cs, Path(a)); 662 }); 663 } 664 665 /// A runtime database of the current status of the test binaries and their checksum. 666 struct TestBinaryDb { 667 import my.hash : Checksum64; 668 import my.set : Set; 669 670 Set!Checksum64 original; 671 Mutation.Status[Checksum64] mutated; 672 673 // last added 674 Mutation.Status[Checksum64] added; 675 676 void add(Checksum64 cs, Mutation.Status status) @safe pure nothrow { 677 added[cs] = status; 678 mutated[cs] = status; 679 } 680 681 void clearAdded() @safe pure nothrow @nogc { 682 added = null; 683 } 684 685 bool empty() @safe pure nothrow const @nogc { 686 return original.empty && mutated.empty; 687 } 688 }