improve debuggability of cache.up_to_date? - close #46

build_tests/simple/cache_debugging.rb

@@ -0,0 +1,34 @@
+class DebugBuilder < Rscons::Builder
+  def run(options)
+    target, sources, cache, env, vars = options.values_at(:target, :sources, :cache, :env, :vars)
+    command = %W[gcc -c -o #{target} #{sources.first}]
+    if ENV["command_change"]
+      command += %w[-Wall]
+    end
+    if ENV["new_dep"]
+      sources += ["extra"]
+    end
+    if ENV["strict_deps1"]
+      sources += ["extra"]
+      strict_deps = true
+    end
+    if ENV["strict_deps2"]
+      sources = ["extra"] + sources
+      strict_deps = true
+    end
+    unless cache.up_to_date?(target, command, sources, env, debug: true, strict_deps: strict_deps)
+      desc = "#{self.class.name} #{target}"
+      return false unless env.execute(desc, command)
+      cache.register_build(target, command, sources, env)
+    end
+    target
+  end
+end
+
+Rscons::Environment.new do |env|
+  env.add_builder(DebugBuilder.new)
+  if ENV["new_user_dep"]
+    env.depends("foo.o", "new_dep")
+  end
+  env.DebugBuilder("foo.o", "simple.c")
+end

lib/rscons/cache.rb

@@ -133,39 +133,79 @@ module Rscons
 
         unless Rscons.phony_target?(target)
           # target file must exist on disk
-          return false unless File.exists?(target)
+          unless File.exists?(target)
+            if options[:debug]
+              puts "Target #{target} needs rebuilding because it does not exist on disk"
+            end
+            return false
+          end
         end
 
         # target must be registered in the cache
-        return false unless @cache["targets"].has_key?(cache_key)
+        unless @cache["targets"].has_key?(cache_key)
+          if options[:debug]
+            puts "Target #{target} needs rebuilding because there is no cached build information for it"
+          end
+          return false
+        end
 
         unless Rscons.phony_target?(target)
           # target must have the same checksum as when it was built last
-          return false unless @cache["targets"][cache_key]["checksum"] == lookup_checksum(target)
+          unless @cache["targets"][cache_key]["checksum"] == lookup_checksum(target)
+            if options[:debug]
+              puts "Target #{target} needs rebuilding because it has been changed on disk since being built last"
+            end
+            return false
+          end
         end
 
         # command used to build target must be identical
-        return false unless @cache["targets"][cache_key]["command"] == Digest::MD5.hexdigest(command.inspect)
+        unless @cache["targets"][cache_key]["command"] == Digest::MD5.hexdigest(command.inspect)
+          if options[:debug]
+            puts "Target #{target} needs rebuilding because the command used to build it has changed"
+          end
+          return false
+        end
 
         cached_deps = @cache["targets"][cache_key]["deps"] || []
         cached_deps_fnames = cached_deps.map { |dc| dc["fname"] }
         if options[:strict_deps]
           # depedencies passed in must exactly equal those in the cache
-          return false unless deps == cached_deps_fnames
+          unless deps == cached_deps_fnames
+            if options[:debug]
+              puts "Target #{target} needs rebuilding because the :strict_deps option is given and the set of dependencies does not match the previous set of dependencies"
+            end
+            return false
+          end
         else
           # all dependencies passed in must exist in cache (but cache may have more)
-          return false unless (Set.new(deps) - Set.new(cached_deps_fnames)).empty?
+          unless (Set.new(deps) - Set.new(cached_deps_fnames)).empty?
+            if options[:debug]
+              puts "Target #{target} needs rebuilding because there are new dependencies"
+            end
+            return false
+          end
         end
 
         # set of user dependencies must match
         user_deps = env.get_user_deps(target) || []
         cached_user_deps = @cache["targets"][cache_key]["user_deps"] || []
         cached_user_deps_fnames = cached_user_deps.map { |dc| dc["fname"] }
-        return false unless user_deps == cached_user_deps_fnames
+        unless user_deps == cached_user_deps_fnames
+          if options[:debug]
+            puts "Target #{target} needs rebuilding because the set of user-specified dependency files has changed"
+          end
+          return false
+        end
 
         # all cached dependencies must have their checksums match
         (cached_deps + cached_user_deps).each do |dep_cache|
-          return false unless dep_cache["checksum"] == lookup_checksum(dep_cache["fname"])
+          unless dep_cache["checksum"] == lookup_checksum(dep_cache["fname"])
+            if options[:debug]
+              puts "Target #{target} needs rebuilding because dependency file #{dep_cache["fname"]} has changed"
+            end
+            return false
+          end
         end
       end
 

spec/build_tests_spec.rb

@@ -91,6 +91,7 @@ end
 $LOAD_PATH.unshift(#{@owd.inspect} + "/lib")
 # force color off
 ENV["TERM"] = nil
+#{options[:ruby_setup_code]}
 EOF
     end
     stdout, stderr, status = nil, nil, nil
@@ -1273,6 +1274,69 @@ EOF
       expect(result.stderr).to eq ""
       expect(result.stdout).to eq ""
     end
+
+    context "debugging" do
+      it "prints a message when the target does not exist" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because it does not exist on disk/
+      end
+
+      it "prints a message when there is no cached build information for the target" do
+        test_dir("simple")
+        FileUtils.touch("foo.o")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because there is no cached build information for it/
+      end
+
+      it "prints a message when the target file has changed on disk" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        File.open("foo.o", "wb") {|fh| fh.puts "hi"}
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because it has been changed on disk since being built last/
+      end
+
+      it "prints a message when the command has changed" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        result = run_test(rsconsfile: "cache_debugging.rb", ruby_setup_code: %[ENV["command_change"] = "yes"])
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because the command used to build it has changed/
+      end
+
+      it "prints a message when strict_deps is in use and the set of dependencies does not match" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb", ruby_setup_code: %[ENV["strict_deps1"] = "yes"])
+        result = run_test(rsconsfile: "cache_debugging.rb", ruby_setup_code: %[ENV["strict_deps2"] = "yes"])
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because the :strict_deps option is given and the set of dependencies does not match the previous set of dependencies/
+      end
+
+      it "prints a message when there is a new dependency" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        result = run_test(rsconsfile: "cache_debugging.rb", ruby_setup_code: %[ENV["new_dep"] = "yes"])
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because there are new dependencies/
+      end
+
+      it "prints a message when there is a new user-specified dependency" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        result = run_test(rsconsfile: "cache_debugging.rb", ruby_setup_code: %[ENV["new_user_dep"] = "yes"])
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because the set of user-specified dependency files has changed/
+      end
+
+      it "prints a message when a dependency file has changed" do
+        test_dir("simple")
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        f = File.read("simple.c", mode: "rb")
+        f += "\n"
+        File.open("simple.c", "wb") do |fh|
+          fh.write(f)
+        end
+        result = run_test(rsconsfile: "cache_debugging.rb")
+        expect(result.stdout).to match /Target foo\.o needs rebuilding because dependency file simple\.c has changed/
+      end
+    end
   end
 
   context "Object builder" do