--profile.graph sometimes shows wrong methods

I think the problem here is that the the new! method for Date and the new method for GemPathSearcher are resolving to the same actual method object in-memory in JRuby. As a result, we go with the first one defined, and report all future results with that method's name.

Looking into it.

Ok, this might be tricky to fix, but it would be nice. I think what we need to do is expand the profile gathering to consider both the target class's ID and the method serial number. The issue is something like this:

Given the following code

class Foo
  def something; end
end

class Bar < Foo; end
class Baz < Foo; end

calls to Bar#something or Baz#something will show up in profiles as always being Foo#something. In this case, it's not as misleading, but in the case of core methods inherited by user-created classes, it can be very strange.

Consider, for example, the following:

~/projects/jruby ➔ jruby --profile -e "class Foo; end; class Bar; end; 10000.times { Foo.new; Bar.new }"
Total time: 0.03

     total        self    children       calls  method
----------------------------------------------------------------
      0.03        0.02        0.01           1  Fixnum#times
      0.01        0.01        0.00       20000  Class#new
      0.00        0.00        0.00       20000  Object#initialize
      0.00        0.00        0.00         147  Class#inherited

Here, there are two different classes' objects being constructed: Foo and Bar instances. But they both use the default "new" implementation from JRuby, which results in only that method class+name showing up in profiles.

Now this may actually be appropriate, if sometimes confusing. It's most tricky in the case of class methods like "new", since they're almost always shared across many different classes. But there's really only one method, and so profiles showing different methods could also be misleading.

It also occurs to me as I write this that we may be unconditionally redefining the class+name for a given method, which causes Date.new! to get used for several other "new" calls. I'll look into that now as well.

Ok, as neat as it might be to see the actual class against which a method is being called, I've decided that's out of scope for this bug.

In the original case, the method being called is actually the default "new", indicated by Class#new normally. Because Date aliased that new to new!, it took over the serial number we use to identify that unique method, and all subsequent calls to the default new showed up as Date::new!.

I made a minor modification to the name-gathering part of profiling to only use the first name encountered for a given serial number, since subsequent uses of the same serial number are all still the same method body. With this change, profiles are now making a lot more sense, and the Date.new! that was reported as a problem shows up properly as Class#new.

commit 04ce8b7d9d93135fcf274389be392875a5b2d8cb
Author: Charles Oliver Nutter <headius@headius.com>
Date: Tue Jan 25 18:19:09 2011 -0600

Fix JRUBY-5356: --profile.graph sometimes shows wrong methods

• Only use the first name encountered for a given method serial, since aliases/etc will re-use them.