ruby-core@ruby-lang.org archive (unofficial mirror)
 help / color / mirror / Atom feed
* [ruby-core:70603] [Ruby trunk - Bug #11490] [Open] Allocation tracer sometimes attributes allocations to the wrong source file/line
       [not found] <redmine.issue-11490.20150827073853@ruby-lang.org>
@ 2015-08-27  7:38 ` godfreykfc
  2015-08-27  7:42 ` [ruby-core:70604] [Ruby trunk - Bug #11490] " godfreykfc
                   ` (2 subsequent siblings)
  3 siblings, 0 replies; 4+ messages in thread
From: godfreykfc @ 2015-08-27  7:38 UTC (permalink / raw
  To: ruby-core

Issue #11490 has been reported by Godfrey Chan.

----------------------------------------
Bug #11490: Allocation tracer sometimes attributes allocations to the wrong source file/line
https://bugs.ruby-lang.org/issues/11490

* Author: Godfrey Chan
* Status: Open
* Priority: Normal
* Assignee: 
* ruby -v: 
* Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN
----------------------------------------
See the reproduction script in https://gist.github.com/chancancode/dc175e702c02cdfa5ffb

This was originally brought to my attention via https://github.com/skylightio/skylight-ruby/issues/36

As you can see in the Github ticket, we overwrote `Kernel#require` and was incorrectly blamed for allocating a lot of objects/memory. I checked the source and saw that the file/line info is filled by the [last Ruby-land control frame](https://github.com/ruby/ruby/blob/7cf523c7db67c22ffc09b38a9c5bea057f578db2/vm_trace.c#L752), so I was almost ready to accept this as an unfortunate artifact that cannot be fixed.

However, when I made the standalone reproduction script to test my theory, I noticed that it actually gets it right sometimes (the lines that reports `nokogiri.bundle:0` instead of `allocation_tracker_bug.rb:11`), so it seems like something else is going on here.

By the way, since RubyGems overwrites `Kernel#require`, even without any other third-party libraries loaded, you can already observe allocation tracer attributing a lot of allocations to RubyGem's `kernel_require.rb` out of the box.

---Files--------------------------------
allocation_tracker_bug.rb (786 Bytes)


-- 
https://bugs.ruby-lang.org/

^ permalink raw reply	[flat|nested] 4+ messages in thread

* [ruby-core:70604] [Ruby trunk - Bug #11490] Allocation tracer sometimes attributes allocations to the wrong source file/line
       [not found] <redmine.issue-11490.20150827073853@ruby-lang.org>
  2015-08-27  7:38 ` [ruby-core:70603] [Ruby trunk - Bug #11490] [Open] Allocation tracer sometimes attributes allocations to the wrong source file/line godfreykfc
@ 2015-08-27  7:42 ` godfreykfc
  2015-08-27 21:10 ` [ruby-core:70612] " godfreykfc
  2015-09-01  9:02 ` [ruby-core:70643] [Ruby trunk - Bug #11490] [Feedback] " ko1
  3 siblings, 0 replies; 4+ messages in thread
From: godfreykfc @ 2015-08-27  7:42 UTC (permalink / raw
  To: ruby-core

Issue #11490 has been updated by Godfrey Chan.


Related: when the allocation tracer is trying to blame the `Kernel#require` monkey patch, the line number appears to be off-by-one ("11" instead of "12")

----------------------------------------
Bug #11490: Allocation tracer sometimes attributes allocations to the wrong source file/line
https://bugs.ruby-lang.org/issues/11490#change-54011

* Author: Godfrey Chan
* Status: Open
* Priority: Normal
* Assignee: 
* ruby -v: 
* Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN
----------------------------------------
See the reproduction script in https://gist.github.com/chancancode/dc175e702c02cdfa5ffb

This was originally brought to my attention via https://github.com/skylightio/skylight-ruby/issues/36

As you can see in the Github ticket, we overwrote `Kernel#require` and was incorrectly blamed for allocating a lot of objects/memory. I checked the source and saw that the file/line info is filled by the [last Ruby-land control frame](https://github.com/ruby/ruby/blob/7cf523c7db67c22ffc09b38a9c5bea057f578db2/vm_trace.c#L752), so I was almost ready to accept this as an unfortunate artifact that cannot be fixed.

However, when I made the standalone reproduction script to test my theory, I noticed that it actually gets it right sometimes (the lines that reports `nokogiri.bundle:0` instead of `allocation_tracker_bug.rb:11`), so it seems like something else is going on here.

By the way, since RubyGems overwrites `Kernel#require`, even without any other third-party libraries loaded, you can already observe allocation tracer attributing a lot of allocations to RubyGem's `kernel_require.rb` out of the box.

---Files--------------------------------
allocation_tracker_bug.rb (786 Bytes)


-- 
https://bugs.ruby-lang.org/

^ permalink raw reply	[flat|nested] 4+ messages in thread

* [ruby-core:70612] [Ruby trunk - Bug #11490] Allocation tracer sometimes attributes allocations to the wrong source file/line
       [not found] <redmine.issue-11490.20150827073853@ruby-lang.org>
  2015-08-27  7:38 ` [ruby-core:70603] [Ruby trunk - Bug #11490] [Open] Allocation tracer sometimes attributes allocations to the wrong source file/line godfreykfc
  2015-08-27  7:42 ` [ruby-core:70604] [Ruby trunk - Bug #11490] " godfreykfc
@ 2015-08-27 21:10 ` godfreykfc
  2015-09-01  9:02 ` [ruby-core:70643] [Ruby trunk - Bug #11490] [Feedback] " ko1
  3 siblings, 0 replies; 4+ messages in thread
From: godfreykfc @ 2015-08-27 21:10 UTC (permalink / raw
  To: ruby-core

Issue #11490 has been updated by Godfrey Chan.


Thinking about it more, it seems my original hunch is *probably* correct: when loading/parsing/evaluating the file, the VM has to allocate a large amount of objects (e.g. when it runs `def zomg; ...; end`, it needs to create the "immortal"symbol `:zomg`, among other things like `InstructionSequence`, etc). It then attributed the allocation of these objects to the closest Ruby frame. Since the "raw" `Kernel#require` is implemented in C, whoever calls it will end up "getting the blame".

That is fine in an ideal world – this would point to the line where you `require`d the file with lots of code (e.g. the `require "nokogiri"` line), and that is at least somewhat useful (I can save X MB if I don't use nokogiri, and you can choose to make that tradeoff; although that is rarely a real problem). Unfortunately, **all** Rubies (C Ruby) have at least one `Kernel#require` override in Ruby-land (in RubyGems), so in practice, this information is always going to point you to the "wrong" place. Most commonly, it will be [this line](https://github.com/rubygems/rubygems/blob/ae1718fd2d0e238940c38d56e32c56bffe083894/lib/rubygems/core_ext/kernel_require.rb#L54) in RubyGems, but it could also be [this line](https://github.com/rails/rails/blob/cae2b5bb59212961c4a35c939381ebece48d1177/activesupport/lib/active_support/dependencies.rb#L300) in Active Support or a similar place in bundler.

I'm not sure what's the best way to go about fixing this. Perhaps it should not report any allocation source/line for these internal VM things (the symbols, instruction sequence, etc), report it as "(VM internal):0", or perhaps point it to the corresponding line in the source (`:zomg` is "allocated" by the `def zomg` line).

Or perhaps it is just not a big deal and not worth the effort. If my explanation is right, I can accept that this is technically "correct", but evidently people have tried to use this information to "slim down" their app and this has caused them to go down the wrong rabbit hole.

----------------------------------------
Bug #11490: Allocation tracer sometimes attributes allocations to the wrong source file/line
https://bugs.ruby-lang.org/issues/11490#change-54018

* Author: Godfrey Chan
* Status: Open
* Priority: Normal
* Assignee: 
* ruby -v: 
* Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN
----------------------------------------
See the reproduction script in https://gist.github.com/chancancode/dc175e702c02cdfa5ffb

This was originally brought to my attention via https://github.com/skylightio/skylight-ruby/issues/36

As you can see in the Github ticket, we overwrote `Kernel#require` and was incorrectly blamed for allocating a lot of objects/memory. I checked the source and saw that the file/line info is filled by the [last Ruby-land control frame](https://github.com/ruby/ruby/blob/7cf523c7db67c22ffc09b38a9c5bea057f578db2/vm_trace.c#L752), so I was almost ready to accept this as an unfortunate artifact that cannot be fixed.

However, when I made the standalone reproduction script to test my theory, I noticed that it actually gets it right sometimes (the lines that reports `nokogiri.bundle:0` instead of `allocation_tracker_bug.rb:11`), so it seems like something else is going on here.

By the way, since RubyGems overwrites `Kernel#require`, even without any other third-party libraries loaded, you can already observe allocation tracer attributing a lot of allocations to RubyGem's `kernel_require.rb` out of the box.

---Files--------------------------------
allocation_tracker_bug.rb (786 Bytes)


-- 
https://bugs.ruby-lang.org/

^ permalink raw reply	[flat|nested] 4+ messages in thread

* [ruby-core:70643] [Ruby trunk - Bug #11490] [Feedback] Allocation tracer sometimes attributes allocations to the wrong source file/line
       [not found] <redmine.issue-11490.20150827073853@ruby-lang.org>
                   ` (2 preceding siblings ...)
  2015-08-27 21:10 ` [ruby-core:70612] " godfreykfc
@ 2015-09-01  9:02 ` ko1
  3 siblings, 0 replies; 4+ messages in thread
From: ko1 @ 2015-09-01  9:02 UTC (permalink / raw
  To: ruby-core

Issue #11490 has been updated by Koichi Sasada.

Status changed from Open to Feedback
Assignee set to Koichi Sasada

I don't think "(VM internal):0" is useful.


----------------------------------------
Bug #11490: Allocation tracer sometimes attributes allocations to the wrong source file/line
https://bugs.ruby-lang.org/issues/11490#change-54044

* Author: Godfrey Chan
* Status: Feedback
* Priority: Normal
* Assignee: Koichi Sasada
* ruby -v: 
* Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN
----------------------------------------
See the reproduction script in https://gist.github.com/chancancode/dc175e702c02cdfa5ffb

This was originally brought to my attention via https://github.com/skylightio/skylight-ruby/issues/36

As you can see in the Github ticket, we overwrote `Kernel#require` and was incorrectly blamed for allocating a lot of objects/memory. I checked the source and saw that the file/line info is filled by the [last Ruby-land control frame](https://github.com/ruby/ruby/blob/7cf523c7db67c22ffc09b38a9c5bea057f578db2/vm_trace.c#L752), so I was almost ready to accept this as an unfortunate artifact that cannot be fixed.

However, when I made the standalone reproduction script to test my theory, I noticed that it actually gets it right sometimes (the lines that reports `nokogiri.bundle:0` instead of `allocation_tracker_bug.rb:11`), so it seems like something else is going on here.

By the way, since RubyGems overwrites `Kernel#require`, even without any other third-party libraries loaded, you can already observe allocation tracer attributing a lot of allocations to RubyGem's `kernel_require.rb` out of the box.

---Files--------------------------------
allocation_tracker_bug.rb (786 Bytes)


-- 
https://bugs.ruby-lang.org/

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2015-09-01  8:41 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
     [not found] <redmine.issue-11490.20150827073853@ruby-lang.org>
2015-08-27  7:38 ` [ruby-core:70603] [Ruby trunk - Bug #11490] [Open] Allocation tracer sometimes attributes allocations to the wrong source file/line godfreykfc
2015-08-27  7:42 ` [ruby-core:70604] [Ruby trunk - Bug #11490] " godfreykfc
2015-08-27 21:10 ` [ruby-core:70612] " godfreykfc
2015-09-01  9:02 ` [ruby-core:70643] [Ruby trunk - Bug #11490] [Feedback] " ko1

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).