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