class Sqreen::Weave::Legacy::Instrumentation
Attributes
metrics_engine[RW]
Public Class Methods
new(metrics_engine, opts = {})
click to toggle source
# File lib/sqreen/weave/legacy/instrumentation.rb, line 18 def initialize(metrics_engine, opts = {}) Sqreen::Weave.logger.debug { "#{self.class.name}#initialize #{metrics_engine}" } @hooks = [] self.metrics_engine = metrics_engine ### bail out if no metric engine return if metrics_engine.nil? ### init metric to count calls to sqreen metrics_engine.create_metric( 'name' => 'sqreen_call_counts', 'period' => 60, 'kind' => 'Sum', ) ### init metric to count request whitelist matches (ip or path whitelist) metrics_engine.create_metric( 'name' => 'whitelisted', 'period' => 60, 'kind' => 'Sum', ) ### init metric to count over budget hits metrics_engine.create_metric( 'name' => 'request_overtime', 'period' => 60, 'kind' => 'Sum', ) # PerformanceNotifications::Binning metrics_engine.create_metric( 'name' => 'req', 'period' => opts[:period] || 60, 'kind' => 'Binning', 'options' => opts[:perf_metric] || { 'base' => 2.0, 'factor' => 0.1 }, ) metrics_engine.create_metric( 'name' => 'sq', 'period' => opts[:period] || 60, 'kind' => 'Binning', 'options' => opts[:perf_metric] || { 'base' => 2.0, 'factor' => 0.1 }, ) metrics_engine.create_metric( 'name' => 'pct', 'period' => opts[:period] || 60, 'kind' => 'Binning', 'options' => opts[:perf_metric_percent] || { 'base' => 1.3, 'factor' => 1.0 }, ) metrics_engine.create_metric( 'name' => 'req.sq.hook.overhead', 'period' => 60, 'kind' => 'Binning', 'options' => { 'base' => 2.0, 'factor' => 0.1 }, ) metrics_engine.create_metric( 'name' => 'sq.hook.overhead', 'period' => 60, 'kind' => 'Binning', 'options' => { 'base' => 2.0, 'factor' => 0.1 }, ) metrics_engine.create_metric( 'name' => 'sq.shrinkwrap', 'period' => 60, 'kind' => 'Binning', 'options' => { 'base' => 2.0, 'factor' => 0.1 }, ) Sqreen.thread_cpu_time? && metrics_engine.create_metric( 'name' => 'sq_thread_cpu_pct', 'period' => opts[:period] || 60, 'kind' => 'Binning', 'options' => opts[:perf_metric_percent] || { 'base' => 1.3, 'factor' => 1.0 }, ) end
Public Instance Methods
add_callback(rule, callback, strategy)
click to toggle source
needed by instrument!
# File lib/sqreen/weave/legacy/instrumentation.rb, line 409 def add_callback(rule, callback, strategy) Sqreen::Weave.logger.debug { "Adding rule: #{rule} callback: #{callback}" } klass = callback.klass method = callback.method if (call_count = ENV['SQREEN_DEBUG_CALL_COUNT']) call_count = JSON.parse(call_count) if callback.respond_to?(:rule_name) && call_count.key?(callback.rule_name) count = call_count[callback.rule_name] Sqreen::Weave.logger.debug { "override rule: #{callback.rule_name} call_count: #{count.inspect}" } callback.instance_eval { @call_count_interval = call_count[callback.rule_name] } end end if Sqreen::Graft::HookPoint.new("#{klass}.#{method}").exist? hook_point = "#{klass}.#{method}" elsif Sqreen::Graft::HookPoint.new("#{klass}##{method}").exist? hook_point = "#{klass}##{method}" end return if hook_point.nil? priority = callback.priority || 100 block = callback.respond_to?(:block) ? callback.block : true ignore = -> { callback.whitelisted? } if callback.respond_to?(:whitelisted?) hook = Sqreen::Graft::Hook[hook_point, strategy] hook.add do if callback.pre? before(rule, rank: priority, mandatory: !callback.overtimeable, flow: block, ignore: ignore) do |call, b| next unless Thread.current[:sqreen_http_request] i = call.instance a = call.args r = call.remaining begin ret = callback.pre(i, a, r) rescue StandardError => e Sqreen::Weave.logger.warn { "#{rule} klass=#{callback.klass} method=#{callback.method} when=#pre instance=#{i} => exception=#{e}" } if callback.respond_to?(:record_exception) callback.record_exception(e) else Sqreen::RemoteException.record(e) end end next if ret.nil? || !ret.is_a?(Hash) throw_val = case ret[:status] when :skip, 'skip' b.return(ret[:new_return_value]).break! if ret.key?(:new_return_value) when :modify_args, 'modify_args' b.args(ret[:args]) when :raise, 'raise' if ret.key?(:exception) b.raise(ret[:exception]) else b.raise(Sqreen::AttackBlocked.new("Sqreen blocked a security threat (type: #{callback.rule_name}). No action is required.")) end end next unless throw_val throw_val.break! if ret[:skip_rem_cbs] throw(b, throw_val) end end if callback.post? after(rule, rank: -priority, mandatory: !callback.overtimeable, flow: block, ignore: ignore) do |call, b| next unless Thread.current[:sqreen_http_request] i = call.instance v = call.returned a = call.args r = call.remaining begin ret = callback.post(v, i, a, r) rescue StandardError => e Sqreen::Weave.logger.warn { "#{rule} klass=#{callback.klass} method=#{callback.method} when=#post instance=#{i} => exception=#{e}" } if callback.respond_to?(:record_exception) callback.record_exception(e) else Sqreen::RemoteException.record(e) end end case ret[:status] when :override, 'override' throw(b, b.return(ret[:new_return_value])) if ret.key?(:new_return_value) when :raise, 'raise' throw(b, b.raise(ret[:exception])) if ret.key?(:exception) throw(b, b.raise(Sqreen::AttackBlocked.new("Sqreen blocked a security threat (type: #{callback.rule_name}). No action is required."))) end unless ret.nil? || !ret.is_a?(Hash) end end if callback.failing? raised(rule, rank: priority, mandatory: !callback.overtimeable, flow: block, ignore: ignore) do |call, b| next unless Thread.current[:sqreen_http_request] i = call.instance e = call.raised a = call.args r = call.remaining begin ret = callback.failing(e, i, a, r) rescue StandardError => e Sqreen::Weave.logger.warn { "#{rule} klass=#{callback.klass} method=#{callback.method} when=#failing instance=#{i} => exception=#{e}" } if callback.respond_to?(:record_exception) callback.record_exception(e) else Sqreen::RemoteException.record(e) end end throw(b, b.raise(e)) if ret.nil? || !ret.is_a?(Hash) case ret[:status] when :override, 'override' throw(b, b.return(ret[:new_return_value])) if ret.key?(:new_return_value) when :retry, 'retry' throw(b, b.retry) when :raise, 'raise' throw(b, b.raise(ret[:exception])) if ret.key?(:exception) throw(b, b.raise(Sqreen::AttackBlocked.new("Sqreen blocked a security threat (type: #{callback.rule_name}). No action is required."))) when :reraise, 'reraise' throw(b, b.raise(e)) else throw(b, b.raise(e)) end unless ret.nil? || !ret.is_a?(Hash) end end end.install hook end
hardcoded_callbacks(framework)
click to toggle source
needed by instrument!
# File lib/sqreen/weave/legacy/instrumentation.rb, line 565 def hardcoded_callbacks(framework) [ ### callback for performing sec responses based on ip ### init redefined to implement smartass way to hook it upon the ### framework's middleware #call Sqreen::Rules::RunReqStartActions.new(framework), ### callback for performing sec responses based on user Sqreen::Rules::RunUserActions.new(Sqreen, :identify, 0), ### callback for performing sec responses based on user Sqreen::Rules::RunUserActions.new(Sqreen, :auth_track, 1), ] end
install_graphql_hook()
click to toggle source
# File lib/sqreen/weave/legacy/instrumentation.rb, line 578 def install_graphql_hook hook = Sqreen::Graft::Hook['GraphQL::Execution::Multiplex.run_queries'] hook.add do before('weave,test,graphql', mandatory: true) do |call| find_args = proc do |*items| args = [] items.each do |e| args << e if e.is_a?(GraphQL::Language::Nodes::Argument) args += find_args.call(*e.children) end args end queries = call.args[1] qdocs = queries.map { |q| [q.query_string, q.document] } qargs = qdocs.map do |q, doc| next if doc.nil? [q, find_args.call(*doc.children).map { |arg| { arg.name => arg.value } }.reduce(&:merge)] end Sqreen.framework.graphql_args = Hash[*qargs.flatten(1)] end end.install hook end
instrument!(rules, framework)
click to toggle source
needed by Sqreen::Runner#initialize
# File lib/sqreen/weave/legacy/instrumentation.rb, line 96 def instrument!(rules, framework) Sqreen::Weave.logger.debug { "#{rules.count} rules, #{framework}" } # TODO: make config able to see if value was user-set or default strategy = Sqreen.config_get(:weave_strategy) # TODO: factor generic hint system out # TODO: factor those hint definitions to dependency strategy_hints = [] if strategy == :prepend && !Module.respond_to?(:prepend) Sqreen::Weave.logger.debug { "strategy: #{strategy.inspect} unavailable, falling back to :chain" } strategy_hints << [:chain, 'Module.respond_to?(:prepend)', 'false'] end if Gem::Specification.select { |s| s.name == 'scout_apm' && Gem::Requirement.new('< 2.5.2').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :prepend unavailable with scout_apm < 2.5.2, hinting at :chain" } strategy_hints << [:chain, 'scout_apm', '< 2.5.2'] end if Gem::Specification.select { |s| s.name == 'scout_apm' && Gem::Requirement.new('>= 2.5.2').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with scout_apm >= 2.5.2, hinting at :prepend" } strategy_hints << [:prepend, 'scout_apm', '>= 2.5.2'] end if Gem::Specification.select { |s| s.name == 'ddtrace' && Gem::Requirement.new('< 0.27').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :prepend unavailable with ddtrace < 0.27, hinting at :chain" } strategy_hints << [:chain, 'ddtrace', '< 0.27'] end if Gem::Specification.select { |s| s.name == 'ddtrace' && Gem::Requirement.new('>= 0.27').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with ddtrace >= 0.27, hinting at :prepend" } strategy_hints << [:prepend, 'ddtrace', '>= 0.27'] end if Gem::Specification.select { |s| s.name == 'skylight' && Gem::Requirement.new('< 5.0.0.beta').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :prepend unavailable with skylight < 5.0.0.beta, hinting at :chain" } strategy_hints << [:chain, 'skylight', '< 5.0.0.beta'] end if Gem::Specification.select { |s| s.name == 'skylight' && Gem::Requirement.new('>= 5.0.0.beta').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with skylight >= 5.0.0.beta, hinting at :prepend" } strategy_hints << [:prepend, 'skylight', '>= 5.0.0.beta'] end if Gem::Specification.select { |s| s.name == 'elastic-apm' && Gem::Requirement.new('< 4.0.a').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :prepend unavailable with elastic-apm < 4.0, hinting at :chain" } strategy_hints << [:chain, 'elastic-apm', '< 4.0.a'] end if Gem::Specification.select { |s| s.name == 'elastic-apm' && Gem::Requirement.new('>= 4.0').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with elastic-apm >= 4.0, hinting at :prepend" } strategy_hints << [:prepend, 'elastic-apm', '>= 4.0.a'] end if Gem::Specification.select { |s| s.name == 'airbrake' && Gem::Requirement.new('>= 11.0.2').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with airbrake >= 11.0.2, hinting at :prepend" } strategy_hints << [:prepend, 'airbrake', '>= 11.0.2'] end if Gem::Specification.select { |s| s.name == 'newrelic_rpm' && Gem::Requirement.new('>= 6.14').satisfied_by?(Gem::Version.new(s.version)) }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with newrelic_rpm >= 6.14, hinting at :prepend" } strategy_hints << [:prepend, 'newrelic_rpm', '>= 6.14'] end if Gem::Specification.select { |s| s.name =~ /^opentelemetry/ }.any? Sqreen::Weave.logger.debug { "strategy: :chain unavailable with opentelemetry, hinting at :prepend" } strategy_hints << [:prepend, 'opentelemetry'] end if strategy_hints.map(&:first).uniq.count > 1 raise Sqreen::Exception, "conflicting instrumentation strategies: #{strategy_hints.inspect}" end if strategy_hints.map(&:first).uniq.count == 1 && strategy != strategy_hints.first.first was = strategy strategy = strategy_hints.first.first Sqreen::Weave.logger.warn { "strategy: #{strategy.inspect} was: #{was.inspect} hints: #{strategy_hints.inspect}" } else Sqreen::Weave.logger.info { "strategy: #{strategy.inspect}" } end ### set up rule signature verifier verifier = nil # TODO: check for JRuby via dependency # TODO: reinstate signatures for JRuby if Sqreen.config_get(:rules_verify_signature) == true && !defined?(::JRUBY_VERSION) verifier = Sqreen::SqreenSignedVerifier.new Sqreen::Weave.logger.debug('rules: signature status: enabled') else Sqreen::Weave.logger.debug('rules: signature status: disabled') end if verifier invalid_rules = rules.reject do |rule| valid = verifier.verify(rule) if valid Sqreen::Weave.logger.debug { "rule: #{rule['name']} signed: true result: ok" } else Sqreen::Weave.logger.error { "rule: #{rule['name']} singed: true result: fail" } end valid end if invalid_rules.any? Sqreen::Weave.logger.error { "weave: instrument status: abort reason: signature result: fail" } raise Sqreen::Exception, "Signature error: rules: #{invalid_rules.map { |r| r['name'] }.inspect}" else Sqreen::Weave.logger.info { "weave: instrument rules: signed result: ok" } end end ### force clean instrumentation callback list @hooks = [] ### for each rule description rules.each do |rule| Sqreen::Weave.logger.debug { "Processing rule: #{rule['name']}" } ### transform into format for adding callback rule_callback = Sqreen::Rules.cb_from_rule(rule, self, metrics_engine, verifier) next unless rule_callback ### attach framework to callback rule_callback.framework = framework ## create metric Sqreen::Weave.logger.debug { "Adding rule metric: #{rule_callback}" } [:pre, :post, :failing].each do |whence| next unless rule_callback.send(:"#{whence}?") metric_name = "sq.#{rule['name']}.#{whence}" metrics_engine.create_metric( 'name' => metric_name, 'period' => 60, 'kind' => 'Binning', 'options' => { 'base' => 2.0, 'factor' => 0.1 }, ) metric_name = "req.sq.#{rule['name']}.#{whence}" metrics_engine.create_metric( 'name' => metric_name, 'period' => 60, 'kind' => 'Binning', 'options' => { 'base' => 2.0, 'factor' => 0.1 }, ) end ### install callback, observing priority Sqreen::Weave.logger.debug { "Adding rule callback: #{rule_callback}" } @hooks << add_callback("weave,rule=#{rule['name']}", rule_callback, strategy) end ### for each hardcoded callback hardcoded_callbacks(framework).each do |hard_callback| Sqreen::Weave.logger.debug { "Adding hardcoded callback: #{hard_callback}" } ### install hardcoded callbacks, observing priority @hooks << add_callback('weave,hardcoded', hard_callback, strategy) end @hooks << install_graphql_hook metrics_engine = self.metrics_engine request_hook = Sqreen::Graft::Hook['Sqreen::ShrinkWrap#call', strategy] @hooks << request_hook request_hook.add do before('wave,meta,request', rank: -100000, mandatory: true) do |_call| next unless Sqreen.instrumentation_ready # shrinkwrap_timer = Sqreen::Graft::Timer.new('weave,shrinkwrap') # shrinkwrap_timer.start if defined?(Datadog) && Datadog.tracer && (datadog_span = Datadog.tracer.active_root_span) Sqreen::Weave.logger.debug { "request datadog:true span_id:#{datadog_span.span_id} parent_id:#{datadog_span.parent_id} trace_id:#{datadog_span.trace_id}" } end request_timer = Sqreen::Graft::Timer.new("request") request_timer.start sqreen_timer = Sqreen::Graft::Timer.new("sqreen") budget = Sqreen::Weave::Budget.current request_budget_threshold = budget.threshold if budget request_budget_ratio = budget.ratio if budget request_budget_is_dynamic = !request_budget_ratio.nil? request_budget = !request_budget_threshold.nil? timed_level = (Sqreen.features['perf_level'] || 1).to_i Sqreen::Weave.logger.debug { "request budget: #{budget.to_h} timed.level: #{timed_level}" } if Sqreen::Weave.logger.debug? Thread.current[:sqreen_http_request] = { request_timer: request_timer, sqreen_timer: sqreen_timer, time_budget_expended: false, time_budget_threshold: request_budget_threshold, time_budget_dynamic: request_budget_is_dynamic, time_budget_ratio: request_budget_ratio, time_budget: request_budget, timed_callbacks: [], timed_hooks: [], timed_level: timed_level, skipped_callbacks: [], # timed_shrinkwrap: shrinkwrap_timer, datadog_span: datadog_span, } # shrinkwrap_timer.stop end ensured('weave,meta,request', rank: 100000, mandatory: true) do |_call| request = Thread.current[:sqreen_http_request] next if request.nil? # shrinkwrap_timer = request[:timed_shrinkwrap] # shrinkwrap_timer.start Thread.current[:sqreen_http_request] = nil request_timer = request[:request_timer] now = request_timer.stop if request[:timed_level] >= 1 request[:timed_callbacks].each do |timer| duration = timer.duration timer.tag =~ /weave,rule=(.*)$/ && rule = $1 next unless rule whence = case timer.tag when /@before/ then 'pre' when /@after/ then 'post' when /@raised/ then 'failing' end next unless whence metric_name = "sq.#{rule}.#{whence}" metrics_engine.update(metric_name, now, nil, duration * 1000) # Sqreen.observations_queue.push([metric_name, nil, duration * 1000, utc_now]) end request[:timed_hooks].each do |timer| duration = timer.duration metrics_engine.update('sq.hook.overhead', now, nil, duration * 1000) # Sqreen.observations_queue.push(['sq.hook.overhead', nil, duration * 1000, utc_now]) end end sqreen_timer = request[:sqreen_timer] total = sqreen_timer.duration Sqreen::Weave.logger.debug { "request sqreen_timer.total: #{'%.03fus' % (total * 1_000_000)}" } if Sqreen::Weave.logger.debug? total = request_timer.duration Sqreen::Weave.logger.debug { "request request_timer.total: #{'%.03fus' % (total * 1_000_000)}" } if Sqreen::Weave.logger.debug? if request[:timed_level] >= 2 skipped = request[:skipped_callbacks].map(&:name) Sqreen::Weave.logger.debug { "request callback.skipped.count: #{skipped.count}" } if Sqreen::Weave.logger.debug? timings = request[:timed_callbacks].map(&:to_s) total = request[:timed_callbacks].sum(&:duration) Sqreen::Weave.logger.debug { "request callback.total: #{'%.03fus' % (total * 1_000_000)} callback.count: #{timings.count}" } if Sqreen::Weave.logger.debug? timings = request[:timed_hooks].map(&:to_s) total = request[:timed_hooks].sum(&:duration) Sqreen::Weave.logger.debug { "request hook.total: #{'%.03fus' % (total * 1_000_000)} hook.count: #{timings.count}" } if Sqreen::Weave.logger.debug? end skipped = request[:skipped_callbacks].map(&:name) skipped_rule_name = skipped.first && skipped.first =~ /weave,rule=(.*)$/ && $1 metrics_engine.update('request_overtime', now, skipped_rule_name, 1) if skipped_rule_name # Sqreen.observations_queue.push(['request_overtime', skipped_rule_name, 1, utc_now]) if skipped_rule_name sqreen_request_duration = sqreen_timer.duration metrics_engine.update('sq', now, nil, sqreen_request_duration * 1000) # Sqreen.observations_queue.push(['sq', nil, sqreen_request_duration * 1000, utc_now]) request_duration = request_timer.duration metrics_engine.update('req', now, nil, request_duration * 1000) # Sqreen.observations_queue.push(['req', nil, request_duration * 1000, utc_now]) sqreen_request_ratio = (sqreen_request_duration * 100.0) / (request_duration - sqreen_request_duration) metrics_engine.update('pct', now, nil, sqreen_request_ratio) # Sqreen.observations_queue.push(['pct', nil, sqreen_request_ratio, utc_now]) Sqreen::Weave.logger.debug { "request sqreen_timer.ratio: #{'%.03f' % (sqreen_request_ratio / 100.0)}" } if Sqreen::Weave.logger.debug? if request[:timed_level] >= 2 tallies = Hash.new(0.0) request[:timed_callbacks].each do |timer| duration = timer.duration timer.tag =~ /weave,rule=(.*)$/ && rule = $1 next unless rule whence = case timer.tag when /@before/ then 'pre' when /@after/ then 'post' when /@raised/ then 'failing' end next unless whence metric_name = "req.sq.#{rule}.#{whence}" tallies[metric_name] += duration end tallies.each do |metric_name, duration| metrics_engine.update(metric_name, now, nil, duration * 1000) # Sqreen.observations_queue.push([metric_name, nil, duration * 1000, utc_now]) end duration = request[:timed_hooks].sum(&:duration) metrics_engine.update('req.sq.hook.overhead', now, nil, duration * 1000) # Sqreen.observations_queue.push(['req.sq.hook.overhead', nil, duration * 1000, utc_now]) end # shrinkwrap_timer.stop # duration = shrinkwrap_timer.duration # metrics_engine.update('sq.shrinkwrap', now, nil, duration * 1000) end end.install ### globally declare instrumentation ready Sqreen.instrumentation_ready = true Sqreen::Weave.logger.info { "Instrumentation activated" } end
remove_all_callbacks()
click to toggle source
needed by Sqreen::Runner
# File lib/sqreen/weave/legacy/instrumentation.rb, line 395 def remove_all_callbacks Sqreen.instrumentation_ready = false Sqreen::Weave.logger.info { "Instrumentation deactivated" } loop do hook = @hooks.pop break unless hook Sqreen::Weave.logger.debug { "hook.deinstrument: #{hook}" } hook.uninstall hook.clear end end
valid_method?(klass, method)
click to toggle source
needed by Sqreen::Rules.cb_from_rule
# File lib/sqreen/weave/legacy/instrumentation.rb, line 551 def valid_method?(klass, method) if Sqreen::Graft::HookPoint.new("#{klass}.#{method}").exist? Sqreen::Weave.logger.debug { "HookPoint found: #{klass}.#{method}" } true elsif Sqreen::Graft::HookPoint.new("#{klass}##{method}").exist? Sqreen::Weave.logger.debug { "HookPoint found: #{klass}##{method}" } true else Sqreen::Weave.logger.debug { "HookPoint not found: #{klass} #{method}" } false end end