Why does ruby-prof list "Kernel#`" as a resource hog?

Question

I'm using ruby-prof to figure out where my CPU time is going for a small 2D game engine I'm building in Ruby. Everything looks normal here aside from the main Kernel#` entry. The Ruby docs here would suggest that this is a function for getting the STDOUT of a command running in a subshell:

Measure Mode: wall_time
Thread ID: 7966920
Fiber ID: 16567620
Total: 7.415271
Sort by: self_time

 %self      total      self      wait     child     calls  name
 28.88      2.141     2.141     0.000     0.000      476   Kernel#`
 10.72      1.488     0.795     0.000     0.693  1963500   Tile#draw
  9.35      0.693     0.693     0.000     0.000  1963976   Gosu::Image#draw
  6.67      7.323     0.495     0.000     6.828      476   Gosu::Window#_tick
  1.38      0.102     0.102     0.000     0.000     2380   Gosu::Font#draw
  0.26      4.579     0.019     0.000     4.560    62832  *Array#each
  0.15      0.011     0.011     0.000     0.000      476   Gosu::Window#caption=
  0.09      6.873     0.007     0.000     6.867      476   PlayState#draw
  0.07      0.005     0.005     0.000     0.000      476   String#gsub
  0.06      2.155     0.004     0.000     2.151      476   GameWindow#memory_usage
  0.06      4.580     0.004     0.000     4.576     1904   Hash#each
  0.04      0.003     0.003     0.000     0.000      476   String#chomp
  0.04      0.038     0.003     0.000     0.035      476   Gosu::Window#protected_update
  0.04      0.004     0.003     0.000     0.001     3167   Gosu::Window#button_down?
  0.04      0.005     0.003     0.000     0.002      952   Enumerable#map
  0.03      0.015     0.003     0.000     0.012      476   Player#update
  0.03      4.596     0.002     0.000     4.593      476   <Module::Gosu>#scale
  0.03      0.002     0.002     0.000     0.000     5236   Fixnum#to_s
  0.03      7.326     0.002     0.000     7.324      476   Gosu::Window#tick
  0.03      0.003     0.002     0.000     0.001      952   Player#coord_facing
  0.03      4.598     0.002     0.000     4.597      476   <Module::Gosu>#translate
  0.02      0.002     0.002     0.000     0.000      952   Array#reject

Any suggestions as to why this might be happening? I'm fairly confident that I'm not using it in my code - unless it's being called indirectly somehow. Not sure where to start looking for that sort of thing.

score 1 · Accepted Answer · answered Jun 23 '17 at 00:59

I've solved my problem. Though it wasn't exactly clear to me given the ruby documentation I linked in the question, the source of the problem is how ruby-prof categorizes the usage of the #{} shortcut, also known as 'string interpolation'. I had semi-intensive debugging logic being executed within these shortcuts.

Turning off my debugging text solves my problem.

Why does ruby-prof list "Kernel#`" as a resource hog?

1 Answers1