lib/sqreen/instrumentation.rb in sqreen-alt-1.11.0 vs lib/sqreen/instrumentation.rb in sqreen-alt-1.11.1

- old
+ new

@@ -1,16 +1,17 @@ # Copyright (c) 2015 Sqreen. All Rights Reserved. # Please refer to our terms for more information: https://www.sqreen.io/terms.html require 'sqreen/callback_tree' require 'sqreen/log' -require 'sqreen/stats' require 'sqreen/exception' require 'sqreen/performance_notifications' require 'sqreen/call_countable' require 'sqreen/events/remote_exception' require 'sqreen/rules_signature' +require 'sqreen/shared_storage' +require 'sqreen/rules_callbacks/record_request_context' require 'set' # How to override a class method: # # class Cache @@ -31,17 +32,20 @@ # alias_method :get, :get_modified # end module Sqreen class Instrumentation - WHITELISTED_METRIC='whitelisted'.freeze - OVERTIME_METRIC='request_overtime'.freeze + OVERTIME_METRIC = 'request_overtime'.freeze + MGMT_COST = 0.000025 @@override_semaphore = Mutex.new + @@overriden_singleton_methods = false ## Overriden methods and callbacks globals @@overriden_methods = [] @@registered_callbacks = CBTree.new + @@unovertimable_hookpoints = Set.new + @@record_request_hookpoints = Set.new @@instrumented_pid = nil def self.semaphore @@override_semaphore end @@ -55,284 +59,336 @@ end def self.overriden @@overriden_methods end - - def self.callback_wrapper_pre(klass, method, instance, *args, &block) - Instrumentation.guard_call(method, []) do - callbacks = @@registered_callbacks.get(klass, method, :pre) - if callbacks.any?(&:whitelisted?) - callbacks = callbacks.reject(&:whitelisted?) - end - - cb_with_framework = callbacks.find(&:framework) - budget = nil - budget = cb_with_framework.framework.remaining_perf_budget if cb_with_framework + def self.callback_wrapper_pre(callbacks, framework, budget, _klass, method, instance, args, &block) + all_start = Sqreen::PerformanceNotifications.time + #Instrumentation.guard_call(method, []) do returns = [] callbacks.each do |cb| # If record_request is part of callbacks we should filter after it ran next if cb.whitelisted? rule = cb.rule_name if cb.respond_to?(:rule_name) - if !budget.nil? && budget <= 0 - next if cb.overtime! + if budget && budget <= 0.0 + next if cb.overtimeable end Sqreen.log.debug { "running pre cb #{cb}" } begin start = Sqreen::PerformanceNotifications.time - res = cb.send(:pre, instance, *args, &block) + res = cb.pre(instance, args, budget, &block) stop = Sqreen::PerformanceNotifications.time # The first few pre callbacks could not have a request & hence a budget just yet so we try harder to find it - budget = cb_with_framework.framework.remaining_perf_budget if budget.nil? && !Sqreen.performance_budget.nil? && cb.framework - budget -= (stop - start) unless budget.nil? + budget = framework.remaining_perf_budget if framework && !budget && Sqreen.performance_budget + if budget + budget -= (stop - start) + cb.overtime! if budget <= 0.0 + end + all_start += (stop - start) if !res.nil? && cb.respond_to?(:block) && (!cb.block && !Sqreen.config_get(:block_all_rules)) Sqreen.log.debug do "#{cb} cannot block, overriding return value" end res = nil elsif res.is_a?(Hash) res[:rule_name] = rule end returns << res rescue StandardError => e - Sqreen.log.warn "we catch an exception: #{e.inspect}" + Sqreen.log.warn { "we catch an exception: #{e.inspect}" } Sqreen.log.debug e.backtrace if cb.respond_to?(:record_exception) cb.record_exception(e) else Sqreen::RemoteException.record(e) end next end Sqreen::PerformanceNotifications.notify("Callbacks/#{rule || cb.class.name}/pre", start, stop) end - cb_with_framework.framework.remaining_perf_budget=budget if cb_with_framework && !budget.nil? + all_stop = Sqreen::PerformanceNotifications.time + framework.remaining_perf_budget = budget - (all_stop - all_start) - MGMT_COST * callbacks.size if framework && budget + Sqreen::PerformanceNotifications.notify('Callbacks/hooks_pre/pre', all_start, all_stop) returns - end + #end rescue StandardError => e - Sqreen.log.warn "we catched an exception between cbs: #{e.inspect}" + Sqreen.log.warn { "we catched an exception between cbs: #{e.inspect}" } Sqreen::RemoteException.record(e) + [] end - def self.callback_wrapper_post(klass, method, return_val, instance, *args, &block) - Instrumentation.guard_call(method, []) do - callbacks = @@registered_callbacks.get(klass, method, :post) - if callbacks.any?(&:whitelisted?) - callbacks = callbacks.reject(&:whitelisted?) - end - - cb_with_framework = callbacks.find(&:framework) - budget = nil - budget = cb_with_framework.framework.remaining_perf_budget if cb_with_framework + def self.callback_wrapper_post(callbacks, framework, budget, _klass, method, return_val, instance, args, &block) + all_start = Sqreen::PerformanceNotifications.time + #Instrumentation.guard_call(method, []) do returns = [] callbacks.reverse_each do |cb| + next if cb.whitelisted? rule = cb.rule_name if cb.respond_to?(:rule_name) - if !budget.nil? && budget <= 0 - next if cb.overtime! + if budget && budget <= 0.0 + next if cb.overtimeable end Sqreen.log.debug { "running post cb #{cb}" } begin start = Sqreen::PerformanceNotifications.time - res = cb.send(:post, return_val, instance, *args, &block) + res = cb.post(return_val, instance, args, budget, &block) stop = Sqreen::PerformanceNotifications.time - budget -= (stop - start) unless budget.nil? + if budget + budget -= (stop - start) + cb.overtime! if budget <= 0.0 + end + all_start += (stop - start) if !res.nil? && cb.respond_to?(:block) && (!cb.block && !Sqreen.config_get(:block_all_rules)) Sqreen.log.debug do "#{cb} cannot block, overriding return value" end res = nil elsif res.is_a?(Hash) res[:rule_name] = rule end returns << res - rescue => e - Sqreen.log.warn "we catch an exception: #{e.inspect}" + rescue StandardError => e + Sqreen.log.warn { "we catch an exception: #{e.inspect}" } Sqreen.log.debug e.backtrace if cb.respond_to?(:record_exception) cb.record_exception(e) else Sqreen::RemoteException.record(e) end next end Sqreen::PerformanceNotifications.notify("Callbacks/#{rule || cb.class.name}/post", start, stop) end - cb_with_framework.framework.remaining_perf_budget=budget if cb_with_framework && !budget.nil? && !cb_with_framework.framework.remaining_perf_budget.nil? + all_stop = Sqreen::PerformanceNotifications.time + if framework && budget && framework.remaining_perf_budget + framework.remaining_perf_budget = budget - (all_stop - all_start) - MGMT_COST * callbacks.size + end + Sqreen::PerformanceNotifications.notify('Callbacks/hooks_post/post', all_start, all_stop) returns - end + #end rescue StandardError => e - Sqreen.log.warn "we catched an exception between cbs: #{e.inspect}" + Sqreen.log.warn { "we catched an exception between cbs: #{e.inspect}" } Sqreen::RemoteException.record(e) + [] end - def self.callback_wrapper_failing(exception, klass, method, instance, *args, &block) - Instrumentation.guard_call(method, []) do - callbacks = @@registered_callbacks.get(klass, method, :failing) - if callbacks.any?(&:whitelisted?) - callbacks = callbacks.reject(&:whitelisted?) - end - - cb_with_framework = callbacks.find(&:framework) - budget = nil - budget = cb_with_framework.framework.remaining_perf_budget if cb_with_framework + def self.callback_wrapper_failing(callbacks, framework, budget, exception, _klass, method, instance, args, &block) + all_start = Sqreen::PerformanceNotifications.time + #Instrumentation.guard_call(method, []) do returns = [] callbacks.each do |cb| + next if cb.whitelisted? rule = cb.rule_name if cb.respond_to?(:rule_name) - if !budget.nil? && budget <= 0 - next if cb.overtime! + if budget && budget <= 0.0 + next if cb.overtimeable end Sqreen.log.debug { "running failing cb #{cb}" } begin start = Sqreen::PerformanceNotifications.time - res = cb.send(:failing, exception, instance, *args, &block) + res = cb.failing(exception, instance, args, budget, &block) stop = Sqreen::PerformanceNotifications.time - budget -= (stop - start) unless budget.nil? + if budget + budget -= (stop - start) + cb.overtime! if budget <= 0.0 + end + all_start += (stop - start) if !res.nil? && cb.respond_to?(:block) && (!cb.block && !Sqreen.config_get(:block_all_rules)) Sqreen.log.debug do "#{cb} cannot block, overriding return value" end res = nil elsif res.is_a?(Hash) res[:rule_name] = rule end returns << res - rescue => e - Sqreen.log.warn "we catch an exception: #{e.inspect}" - Sqreen.log.debug e.backtrace + rescue StandardError => e + Sqreen.log.warn { "we catch an exception: #{e.inspect}" } + Sqreen.log.debug { e.backtrace } if cb.respond_to?(:record_exception) cb.record_exception(e) else Sqreen::RemoteException.record(e) end next end Sqreen::PerformanceNotifications.notify("Callbacks/#{rule || cb.class.name}/failing", start, stop) end - cb_with_framework.framework.remaining_perf_budget=budget if cb_with_framework && !budget.nil? && !cb_with_framework.framework.remaining_perf_budget.nil? + all_stop = Sqreen::PerformanceNotifications.time + if framework && budget && framework.remaining_perf_budget + framework.remaining_perf_budget = budget - (all_stop - all_start) - MGMT_COST * callbacks.size + end + Sqreen::PerformanceNotifications.notify('Callbacks/hooks_failing/failing', all_start, all_stop) returns - end + # end rescue StandardError => e Sqreen.log.warn "we catched an exception between cbs: #{e.inspect}" Sqreen::RemoteException.record(e) + [] end def self.guard_multi_call(instance, method, original_method, args, block) - @sqreen_multi_instr ||= nil + return yield unless @@overriden_singleton_methods key = [method] - Instrumentation.guard_call(nil, :guard_multi_call) do - args.each{|e| key.push(e.object_id)} - end + args.each { |e| key.push(e.object_id) } if key && @sqreen_multi_instr && @sqreen_multi_instr[instance.object_id].member?(key) return instance.send(original_method, *args, &block) end - @sqreen_multi_instr ||= Hash.new {|h, k| h[k]=Set.new } # TODO this should probably be a thread local + @sqreen_multi_instr ||= Hash.new { |h, k| h[k] = Set.new } # TODO: this should probably be a thread local @sqreen_multi_instr[instance.object_id].add(key) r = yield return r ensure if @sqreen_multi_instr && @sqreen_multi_instr[instance.object_id] && @sqreen_multi_instr[instance.object_id].delete(key).empty? @sqreen_multi_instr.delete(instance.object_id) end end - def self.guard_call(method, retval) - @sqreen_in_instr ||= nil - return retval if @sqreen_in_instr && @sqreen_in_instr.member?(method) - @sqreen_in_instr ||= Set.new # TODO this should probably be a thread local - @sqreen_in_instr.add(method) - r = yield - @sqreen_in_instr.delete(method) - return r - rescue Exception => e - @sqreen_in_instr.delete(method) - raise e - end - def self.define_callback_method(meth, original_meth, klass_name) + @sqreen_multi_instr ||= nil proc do |*args, &block| - if Process.pid != Instrumentation.instrumented_pid + budget = nil + skip_call = Thread.current[:sqreen_in_use] + begin + if !skip_call && Sqreen.performance_budget + # Not using framework here to try to get a bit more perf by not loading cbs + budget = Sqreen::SharedStorage.get(:performance_budget) + skip_call = budget && budget <= 0.0 && !@@unovertimable_hookpoints.include?([klass_name, meth]) + end + rescue StandardError => e + Sqreen.log.warn "we catched an exception looking for overtime: #{e.inspect}" + Sqreen::RemoteException.record(e) + end + if !skip_call && Process.pid != Instrumentation.instrumented_pid Sqreen.log.debug do "Instrumented #{Instrumentation.instrumented_pid} != PID #{Process.pid}" end - return send(original_meth, *args, &block) + skip_call = true end + # If we are already overbudget let's not work at all + return send(original_meth, *args, &block) if skip_call Instrumentation.guard_multi_call(self, meth, original_meth, args, block) do - Sqreen.stats.callbacks_calls += 1 - - skip = false - result = nil - - # pre callback - returns = Instrumentation.callback_wrapper_pre(klass_name, - meth, - self, - *args, - &block) - returns.each do |ret| - next unless ret.is_a? Hash - case ret[:status] - when :skip, 'skip' - skip = true - result = ret[:new_return_value] if ret.key? :new_return_value - next - when :modify_args, 'modify_args' - args = ret[:args] - when :raise, 'raise' - fail Sqreen::AttackBlocked, "Sqreen blocked a security threat (type: #{ret[:rule_name]}). No action is required." + precbs, postcbs, failcbs = Instrumentation.callbacks.get(klass_name, meth) + Thread.current[:sqreen_in_use] = true + begin + if budget && budget <= 0.0 + precbs = precbs.reject(&:overtimeable) if precbs + end + # We need the framework to set budget remaining time else don't look for it + if budget + cb_with_framework = nil + cb_with_framework = precbs.find(&:framework) if precbs + cb_with_framework = postcbs.find(&:framework) unless cb_with_framework || !postcbs + cb_with_framework = failcbs.find(&:framework) unless cb_with_framework || !failcbs + framework = cb_with_framework ? cb_with_framework.framework : nil + else + framework = nil + end + rescue StandardError => e + Sqreen.log.warn "we catched an exception looking for framework: #{e.inspect}" + Sqreen::RemoteException.record(e) + framework = nil end - end - return result if skip - begin - result = send(original_meth, *args, &block) - rescue => e - returns = Instrumentation.callback_wrapper_failing(e, klass_name, - meth, - self, - *args, - &block) - will_retry = false - will_raise = returns.empty? - returns.each do |ret| - will_raise = true if ret.nil? - next unless ret.is_a? Hash - case ret[:status] - when :override, 'override' - result = ret[:new_return_value] if ret.key? :new_return_value - when :retry, 'retry' - will_retry = true - else # :reraise, 'reraise' - will_raise = true + skip = false + result = nil + + if precbs && !precbs.empty? + # pre callback + returns = Instrumentation.callback_wrapper_pre(precbs, framework, + budget, + klass_name, + meth, + self, + args, + &block) + returns.each do |ret| + next unless ret.is_a? Hash + case ret[:status] + when :skip, 'skip' + skip = true + result = ret[:new_return_value] if ret.key? :new_return_value + next + when :modify_args, 'modify_args' + args = ret[:args] + when :raise, 'raise' + Thread.current[:sqreen_in_use] = false + raise Sqreen::AttackBlocked, "Sqreen blocked a security threat (type: #{ret[:rule_name]}). No action is required." + end end end - raise e if will_raise - retry if will_retry - result - else - - # post callback - returns = Instrumentation.callback_wrapper_post(klass_name, - meth, - result, - self, - *args, - &block) - returns.each do |ret| - next unless ret.is_a? Hash - case ret[:status] - when :raise, 'raise' - fail Sqreen::AttackBlocked, "Sqreen blocked a security threat (type: #{ret[:rule_name]}). No action is required." - when :override, 'override' - result = ret[:new_return_value] - else - next + Thread.current[:sqreen_in_use] = false + return result if skip + begin + result = send(original_meth, *args, &block) + rescue StandardError => e + Thread.current[:sqreen_in_use] = true + budget = Sqreen.performance_budget && framework && framework.remaining_perf_budget + failcbs = failcbs.reject(&:overtimeable) if failcbs && budget && budget <= 0.0 + raise e unless failcbs && !failcbs.empty? + returns = Instrumentation.callback_wrapper_failing(failcbs, + framework, + budget, + e, + klass_name, + meth, + self, + args, + &block) + will_retry = false + will_raise = returns.empty? + returns.each do |ret| + will_raise = true if ret.nil? + next unless ret.is_a? Hash + case ret[:status] + when :override, 'override' + result = ret[:new_return_value] if ret.key? :new_return_value + when :retry, 'retry' + will_retry = true + else # :reraise, 'reraise' + will_raise = true + end end + raise e if will_raise + retry if will_retry + result + else + Thread.current[:sqreen_in_use] = true + budget = Sqreen.performance_budget && framework && framework.remaining_perf_budget + postcbs = postcbs.reject(&:overtimeable) if postcbs && budget && budget <= 0.0 + return result unless postcbs && !postcbs.empty? + # post callback + returns = Instrumentation.callback_wrapper_post(postcbs, + framework, + budget, + klass_name, + meth, + result, + self, + args, + &block) + returns.each do |ret| + next unless ret.is_a? Hash + case ret[:status] + when :raise, 'raise' + raise Sqreen::AttackBlocked, "Sqreen blocked a security threat (type: #{ret[:rule_name]}). No action is required." + when :override, 'override' + result = ret[:new_return_value] + else + next + end + end + result + ensure + if @@record_request_hookpoints.include?([klass_name, meth]) && Sqreen::PerformanceNotifications.listen_for? + Sqreen::PerformanceNotifications.instrument('Callbacks/hooks_reporting/pre') do + Sqreen::PerformanceNotifications::LogPerformance.next_request + Sqreen::PerformanceNotifications::NewRelic.next_request + end + end + Thread.current[:sqreen_in_use] = false end - result end end - end end def override_class_method(klass, meth) # FIXME: This is somehow ugly. We should reduce the amount of # `evaled` code. @@ -370,24 +426,23 @@ saved_meth_name = get_saved_method_name(meth) method_kind = nil obj.class_eval do # Note: As a lambda the following will crash ruby 2.2.3p173 - case - when public_method_defined?(meth) + if public_method_defined?(meth) method_kind = :public - when protected_method_defined?(meth) + elsif protected_method_defined?(meth) method_kind = :protected - when private_method_defined?(meth) + elsif private_method_defined?(meth) method_kind = :private end alias_method meth, saved_meth_name send(method_kind, meth) end end - def get_saved_method_name(meth, suffix=nil) + def get_saved_method_name(meth, suffix = nil) "#{meth}_sq#{suffix}_not_modified".to_sym end def override_instance_method(klass_name, meth) saved_meth_name = get_saved_method_name(meth) @@ -399,16 +454,15 @@ klass_name.class_eval do alias_method saved_meth_name, meth define_method(new_method, p) - case - when public_method_defined?(meth) + if public_method_defined?(meth) method_kind = :public - when protected_method_defined?(meth) + elsif protected_method_defined?(meth) method_kind = :protected - when private_method_defined?(meth) + elsif private_method_defined?(meth) method_kind = :private end alias_method meth, new_method private saved_meth_name private new_method @@ -463,10 +517,11 @@ is_instance_method?(obj, method) end # Override a singleton method on an instance def override_singleton_method(instance, klass_name, meth) + @@overriden_singleton_methods = true saved_meth_name = get_saved_method_name(meth, 'singleton') if instance.respond_to?(saved_meth_name, true) Sqreen.log.debug { "#{saved_meth_name} found #{instance.class}##{instance.object_id} already instrumented" } return nil elsif instance.frozen? @@ -531,10 +586,12 @@ Sqreen.log.debug { "Reinstrumented #{insts} instances of #{klass}" } end end @@registered_callbacks.add(cb) + @@unovertimable_hookpoints << key unless cb.overtimeable + @@record_request_hookpoints << key if cb.is_a?(Sqreen::Rules::RecordRequestContext) @@instrumented_pid = Process.pid end end def remove_callback(cb) @@ -553,11 +610,11 @@ unless already_overriden Sqreen.log.debug "#{key} not overriden, returning" return end - defined_cbs = @@registered_callbacks.get(klass, method) + defined_cbs = @@registered_callbacks.get(klass, method).flatten nb_removed = 0 defined_cbs.each do |found_cb| if found_cb == cb Sqreen.log.debug "Removing callback #{found_cb}" @@ -605,11 +662,11 @@ # Instrument the application code using the rules # @param rules [Array<Hash>] Rules to instrument # @param metrics_engine [MetricsStore] Metric storage facility def instrument!(rules, framework) verifier = nil - if Sqreen.features['rules_signature'] && + if Sqreen.features['rules_signature'] && Sqreen.config_get(:rules_verify_signature) == true && !defined?(::JRUBY_VERSION) verifier = Sqreen::SqreenSignedVerifier.new else Sqreen.log.debug('Rules signature is not enabled') @@ -628,10 +685,10 @@ self.metrics_engine = metrics_engine return if metrics_engine.nil? metrics_engine.create_metric('name' => CallCountable::COUNT_CALLS, 'period' => 60, 'kind' => 'Sum') - metrics_engine.create_metric('name' => WHITELISTED_METRIC, + metrics_engine.create_metric('name' => Sqreen::Rules::RecordRequestContext::WHITELISTED_METRIC, 'period' => 60, 'kind' => 'Sum') metrics_engine.create_metric('name' => OVERTIME_METRIC, 'period' => 60, 'kind' => 'Sum')