views:

307

answers:

2

EDIT: I slightly changed the spec, to better match what I imagined this to do.

Well, I don't really want to fake C# attributes, I want to one-up-them and support AOP as well.

Given the program:

class Object
  def Object.profile 
    # magic code here
  end
end 

class Foo
  # This is the fake attribute, it profiles a single method.
  profile
  def bar(b)
   puts b
  end

  def barbar(b)
    puts(b)
  end

  comment("this really should be fixed")
  def snafu(b)
  end

end

Foo.new.bar("test")
Foo.new.barbar("test") 
puts Foo.get_comment(:snafu)

Desired output:

Foo.bar was called with param: b = "test"
test
Foo.bar call finished, duration was 1ms
test
This really should be fixed

Is there any way to achieve this?

+6  A: 

Great question. This is my quick attempt at an implementation (I did not try to optimise the code). I took the liberty of adding the profile method to the Module class. In this way it will be available in every class and module definition. It would be even better to extract it into a module and mix it into the class Module whenever you need it.

I also didn't know if the point was to make the profile method behave like Ruby's public/protected/private keywords, but I implemented it like that anyway. All methods defined after calling profile are profiled, until noprofile is called.

class Module
  def profile
    require "benchmark"
    @profiled_methods ||= []
    class << self
      # Save any original method_added callback.
      alias_method :__unprofiling_method_added, :method_added
      # Create new callback.
      def method_added(method)
        # Possible infinite loop if we do not check if we already replaced this method.
        unless @profiled_methods.include?(method)
          @profiled_methods << method
          unbound_method = instance_method(method)
          define_method(method) do |*args|
            puts "#{self.class}##{method} was called with params #{args.join(", ")}"
            bench = Benchmark.measure do
              unbound_method.bind(self).call(*args)
            end
            puts "#{self.class}##{method} finished in %.5fs" % bench.real
          end
          # Call the original callback too.
          __unprofiling_method_added(method)
        end
      end
    end
  end

  def noprofile # What's the opposite of profile?
    class << self
      # Remove profiling callback and restore previous one.
      alias_method :method_added, :__unprofiling_method_added
    end
  end
end

You can now use it as follows:

class Foo
  def self.method_added(method) # This still works.
    puts "Method '#{method}' has been added to '#{self}'."
  end

  profile

  def foo(arg1, arg2, arg3 = nil)
    puts "> body of foo"
    sleep 1
  end

  def bar(arg)
    puts "> body of bar"
  end

  noprofile

  def baz(arg)
    puts "> body of baz"
  end
end

Call the methods as you would normally:

foo = Foo.new
foo.foo(1, 2, 3)
foo.bar(2)
foo.baz(3)

And get benchmarked output (and the result of the original method_added callback just to show that it still works):

Method 'foo' has been added to 'Foo'.
Method 'bar' has been added to 'Foo'.
Method 'baz' has been added to 'Foo'.
Foo#foo was called with params 1, 2, 3
> body of foo
Foo#foo finished in 1.00018s
Foo#bar was called with params 2
> body of bar
Foo#bar finished in 0.00016s
> body of baz

One thing to note is that it is impossible to dynamically get the name of the arguments with Ruby meta-programming. You'd have to parse the original Ruby file, which is certainly possible but a little more complex. See the parse_tree and ruby_parser gems for details.

A fun improvement would be to be able to define this kind of behaviour with a class method in the Module class. It would be cool to be able to do something like:

class Module
  method_wrapper :profile do |*arguments|
    # Do something before calling method.
    yield *arguments  # Call original method.
    # Do something afterwards.
  end
end

I'll leave this meta-meta-programming exercise for another time. :-)

molf
+1 awesome answer, will add a few comments in my question
Sam Saffron
Note: I'm going to wait 24 hours or so before accepting this, to encourage some more feedback on the question. I added extended specs, so it better matches the way C# does attribs. Thanks again for the detailed and well thought out answer
Sam Saffron
Ruby 1.9.2 has Proc#args, so you *can* actually get the names of the parameters.
Jörg W Mittag
Great question, great answer.
Ryan Bigg
Sorry, that's Proc#parameters, not Proc#args. See: https://GitHub.Com/RubySpec/MatzRuby/blob/trunk/proc.c#L694-710 for more information.
Jörg W Mittag
Jörg: You can actually get support for getting method parameters, as I alluded below, across all implementation, using the action_args code in Merb. I should release it as a standalone gem.
Yehuda Katz
+9  A: 

I have a somewhat different approach:

class Object
  def self.profile(method_name)
    return_value = nil
    time = Benchmark.measure do
      return_value = yield
    end

    puts "#{method_name} finished in #{time.real}"
    return_value
  end
end

require "benchmark"

module Profiler
  def method_added(name)
    profile_method(name) if @method_profiled
    super
  end

  def profile_method(method_name)
    @method_profiled = nil
    alias_method "unprofiled_#{method_name}", method_name
    class_eval <<-ruby_eval
      def #{method_name}(*args, &blk)
        name = "\#{self.class}##{method_name}"
        msg = "\#{name} was called with \#{args.inspect}"
        msg << " and a block" if block_given?
        puts msg

        Object.profile(name) { unprofiled_#{method_name}(*args, &blk) }
      end
    ruby_eval
  end

  def profile
    @method_profiled = true
  end
end

module Comment
  def method_added(name)
    comment_method(name) if @method_commented
    super
  end

  def comment_method(method_name)
    comment = @method_commented
    @method_commented = nil
    alias_method "uncommented_#{method_name}", method_name
    class_eval <<-ruby_eval
      def #{method_name}(*args, &blk)
        puts #{comment.inspect}
        uncommented_#{method_name}(*args, &blk)
      end
    ruby_eval
  end

  def comment(text)
    @method_commented = text
  end
end

class Foo
  extend Profiler
  extend Comment

  # This is the fake attribute, it profiles a single method.
  profile
  def bar(b)
   puts b
  end

  def barbar(b)
    puts(b)
  end

  comment("this really should be fixed")
  def snafu(b)
  end
end

A few points about this solution:

  • I provided the additional methods via modules which could be extended into new classes as needed. This avoids polluting the global namespace for all modules.
  • I avoided using alias_method, since module includes allow AOP-style extensions (in this case, for method_added) without the need for aliasing.
  • I chose to use class_eval rather than define_method to define the new method in order to be able to support methods that take blocks. This also necessitated the use of alias_method.
  • Because I chose to support blocks, I also added a bit of text to the output in case the method takes a block.
  • There are ways to get the actual parameter names, which would be closer to your original output, but they don't really fit in a response here. You can check out merb-action-args, where we wrote some code that required getting the actual parameter names. It works in JRuby, Ruby 1.8.x, Ruby 1.9.1 (with a gem), and Ruby 1.9 trunk (natively).
  • The basic technique here is to store a class instance variable when profile or comment is called, which is then applied when a method is added. As in the previous solution, the method_added hook is used to track when the new method is added, but instead of removing the hook each time, the hook checks for an instance variable. The instance variable is removed after the AOP is applied, so it only applies once. If this same technique was used multiple time, it could be further abstracted.
  • In general, I tried to stick as close to your "spec" as possible, which is why I included the Object.profile snippet instead of implementing it inline.
Yehuda Katz
+1 fantastic answer.
Sam Saffron