Merge pull request #19 from ohbarye/verbose-mode

Verbose mode

CHANGELOG.md

@@ -1,5 +1,7 @@
 ## [Unreleased]
 
+- Add verbose mode. It's useful to debug the test case.
+
 ## [0.1.1] - 2024-04-14
 
 - Change default worker from `:ractor` to `:none`

README.md

@@ -107,7 +107,7 @@ There are many built-in arbitraries in `Pbt`. You can use them to generate rando
 #### Primitives
 
 ```ruby
-rng = Random.new(
+rng = Random.new
 
 Pbt.integer.generate(rng) # => 42
 Pbt.integer(min: -1, max: 8).generate(rng) # => Integer between -1 and 8
@@ -139,6 +139,71 @@ Pbt.one_of(:a, 1, 0.1).generate(rng) # => :a or 1 or 0.1
 
 See [ArbitraryMethods](https://github.com/ohbarye/pbt/blob/main/lib/pbt/arbitrary/arbitrary_methods.rb) module for more details.
 
+## What if property-based tests fail?
+
+Once a test fails it's time to debug. `Pbt` provides some features to help you debug.
+
+### How to reproduce
+
+When a test fails, you'll see a message like below.
+
+```text
+Pbt::PropertyFailure:
+  Property failed after 23 test(s)
+  { seed: 11001296583699917659214176011685741769 }
+  Counterexample: 0
+  Shrunk 3 time(s)
+  Got ZeroDivisionError: divided by 0
+  # and backtraces
+```
+
+You can reproduce the failure by passing the seed to `Pbt.assert`.
+
+```ruby
+Pbt.assert(seed: 11001296583699917659214176011685741769) do
+  Pbt.property(Pbt.integer) do |number|
+    # your test
+  end
+end
+```
+
+### Verbose mode
+
+You may want to know which values pass and which values fail. You can enable verbose mode by passing `verbose: true` to `Pbt.assert`.
+
+```ruby
+Pbt.assert(verbose: true) do
+  Pbt.property(Pbt.array(Pbt.integer)) do |numbers|
+    # your failed test
+  end
+end
+```
+
+The verbose mode prints the results of each tested values.
+
+```text
+Encountered failures were:
+- [152477, 666997, -531468, -92182, 623948, 425913, 656138, 856463, -64529]
+- [76239, 666997, -531468, -92182, 623948]
+- [76239, 666997, -531468]
+(snipped for README)
+- [2, 163]
+- [2, 11]
+
+Execution summary:
+. × [152477, 666997, -531468, -92182, 623948, 425913, 656138, 856463, -64529]
+. . √ [152477, 666997, -531468, -92182, 623948]
+. . √ [-64529]
+. . × [76239, 666997, -531468, -92182, 623948, 425913, 656138, 856463, -64529]
+. . . × [76239, 666997, -531468, -92182, 623948]
+(snipped for README)
+. . . . . . . . . . . . . . . . . √ [2, 21]
+. . . . . . . . . . . . . . . . . × [2, 11]
+. . . . . . . . . . . . . . . . . . √ []
+. . . . . . . . . . . . . . . . . . √ [2, 1]
+. . . . . . . . . . . . . . . . . . √ [2, 0]
+```
+
 ## Configuration
 
 You can configure `Pbt` by calling `Pbt.configure` before running tests.

lib/pbt/check/runner_iterator.rb

@@ -51,7 +51,7 @@ def handle_result(c)
           @next_values = @property.shrink(c.val)
         else
           # successful run
-          @run_execution.record_success
+          @run_execution.record_success(c)
         end
       end
     end

lib/pbt/reporter/run_details.rb

@@ -14,6 +14,7 @@ module Reporter
       :error_instance,
       :failures,
       :verbose,
+      :execution_summary,
       :run_configuration,
       keyword_init: true
     )

lib/pbt/reporter/run_details_reporter.rb

@@ -16,24 +16,85 @@ def initialize(run_details)
       def report_run_details
         if @run_details.failed
           message = []
-
-          message << <<~EOS
-            Property failed after #{@run_details.num_runs} test(s)
-            { seed: #{@run_details.seed} }
-            Counterexample: #{@run_details.counterexample}
-            Shrunk #{@run_details.num_shrinks} time(s)
-            Got #{@run_details.error_instance.class}: #{@run_details.error_message}
-          EOS
-
-          if @run_details.verbose
-            message << "  \n#{@run_details.error_instance.backtrace_locations.join("\n    ")}"
-            message << "\nEncountered failures were:"
-            message << @run_details.failures.map { |f| "- #{f.val}" }
+          message << format_error_message
+          message << error_backtrace
+          message << if @run_details.verbose
+            verbose_details
+          else
+            hint
           end
 
           raise PropertyFailure, message.join("\n") if message.size > 0
         end
       end
+
+      private
+
+      # @return [String]
+      def format_error_message
+        <<~MSG.chomp
+          Property failed after #{@run_details.num_runs} test(s)
+          { seed: #{@run_details.seed} }
+          Counterexample: #{@run_details.counterexample}
+          Shrunk #{@run_details.num_shrinks} time(s)
+          Got #{@run_details.error_instance.class}: #{@run_details.error_message}
+        MSG
+      end
+
+      def error_backtrace
+        i = @run_details.verbose ? -1 : 10
+        "    #{@run_details.error_instance.backtrace_locations[..i].join("\n    ")}"
+      end
+
+      # @return [String]
+      def verbose_details
+        [
+          "\nEncountered failures were:",
+          @run_details.failures.map { |f| "- #{f.val}" },
+          format_execution_summary
+        ].join("\n")
+      end
+
+      # @return [String]
+      def format_execution_summary
+        summary_lines = []
+        remaining_trees_and_depth = []
+
+        @run_details.execution_summary.reverse_each do |tree|
+          remaining_trees_and_depth << {depth: 1, tree:}
+        end
+
+        until remaining_trees_and_depth.empty?
+          current_tree_and_depth = remaining_trees_and_depth.pop
+
+          # format current tree according to its depth and result
+          current_tree = current_tree_and_depth[:tree]
+          current_depth = current_tree_and_depth[:depth]
+          result_icon = case current_tree.result
+          in :success
+            "\x1b[32m\u221A\x1b[0m" # green "√"
+          in :failure
+            "\x1b[31m\u00D7\x1b[0m" # red "×"
+          end
+          left_padding = ". " * current_depth
+          summary_lines << "#{left_padding}#{result_icon} #{current_tree.value}"
+
+          # push its children to the queue
+          current_tree.children.reverse_each do |tree|
+            remaining_trees_and_depth << {depth: current_depth + 1, tree:}
+          end
+        end
+
+        "\nExecution summary:\n#{summary_lines.join("\n")}\n"
+      end
+
+      # @return [String]
+      def hint
+        [
+          "\nHint: Set `verbose: true` in order to check the list of all failing values encountered during the run.",
+          "Hint: Set `seed: #{@run_details.seed}` in order to reproduce the failed test case with the same values."
+        ].join("\n")
+      end
     end
   end
 end

lib/pbt/reporter/run_execution.rb

@@ -6,19 +6,33 @@ module Pbt
   module Reporter
     # Represents the result of a single run of a property test.
     class RunExecution
+      # A tree node of the execution for verbose output.
+      ExecutionTreeNode = Struct.new(
+        :result,
+        :value,
+        :children,
+        keyword_init: true
+      )
+
       # @param verbose [Boolean] Whether to print verbose output.
       def initialize(verbose)
         @verbose = verbose
         @path_to_failure = []
         @failure = nil
         @failures = []
         @num_successes = 0
+        @root_execution_trees = []
+        @current_level_execution_trees = @root_execution_trees
       end
 
       # Record a failure in the run.
       #
       # @param c [Pbt::Check::Case]
       def record_failure(c)
+        if @verbose
+          current_tree = append_execution_tree_node(:failure, c.val)
+          @current_level_execution_trees = current_tree.children
+        end
         @path_to_failure << c.index
         @failures << c
 
@@ -29,8 +43,12 @@ def record_failure(c)
 
       # Record a successful run.
       #
+      # @param c [Pbt::Check::Case]
       # @return [void]
-      def record_success
+      def record_success(c)
+        if @verbose
+          append_execution_tree_node(:success, c.val)
+        end
         @num_successes += 1
       end
 
@@ -58,6 +76,7 @@ def to_run_details(config)
             error_instance: nil,
             failures: @failures,
             verbose: @verbose,
+            execution_summary: @root_execution_trees,
             run_configuration: config
           )
         else
@@ -72,10 +91,22 @@ def to_run_details(config)
             error_instance: @failure,
             failures: @failures,
             verbose: @verbose,
+            execution_summary: @root_execution_trees,
             run_configuration: config
           )
         end
       end
+
+      private
+
+      # @param result [Symbol] The result of the current node.
+      # @param value [Object] The value to test.
+      # @return [Hash] The current execution tree.
+      def append_execution_tree_node(result, value)
+        current_tree = ExecutionTreeNode.new(result:, value:, children: [])
+        @current_level_execution_trees << current_tree
+        current_tree
+      end
     end
   end
 end