require 'new_relic/control' module NewRelic module Agent # This module contains class methods added to support installing custom # metric tracers and executing for individual metrics. # # == Examples # # When the agent initializes, it extends Module with these methods. # However if you want to use the API in code that might get loaded # before the agent is initialized you will need to require # this file: # # require 'new_relic/agent/method_tracer' # class A # include NewRelic::Agent::MethodTracer # def process # ... # end # add_method_tracer :process # end # # To instrument a class method: # # require 'new_relic/agent/method_tracer' # class An # def self.process # ... # end # class << self # include NewRelic::Agent::MethodTracer # add_method_tracer :process # end # end module MethodTracer def self.included clazz #:nodoc: clazz.extend ClassMethods clazz.send :include, InstanceMethods end def self.extended clazz #:nodoc: clazz.extend ClassMethods clazz.extend InstanceMethods end module InstanceMethods # Deprecated: original method preserved for API backward compatibility. # Use either #trace_execution_scoped or #trace_execution_unscoped def trace_method_execution(metric_names, push_scope, produce_metric, deduct_call_time_from_parent, &block) #:nodoc: if push_scope trace_execution_scoped(metric_names, :metric => produce_metric, :deduct_call_time_from_parent => deduct_call_time_from_parent, &block) else trace_execution_unscoped(metric_names, &block) end end # Trace a given block with stats assigned to the given metric_name. It does not # provide scoped measurements, meaning whatever is being traced will not 'blame the # Controller'--that is to say appear in the breakdown chart. # This is code is inlined in #add_method_tracer. # * metric_names is a single name or an array of names of metrics # * :force => true will force the metric to be captured even when # tracing is disabled with NewRelic::Agent#disable_all_tracing # def trace_execution_unscoped(metric_names, options={}) return yield unless NewRelic::Agent.is_execution_traced? t0 = Time.now.to_f stats = Array(metric_names).map do | metric_name | NewRelic::Agent.instance.stats_engine.get_stats_no_scope metric_name end begin NewRelic::Agent.instance.push_trace_execution_flag(true) if options[:force] yield ensure NewRelic::Agent.instance.pop_trace_execution_flag if options[:force] duration = Time.now.to_f - t0 # for some reason this is 3 usec faster than Time - Time stats.each { |stat| stat.trace_call(duration) } end end EMPTY_ARRAY = [].freeze # Deprecated. Use #trace_execution_scoped, a version with an options hash. def trace_method_execution_with_scope(metric_names, produce_metric, deduct_call_time_from_parent, scoped_metric_only=false, &block) #:nodoc: trace_execution_scoped(metric_names, :metric => produce_metric, :deduct_call_time_from_parent => deduct_call_time_from_parent, :scoped_metric_only => scoped_metric_only, &block) end alias trace_method_execution_no_scope trace_execution_unscoped #:nodoc: # Trace a given block with stats and keep track of the caller. # See #add_method_tracer for a description of the arguments. # +metric_names+ is either a single name or an array of metric names. # If more than one metric is passed, the +produce_metric+ option only applies to the first. The # others are always recorded. Only the first metric is pushed onto the scope stack. # # Generally you pass an array of metric names if you want to record the metric under additional # categories, but generally this *should never ever be done*. Most of the time you can aggregate # on the server. def trace_execution_scoped(metric_names, options={}) return yield unless NewRelic::Agent.is_execution_traced? || options[:force] produce_metric = options[:metric] != false deduct_call_time_from_parent = options[:deduct_call_time_from_parent] != false scoped_metric_only = produce_metric && options[:scoped_metric_only] t0 = Time.now.to_f if metric_names.instance_of? Array first_name = metric_names.first metric_stats = [] metric_stats << NewRelic::Agent.instance.stats_engine.get_stats(first_name, true, scoped_metric_only) if produce_metric metric_names[1..-1].each do | name | metric_stats << NewRelic::Agent.instance.stats_engine.get_stats_no_scope(name) end else first_name = metric_names if produce_metric metric_stats = [NewRelic::Agent.instance.stats_engine.get_stats(first_name, true, scoped_metric_only)] else metric_stats = EMPTY_ARRAY end end begin # Keep a reference to the scope we are pushing so we can do a sanity check making # sure when we pop we get the one we 'expected' NewRelic::Agent.instance.push_trace_execution_flag(true) if options[:force] expected_scope = NewRelic::Agent.instance.stats_engine.push_scope(first_name, t0, deduct_call_time_from_parent) rescue => e NewRelic::Control.instance.log.error("Caught exception in trace_method_execution header. Metric name = #{first_name}, exception = #{e}") NewRelic::Control.instance.log.error(e.backtrace.join("\n")) end begin yield ensure t1 = Time.now.to_f duration = t1 - t0 begin NewRelic::Agent.instance.pop_trace_execution_flag if options[:force] if expected_scope scope = NewRelic::Agent.instance.stats_engine.pop_scope expected_scope, duration, t1 exclusive = duration - scope.children_time metric_stats.each { |stats| stats.trace_call(duration, exclusive) } end rescue => e NewRelic::Control.instance.log.error("Caught exception in trace_method_execution footer. Metric name = #{first_name}, exception = #{e}") NewRelic::Control.instance.log.error(e.backtrace.join("\n")) end end end end module ClassMethods # Add a method tracer to the specified method. # # === Common Options # # * :push_scope => false specifies this method tracer should not # keep track of the caller; it will not show up in controller breakdown # pie charts. # * :metric => false specifies that no metric will be recorded. # Instead the call will show up in transaction traces as well as traces # shown in Developer Mode. # # === Uncommon Options # # * :scoped_metric_only => true indicates that the unscoped metric # should not be recorded. Normally two metrics are potentially created # on every invocation: the aggregate method where statistics for all calls # of that metric are stored, and the "scoped metric" which records the # statistics for invocations in a particular scope--generally a controller # action. This option indicates that only the second type should be recorded. # The effect is similar to :metric => false but in addition you # will also see the invocation in breakdown pie charts. # * :deduct_call_time_from_parent => false indicates that the method invocation # time should never be deducted from the time reported as 'exclusive' in the # caller. You would want to use this if you are tracing a recursive method # or a method that might be called inside another traced method. # * :code_header and :code_footer specify ruby code that # is inserted into the tracer before and after the call. # * :force = true will ensure the metric is captured even if called inside # an untraced execution call. (See NewRelic::Agent#disable_all_tracing) # # === Overriding the metric name # # +metric_name_code+ is a string that is eval'd to get the # name of the metric associated with the call, so if you want to # use interpolaion evaluated at call time, then single quote # the value like this: # # add_method_tracer :foo, 'Custom/#{self.class.name}/foo' # # This would name the metric according to the class of the runtime # intance, as opposed to the class where +foo+ is defined. # # If not provided, the metric name will be Custom/ClassName/method_name. # # === Examples # # Instrument +foo+ only for custom views--will not show up in transaction traces or caller breakdown graphs: # # add_method_tracer :foo, :push_scope => false # # Instrument +foo+ just for transaction traces only: # # add_method_tracer :foo, :metric => false # # Instrument +foo+ so it shows up in transaction traces and caller breakdown graphs # for actions: # # add_method_tracer :foo # # which is equivalent to: # # add_method_tracer :foo, 'Custom/#{self.class.name}/foo', :push_scope => true, :metric => true # # Instrument the class method +foo+ with the metric name 'Custom/People/fetch': # # class << self # add_method_tracer :foo, 'Custom/People/fetch' # end # def add_method_tracer(method_name, metric_name_code=nil, options = {}) # for backward compatibility: if !options.is_a?(Hash) options = {:push_scope => options} end # in case they omit the metric name code if metric_name_code.is_a?(Hash) options.merge(metric_name_code) end if (unrecognized = options.keys - [:force, :metric, :push_scope, :deduct_call_time_from_parent, :code_header, :code_footer, :scoped_metric_only]).any? fail "Unrecognized options in add_method_tracer_call: #{unrecognized.join(', ')}" end # options[:push_scope] true if we are noting the scope of this for # stats collection as well as the transaction tracing options[:push_scope] = true if options[:push_scope].nil? # options[:metric] true if you are tracking stats for a metric, otherwise # it's just for transaction tracing. options[:metric] = true if options[:metric].nil? options[:force] = false if options[:force].nil? options[:deduct_call_time_from_parent] = false if options[:deduct_call_time_from_parent].nil? && !options[:metric] options[:deduct_call_time_from_parent] = true if options[:deduct_call_time_from_parent].nil? options[:code_header] ||= "" options[:code_footer] ||= "" options[:scoped_metric_only] ||= false klass = (self === Module) ? "self" : "self.class" # Default to the class where the method is defined. metric_name_code = "Custom/#{self.name}/#{method_name.to_s}" unless metric_name_code unless method_defined?(method_name) || private_method_defined?(method_name) NewRelic::Control.instance.log.warn("Did not trace #{self.name}##{method_name} because that method does not exist") return end traced_method_name = _traced_method_name(method_name, metric_name_code) if method_defined? traced_method_name NewRelic::Control.instance.log.warn("Attempt to trace a method twice with the same metric: Method = #{method_name}, Metric Name = #{metric_name_code}") return end fail "Can't add a tracer where push_scope is false and metric is false" if options[:push_scope] == false && !options[:metric] header = "" if !options[:force] header << "return #{_untraced_method_name(method_name, metric_name_code)}(*args, &block) unless NewRelic::Agent.is_execution_traced?\n" end header << options[:code_header] if options[:code_header] if options[:push_scope] == false code = <<-CODE def #{_traced_method_name(method_name, metric_name_code)}(*args, &block) #{header} t0 = Time.now.to_f stats = NewRelic::Agent.instance.stats_engine.get_stats_no_scope "#{metric_name_code}" begin #{"NewRelic::Agent.instance.push_trace_execution_flag(true)\n" if options[:force]} #{_untraced_method_name(method_name, metric_name_code)}(*args, &block)\n ensure #{"NewRelic::Agent.instance.pop_trace_execution_flag\n" if options[:force] } duration = Time.now.to_f - t0 stats.trace_call(duration) #{options[:code_footer]} end end CODE else code = <<-CODE def #{_traced_method_name(method_name, metric_name_code)}(*args, &block) #{options[:code_header]} result = #{klass}.trace_execution_scoped("#{metric_name_code}", :metric => #{options[:metric]}, :forced => #{options[:force]}, :deduct_call_time_from_parent => #{options[:deduct_call_time_from_parent]}, :scoped_metric_only => #{options[:scoped_metric_only]}) do #{_untraced_method_name(method_name, metric_name_code)}(*args, &block) end #{options[:code_footer]} result end CODE end class_eval code, __FILE__, __LINE__ alias_method _untraced_method_name(method_name, metric_name_code), method_name alias_method method_name, _traced_method_name(method_name, metric_name_code) NewRelic::Control.instance.log.debug("Traced method: class = #{self.name}, method = #{method_name}, "+ "metric = '#{metric_name_code}', options: #{options.inspect}") end # For tests only because tracers must be removed in reverse-order # from when they were added, or else other tracers that were added to the same method # may get removed as well. def remove_method_tracer(method_name, metric_name_code) # :nodoc: return unless NewRelic::Control.instance.agent_enabled? if method_defined? "#{_traced_method_name(method_name, metric_name_code)}" alias_method method_name, "#{_untraced_method_name(method_name, metric_name_code)}" undef_method "#{_traced_method_name(method_name, metric_name_code)}" else raise "No tracer for '#{metric_name_code}' on method '#{method_name}'" end end private def _untraced_method_name(method_name, metric_name) "#{_sanitize_name(method_name)}_without_trace_#{_sanitize_name(metric_name)}" end def _traced_method_name(method_name, metric_name) "#{_sanitize_name(method_name)}_with_trace_#{_sanitize_name(metric_name)}" end def _sanitize_name(name) name.to_s.tr_s('^a-zA-Z0-9', '_') end end end end end