Make template evaluation be strict (fails fast on invalid variable or…

… filter references), benchmark run loop

lib/kubetruth/etl.rb

@@ -4,11 +4,15 @@
 require_relative 'kubeapi'
 require 'active_support/core_ext/hash/keys'
 require 'liquid'
+require 'benchmark'
 
 module Kubetruth
   class ETL
     include GemLogger::LoggerSupport
 
+    class TemplateError < ::StandardError
+    end
+
     module CustomLiquidFilters
 
       # From kubernetes error message
@@ -81,17 +85,22 @@ def with_polling(interval, &block)
               logger.debug "CRD watcher exiting"
             end
 
-            begin
-              block.call
-            rescue => e
-              logger.log_exception(e, "Failure while applying config transforms")
+            run_time = Benchmark.measure do
+              begin
+                block.call
+              rescue TemplateError => e
+                logger.error e.message
+              rescue => e
+                logger.log_exception(e, "Failure while applying config transforms")
+              end
             end
+            logger.info "Benchmark: #{run_time}"
 
-            logger.debug("Poller sleeping for #{interval}")
+            logger.info("Poller sleeping for #{interval}")
             interruptible_sleep(interval)
           ensure
             watcher.finish
-            thr.join
+            thr.join(5)
           end
 
         rescue => e
@@ -102,7 +111,14 @@ def with_polling(interval, &block)
     end
 
     def template_eval(tmpl, **kwargs)
-      Liquid::Template.parse(tmpl).render(**kwargs.stringify_keys)
+      begin
+        logger.debug { "Evaluating template '#{tmpl}' with context: #{kwargs.inspect}" }
+        Liquid::Template.parse(tmpl, error_mode: :strict).render!(kwargs.stringify_keys, strict_variables: true, strict_filters: true)
+      rescue Liquid::Error => e
+        msg = "Invalid template '#{tmpl}': #{e.message}"
+        msg << ", context: #{kwargs.inspect}" if e.is_a?(Liquid::UndefinedVariable)
+        raise TemplateError.new(msg)
+      end
     end
 
     def load_config
@@ -137,7 +153,6 @@ def apply
         match = project.match(project_spec.project_selector)
         matches_hash = matches_hash.merge(match.named_captures.symbolize_keys)
         matches_hash[:project] = project unless matches_hash.has_key?(:project)
-        matches_hash = Hash[*matches_hash.collect {|k, v| [k, v, "#{k}_upcase".to_sym, v.upcase]}.flatten]
 
         project_data[project] ||= {}
         project_data[project][:namespace] = template_eval(project_spec.namespace_template, **matches_hash)
@@ -202,7 +217,6 @@ def get_params(project, project_spec, template_matches: {})
         if matches = param.key.match(project_spec.key_selector)
           matches_hash = matches.named_captures.symbolize_keys
           matches_hash[:key] = param.key unless matches_hash.has_key?(:key)
-          matches_hash = Hash[*matches_hash.collect {|k, v| [k, v, "#{k}_upcase".to_sym, v.upcase]}.flatten]
           matches_hash = template_matches.merge(matches_hash)
 
           logger.debug {"Pattern matches '#{param.key}' with: #{matches_hash}"}

spec/kubetruth/etl_spec.rb

@@ -249,6 +249,11 @@ class ForceExit < Exception; end
         expect(etl.template_eval("hello {{foo | env_safe}}", foo: "bar")).to eq("hello BAR")
       end
 
+      it "fails fast" do
+        expect { etl.template_eval("{{foo}}") }.to raise_error(Kubetruth::ETL::TemplateError)
+        expect { etl.template_eval("{{foo | nofilter}}", foo: "bar") }.to raise_error(Kubetruth::ETL::TemplateError)
+      end
+
     end
 
     describe "#load_config" do
@@ -317,18 +322,6 @@ class ForceExit < Exception; end
                              ])
       end
 
-      it "has a number of template options" do
-        expect(@ctapi).to receive(:parameters).with(searchTerm: "", project: "foo").and_return([
-          Parameter.new(key: "svc.name1.key1", value: "value1", secret: false),
-        ])
-        project_spec.key_selector = /^(?<prefix>[^\.]+)\.(?<name>[^\.]+)\.(?<key>.*)/
-        project_spec.key_template = "start.{{key}}.{{name}}.{{prefix}}.middle.{{key_upcase}}.{{name_upcase}}.{{prefix_upcase}}.end"
-        params = etl.get_params(project, project_spec)
-        expect(params).to eq([
-                               Parameter.new(original_key: "svc.name1.key1", key: "start.key1.name1.svc.middle.KEY1.NAME1.SVC.end", value: "value1", secret: false)
-                             ])
-      end
-
       it "doesn't expose secret in debug log" do
         Logging.setup_logging(level: :debug, color: false)