Merge pull request #5 from hanneskaeufler/hk-timeout-mutants

Hk timeout mutants

.circleci/config.yml

@@ -9,8 +9,8 @@ jobs:
       - run: shards
       - run: ./bin/static-analysis
       - run: ./bin/code-style
-      - run: ./bin/test
-      - run: ./bin/test-coverage
+      - run: SPEC_VERBOSE=1 ./bin/test
+      - run: SPEC_VERBOSE=1 ./bin/test-coverage
   test-crystal-0.26.1:
     <<: *test-template
     docker:

CHANGELOG.md

@@ -8,6 +8,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ### Added
 - This changelog
+- Avoid hanging forever by imposing a timeout for mutations
 
 ## [1.1.0] - 2018-10-23
 

README.md

@@ -135,6 +135,8 @@ I have to credit the crystal [code-coverage](https://github.com/anykeyh/crystal-
 
 One of the more difficult parts of crytic was the resolving of `require` statements. In order to work for most projects, crytic has to resolve those statements identical to the way crystal itself does. I achieved this (for now) by copying a bunch of methods from crystal-lang itself.
 
+In order to avoid dependencies for tiny amounts of savings I rather copied/adapted a bit of code from [timeout.cr](https://github.com/hugoabonizio/timeout.cr) and [crystal-diff](https://github.com/MakeNowJust/crystal-diff).
+
 Obviously I didn't invent mutation testing. While I cannot remember where I have read about it initially, my first recollection is the [mutant](https://github.com/mbj/mutant) gem for ruby.
 
 ### Alternatives

fixtures/timeout/timeout.cr

@@ -0,0 +1,5 @@
+def timeout
+  while false
+    puts "hi"
+  end
+end

fixtures/timeout/timeout_spec.cr

@@ -0,0 +1,8 @@
+require "./timeout"
+require "spec"
+
+describe "#timeout" do
+  it "returns nil" do
+    timeout.should be_nil
+  end
+end

spec/integration_spec.cr

@@ -42,6 +42,15 @@ describe Crytic do
       result.exit_code.should be > 0
     end
   end
+
+  describe "a subject that is be mutated into an endless loop" do
+    it "finishes and reports a timed out spec" do
+      result = run_crytic("-s ./fixtures/timeout/timeout.cr ./fixtures/timeout/timeout_spec.cr")
+      result.output.should contain "✅ Original test suite passed.\n"
+      result.output.should contain "1 timeout"
+      result.exit_code.should be > 0
+    end
+  end
 end
 
 def run_crytic(args : String)

spec/io_reporter_spec.cr

@@ -54,7 +54,7 @@ module Crytic
       it "prints errored mutant" do
         io = IO::Memory.new
         result = Mutation::Result.new(
-          status: Mutation::Status::Error,
+          status: Mutation::Status::Errored,
           mutant: fake_mutant,
           diff: "diff")
         IoReporter.new(io).report_result(result)
@@ -73,11 +73,13 @@ module Crytic
           Mutation::Result.new(
             status: Mutation::Status::Covered, mutant: fake_mutant, diff: "diff"),
           Mutation::Result.new(
-            status: Mutation::Status::Error, mutant: fake_mutant, diff: "diff"),
+            status: Mutation::Status::Errored, mutant: fake_mutant, diff: "diff"),
+          Mutation::Result.new(
+            status: Mutation::Status::Timeout, mutant: fake_mutant, diff: "diff"),
         ]
         IoReporter.new(io).report_summary(results)
         io.to_s.should contain "Finished in"
-        io.to_s.should contain "3 mutations, 1 covered, 1 uncovered, 1 errored. Mutation score: 33.33%"
+        io.to_s.should contain "4 mutations, 1 covered, 1 uncovered, 1 errored, 1 timeout. Mutation score: 25.0%"
       end
 
       it "has a N/A score for 0 results" do

spec/mutation/fake_process_runner.cr

@@ -2,23 +2,35 @@ require "../../src/crytic/process_runner"
 
 module Crytic
   class FakeProcessRunner < ProcessRunner
-    getter cmd
-    getter args
+    private getter cmd
+    private getter args
     property exit_code
-    @args : String = ""
+    property timeout
+    @timeout = [] of Time::Span
+    @cmd = [] of String
+    @args = [] of String
     @output_io = IO::Memory.new
 
+    def cmd_with_args
+      cmd.zip(args).map { |c, a| "#{c} #{a}".strip }
+    end
+
     def initialize
       @exit_code = 0
     end
 
     def run(cmd : String, args : Array(String), output, error)
-      @cmd = cmd
-      @args = args.join(" ")
+      @cmd << cmd
+      @args << args.join(" ")
       output << @output_io.to_s
       @exit_code
     end
 
+    def run(cmd : String, args : Array(String), output, error, timeout)
+      @timeout << timeout
+      run(cmd, args, output, error)
+    end
+
     def fill_output_with(text : String)
       @output_io << text
     end

spec/mutation/mutation_spec.cr

@@ -12,6 +12,26 @@ private def mutant
   ))
 end
 
+class FakeFile
+  @@files_deleted = [] of String
+  @@tempfiles_created = [] of String
+  @@tempfile_contents = [] of String
+
+  def self.tempfile_contents
+    @@tempfile_contents
+  end
+
+  def self.delete(filename : String)
+  end
+
+  def self.tempfile(name, extension, content) : String
+    filename = "#{name}.RANDOM#{extension}"
+    @@tempfile_contents << content
+    @@tempfiles_created << filename
+    "/tmp/#{filename}"
+  end
+end
+
 module Crytic::Mutation
   describe Mutation do
     Spec.before_each do
@@ -28,19 +48,22 @@ module Crytic::Mutation
     end
 
     describe "#run" do
-      it "evals the mutated code in a separate process" do
+      it "shoves the code into a tempfile, compiles the binary and executes the binary" do
         mutation = Mutation.with(
           mutant,
           "./fixtures/simple/bar.cr",
           ["./fixtures/simple/bar_spec.cr"])
 
         fake = FakeProcessRunner.new
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
         mutation.run.should be_a(Crytic::Mutation::Result)
-        fake.cmd.should eq "crystal"
-        fake.args.should eq <<-CODE
-        eval # require of `fixtures/simple/bar.cr` from `fixtures/simple/bar_spec.cr:1`
+        fake.cmd_with_args[-2].should eq "crystal build -o /tmp/crytic.RANDOM --no-debug /tmp/crytic.RANDOM.cr"
+        fake.cmd_with_args.last.should eq "/tmp/crytic.RANDOM"
+        FakeFile.tempfile_contents.last.should eq <<-CODE
+        # require of `fixtures/simple/bar.cr` from `fixtures/simple/bar_spec.cr:1`
         def bar
           if false
             2
@@ -68,6 +91,8 @@ module Crytic::Mutation
         fake.exit_code = 1
         fake.fill_output_with("Finished")
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
         mutation.run.status.should eq Status::Covered
       end
@@ -81,6 +106,8 @@ module Crytic::Mutation
         fake = FakeProcessRunner.new
         fake.exit_code = 0
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
         mutation.run.status.should eq Status::Uncovered
       end
@@ -94,6 +121,8 @@ module Crytic::Mutation
         fake = FakeProcessRunner.new
         fake.exit_code = 0
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
         mutation.run.diff.should eq <<-DIFF
         @@ -1,5 +1,5 @@\n def bar\n\e[31m-\e[0m\e[31m  if true\e[0m\n\e[32m+\e[0m\e[32m  if false\e[0m\n     2\n   else\n     3\n
@@ -109,11 +138,12 @@ module Crytic::Mutation
         fake = FakeProcessRunner.new
         fake.exit_code = 0
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
         mutation.run
-        fake.cmd.should eq "crystal"
-        fake.args.should eq <<-CODE
-        eval # require of `fixtures/simple/spec_helper.cr` from `fixtures/simple/bar_with_helper_spec.cr:1`
+        FakeFile.tempfile_contents.last.should eq <<-CODE
+        # require of `fixtures/simple/spec_helper.cr` from `fixtures/simple/bar_with_helper_spec.cr:1`
         require "http"
         # require of `fixtures/simple/bar.cr` from `fixtures/simple/spec_helper.cr:2`
         def bar
@@ -142,11 +172,13 @@ module Crytic::Mutation
 
         fake = FakeProcessRunner.new
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
         mutation.run
 
-        fake.args.should eq <<-CODE
-        eval # require of `fixtures/simple/spec_helper.cr` from `fixtures/simple/bar_with_helper_spec.cr:1`
+        FakeFile.tempfile_contents.last.should eq <<-CODE
+        # require of `fixtures/simple/spec_helper.cr` from `fixtures/simple/bar_with_helper_spec.cr:1`
         require "http"
         # require of `fixtures/simple/bar.cr` from `fixtures/simple/spec_helper.cr:2`
         def bar
@@ -185,8 +217,26 @@ module Crytic::Mutation
         fake.exit_code = 1
         fake.fill_output_with("compiler error/ no specs have run")
         mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
+
+        mutation.run.status.should eq Status::Errored
+      end
+
+      it "reports timed out mutations" do
+        mutation = Mutation.with(
+          mutant,
+          "./fixtures/simple/bar.cr",
+          ["./fixtures/simple/bar_with_helper_spec.cr"])
+
+        fake = FakeProcessRunner.new
+        fake.exit_code = 28
+        mutation.process_runner = fake
+        mutation.file_remover = ->FakeFile.delete(String)
+        mutation.tempfile_writer = ->FakeFile.tempfile(String, String, String)
 
-        mutation.run.status.should eq Status::Error
+        mutation.run.status.should eq Status::Timeout
+        fake.timeout.last.should eq 10.seconds
       end
     end
   end

spec/mutation/no_mutation_spec.cr

@@ -11,8 +11,7 @@ module Crytic::Mutation
         mutation.process_runner = fake
         mutation.run
 
-        fake.cmd.should eq "crystal"
-        fake.args.should eq "spec ./single/test_spec.cr"
+        fake.cmd_with_args.last.should eq "crystal spec ./single/test_spec.cr"
       end
 
       it "runs crystal spec with multiple spec files" do
@@ -21,8 +20,7 @@ module Crytic::Mutation
         mutation.process_runner = fake
         mutation.run
 
-        fake.cmd.should eq "crystal"
-        fake.args.should eq "spec ./a/b_spec.cr ./a/c_spec.cr"
+        fake.cmd_with_args.last.should eq "crystal spec ./a/b_spec.cr ./a/c_spec.cr"
       end
     end
   end

spec/process_process_runner_spec.cr

@@ -0,0 +1,27 @@
+require "../src/crytic/process_process_runner"
+require "./spec_helper"
+
+module Crytic
+  describe ProcessProcessRunner do
+    describe "#run" do
+      it "runs arbitrary commands and returns the exit code" do
+        io = IO::Memory.new
+        code = ProcessProcessRunner.new.run("true", [] of String, io, io)
+        code.should eq 0
+      end
+
+      it "can run commands with arguments" do
+        io = IO::Memory.new
+        code = ProcessProcessRunner.new.run("/bin/sh", ["-c", "exit 123"], io, io)
+        code.should eq 123
+      end
+
+      it "times out after the given period" do
+        io = IO::Memory.new
+        code = ProcessProcessRunner.new.run("/bin/bash", ["-c", "while true; do echo hi; sleep 1; done"], io, io, timeout: 10.milliseconds)
+        code.should eq 28
+        io.to_s.should contain "hi"
+      end
+    end
+  end
+end

spec/spec_helper.cr

@@ -1,3 +1 @@
 require "spec"
-
-Spec.override_default_formatter(Spec::VerboseFormatter.new)

src/crytic/io_reporter.cr

@@ -19,24 +19,30 @@ module Crytic
     end
 
     def report_result(result)
+      @io << "\n#{INDENT}"
       case result.status
-      when Mutation::Status::Error
-        @io << "\n#{INDENT}"
+      when Mutation::Status::Errored
         @io << "❌ #{result.mutant_name}"
         @io << "\n#{INDENT + INDENT}The following change broke the code:\n"
         @io << "#{INDENT + INDENT + INDENT}"
         @io << result.diff.lines.join("\n#{INDENT + INDENT + INDENT}")
         @io << "\n"
       when Mutation::Status::Uncovered
-        @io << "\n#{INDENT}"
         @io << "❌ #{result.mutant_name}"
         @io << "\n#{INDENT + INDENT}The following change didn't fail the test-suite:\n"
         @io << "#{INDENT + INDENT + INDENT}"
         @io << result.diff.lines.join("\n#{INDENT + INDENT + INDENT}")
         @io << "\n"
       when Mutation::Status::Covered
-        @io << "\n#{INDENT}"
         @io << "✅ #{result.mutant_name} at line #{result.location.line_number}, column #{result.location.column_number}"
+      when Mutation::Status::Timeout
+        @io << "❌ #{result.mutant_name}"
+        @io << "\n#{INDENT + INDENT}The following change timed out:\n"
+        @io << "#{INDENT + INDENT + INDENT}"
+        @io << result.diff.lines.join("\n#{INDENT + INDENT + INDENT}")
+        @io << "\n"
+      else
+        raise "There were mutations of unreported type"
       end
     end
 
@@ -45,7 +51,8 @@ module Crytic
       summary = "#{results.size} mutations, "
       summary += "#{results.map(&.status).count(&.covered?)} covered, "
       summary += "#{results.map(&.status).count(&.uncovered?)} uncovered, "
-      summary += "#{results.map(&.status).count(&.errored?)} errored."
+      summary += "#{results.map(&.status).count(&.errored?)} errored, "
+      summary += "#{results.map(&.status).count(&.timeout?)} timeout."
       summary += " Mutation score: #{score_in_percent(results)}"
       summary += "\n"
       @io << summary.colorize(results.map(&.status.covered?).all? ? :green : :red).to_s