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.interface_; 29 import dextool.plugin.mutate.backend.test_mutant.test_case_analyze : GatherTestCase; 30 import dextool.plugin.mutate.backend.test_mutant.test_cmd_runner; 31 import dextool.plugin.mutate.config; 32 import dextool.plugin.mutate.type : TestCaseAnalyzeBuiltin, ShellCommand; 33 import dextool.type : AbsolutePath, Path; 34 35 public import dextool.plugin.mutate.backend.type : Mutation, TestCase, 36 ExitStatus, MutantTimeProfile; 37 38 version (unittest) { 39 import unit_threaded.assertions; 40 } 41 42 @safe: 43 44 /// The result of running the test suite on one mutant. 45 struct MutationTestResult { 46 import dextool.plugin.mutate.backend.database : MutationStatusId; 47 import dextool.plugin.mutate.backend.type : Mutation, TestCase, ExitStatus; 48 49 MutationStatusId id; 50 Mutation.Status status; 51 MutantTimeProfile profile; 52 TestCase[] testCases; 53 ExitStatus exitStatus; 54 55 /// commands that had an exit status other than zero. 56 ShellCommand[] testCmds; 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 if (cmd.value.empty) 436 return CompileResult(false); 437 438 const auto started = Clock.currTime; 439 // every minute print something to indicate that the process is still 440 // alive. Otherwise e.g. Jenkins may determine that it is dead. 441 auto nextTick = Clock.currTime + 1.dur!"minutes"; 442 void tick() { 443 const now = Clock.currTime; 444 if (now > nextTick) { 445 nextTick = now + 1.dur!"minutes"; 446 writeln("compiling... ", now - started); 447 } 448 } 449 450 int runCompilation(bool print) { 451 auto p = () { 452 if (cmd.value.length == 1) { 453 return pipeShell(cmd.value[0]).sandbox.timeout(timeout).rcKill; 454 } 455 return pipeProcess(cmd.value).sandbox.timeout(timeout).rcKill; 456 }(); 457 458 foreach (a; p.process.drain) { 459 if (!a.empty && print) { 460 write(a.byUTF8); 461 } else if (!print) { 462 tick(); 463 } 464 } 465 466 return p.wait; 467 } 468 469 try { 470 auto exitStatus = runCompilation(false); 471 if (exitStatus != 0 && printOnFailure) 472 exitStatus = runCompilation(true); 473 474 if (exitStatus != 0) 475 return CompileResult(Mutation.Status.killedByCompiler); 476 } catch (Exception e) { 477 logger.warning("Unknown error when executing the build command").collectException; 478 logger.warning(cmd.value).collectException; 479 logger.warning(e.msg).collectException; 480 return CompileResult(Mutation.Status.unknown); 481 } 482 483 return CompileResult(true); 484 } 485 486 struct TestResult { 487 Mutation.Status status; 488 ExitStatus exitStatus; 489 DrainElement[][ShellCommand] output; 490 } 491 492 /** Run the test suite to verify a mutation. 493 * 494 * Returns: the result of testing the mutant. 495 */ 496 TestResult runTester(Args...)(ref TestRunner runner, auto ref Args args) nothrow { 497 import proc; 498 499 TestResult rval; 500 try { 501 auto res = runner.run(args); 502 rval.output = res.output; 503 rval.exitStatus = res.exitStatus; 504 505 final switch (res.status) with ( 506 dextool.plugin.mutate.backend.test_mutant.test_cmd_runner.TestResult.Status) { 507 case passed: 508 rval.status = Mutation.Status.alive; 509 break; 510 case failed: 511 rval.status = Mutation.Status.killed; 512 break; 513 case timeout: 514 rval.status = Mutation.Status.timeout; 515 break; 516 case memOverload: 517 rval.status = Mutation.Status.memOverload; 518 break; 519 case error: 520 rval.status = Mutation.Status.unknown; 521 break; 522 } 523 } catch (Exception e) { 524 // unable to for example execute the test suite 525 logger.warning(e.msg).collectException; 526 rval.status = Mutation.Status.unknown; 527 } 528 529 return rval; 530 } 531 532 void restoreFiles(AbsolutePath[] files, FilesysIO fio) { 533 foreach (a; files) { 534 fio.makeOutput(a).write(fio.makeInput(a)); 535 } 536 } 537 538 /// The conditions for when to stop mutation testing. 539 /// Intended to be re-used by both the main FSM and the sub-FSMs. 540 struct TestStopCheck { 541 import std.format : format; 542 import std.datetime.systime : Clock, SysTime; 543 import my.optional; 544 import dextool.plugin.mutate.config : ConfigMutationTest; 545 546 enum HaltReason { 547 none, 548 maxRuntime, 549 aliveTested, 550 overloaded, 551 } 552 553 private { 554 typeof(ConfigMutationTest.loadBehavior) loadBehavior; 555 typeof(ConfigMutationTest.loadThreshold) baseLoadThreshold; 556 typeof(ConfigMutationTest.loadThreshold) loadThreshold; 557 558 Optional!int maxAlive; 559 560 /// Max time to run the mutation testing for. 561 SysTime stopAt; 562 Duration maxRuntime; 563 564 long aliveMutants_; 565 } 566 567 this(ConfigMutationTest conf) { 568 loadBehavior = conf.loadBehavior; 569 loadThreshold = conf.loadThreshold; 570 baseLoadThreshold = conf.loadThreshold; 571 if (!conf.maxAlive.isNull) 572 maxAlive = some(conf.maxAlive.get); 573 stopAt = Clock.currTime + conf.maxRuntime; 574 maxRuntime = conf.maxRuntime; 575 } 576 577 void incrAliveMutants(int number = 1) @safe pure nothrow @nogc { 578 aliveMutants_ += number; 579 } 580 581 long aliveMutants() @safe pure nothrow const @nogc { 582 return aliveMutants_; 583 } 584 585 /// A halt conditions has occured. Mutation testing should stop. 586 HaltReason isHalt() @safe nothrow { 587 if (isMaxRuntime) 588 return HaltReason.maxRuntime; 589 590 if (isAliveTested) 591 return HaltReason.aliveTested; 592 593 if (loadBehavior == ConfigMutationTest.LoadBehavior.halt && load15 > baseLoadThreshold.get) 594 return HaltReason.overloaded; 595 596 return HaltReason.none; 597 } 598 599 /// The system is overloaded and the user has configured the tool to slowdown. 600 bool isOverloaded() @safe nothrow const @nogc { 601 if (loadBehavior == ConfigMutationTest.LoadBehavior.slowdown && load15 > loadThreshold.get) 602 return true; 603 604 return false; 605 } 606 607 bool isAliveTested() @safe pure nothrow @nogc { 608 return maxAlive.hasValue && aliveMutants_ >= maxAlive.orElse(0); 609 } 610 611 bool isMaxRuntime() @safe nothrow const { 612 return Clock.currTime > stopAt; 613 } 614 615 private double[3] load() nothrow const @nogc @trusted { 616 import my.libc : getloadavg; 617 618 double[3] load; 619 const nr = getloadavg(&load[0], 3); 620 if (nr <= 0 || nr > load.length) { 621 return [0.0, 0.0, 0.0]; 622 } 623 return load; 624 }; 625 626 private double load1() @safe nothrow const @nogc { 627 return load[0]; 628 } 629 630 private double load15() @safe nothrow const @nogc { 631 return load[2]; 632 } 633 634 /// Pause the current thread by sleeping. 635 void pause(Duration sleepFor = 30.dur!"seconds") @trusted nothrow { 636 import core.thread : Thread; 637 import std.algorithm : max; 638 639 logger.infof("Sleeping %s", sleepFor).collectException; 640 Thread.sleep(sleepFor); 641 642 // make it more sensitive if the system is still overloaded. 643 if (load1 > loadThreshold.get) 644 loadThreshold.get = max(1, baseLoadThreshold.get - 1); 645 else 646 loadThreshold = baseLoadThreshold; 647 } 648 649 /// Start a background thread that will forcefully terminate the application. 650 void startBgShutdown(Duration waitFor = 10.dur!"minutes") @trusted nothrow { 651 import std.concurrency : spawnLinked, receiveTimeout, LinkTerminated, OwnerTerminated; 652 653 static void tick(Duration waitFor) @trusted nothrow { 654 import core.stdc.stdlib : exit; 655 656 const stopAt = Clock.currTime + waitFor; 657 bool parentAlive = true; 658 659 while (parentAlive && Clock.currTime < stopAt) { 660 try { 661 receiveTimeout(10.dur!"seconds", (int) {}); 662 } catch (LinkTerminated) { 663 parentAlive = false; 664 } catch (OwnerTerminated) { 665 // owner terminated thus assuming the program is progressing to a clean shutdown. 666 return; 667 } catch (Exception e) { 668 } 669 } 670 671 logger.info("Force shutdown").collectException; 672 // note: the below assumption may not be correct because if the 673 // shutdown triggers before files on disc have been restored then 674 // well. It isn't a severe problem as long as the user always setup 675 // the source code from scratch/cleanly when starting. 676 // 677 // it is not really a failure just, a workaround if other parts 678 // lockup such as a thread pool. it happens sometimes. 679 exit(0); 680 } 681 682 spawnLinked(&tick, waitFor).collectException; 683 } 684 685 string overloadToString() @safe const { 686 return format!"Detected overload (%s > %s)"(load15, loadThreshold.get); 687 } 688 689 string maxRuntimeToString() @safe const { 690 return format!"Max runtime of %s reached at %s"(maxRuntime, Clock.currTime); 691 } 692 } 693 694 struct HashFile { 695 import my.hash : Checksum64; 696 697 Checksum64 cs; 698 Path file; 699 } 700 701 auto hashFiles(RangeT)(RangeT files) nothrow { 702 import my.hash : makeCrc64Iso, checksum; 703 import my.file : existsAnd, isFile; 704 705 return files.filter!(a => existsAnd!isFile(Path(a))) 706 .map!((a) { 707 auto p = AbsolutePath(a); 708 auto cs = checksum!makeCrc64Iso(p); 709 return HashFile(cs, Path(a)); 710 }); 711 } 712 713 /// A runtime database of the current status of the test binaries and their checksum. 714 struct TestBinaryDb { 715 import my.hash : Checksum64; 716 import my.set : Set; 717 718 Set!Checksum64 original; 719 Mutation.Status[Checksum64] mutated; 720 721 // last added 722 Mutation.Status[Checksum64] added; 723 724 void add(Checksum64 cs, Mutation.Status status) @safe pure nothrow { 725 added[cs] = status; 726 mutated[cs] = status; 727 } 728 729 void clearAdded() @safe pure nothrow @nogc { 730 added = null; 731 } 732 733 bool empty() @safe pure nothrow const @nogc { 734 return original.empty && mutated.empty; 735 } 736 }