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 }