[ruby-dev:42345] [Ruby 1.9-Feature#3917][Open] [proposal] called_from() which is much faster than caller()

Feature #3917: [proposal] called_from() which is much faster than caller()
http://redmine.ruby-lang.org/issues/show/3917

起票者: makoto kuwata
ステータス: Open, 優先度: Normal
カテゴリ: core, Target version: 1.9.x

I propose to introduce Kernel#called_from() which is similar to caller()
but much faster than it.


Background
----------

There are some cases to want to know from where current method is called.
In this case, Kernel#caller() is used.

But Kernel#caller() has performance issues for these cases.

* caller() retrieves entire stack frame. It is too heavy.
* caller() returns an array of "filename:linenum in `method'" string.
  User must parse it and retrieve filename and linenum by rexp.
  It is also very heavy weight task.

Therefore I propose Kernel#called_from() which is very light weight
compared to caller(). A certain benchmark shows that called_from()
is more than 20 times faster tan caller().

現在のメソッドがどこから呼び出されたかを知りたい場合がときどきある。
こういう場合は通常 Kernel#caller() が使われる。

しかし Kernel#caller() は、こういった用途ではパフォーマンスが非常に悪い。

* caller() はスタックフレームをすべて取り出す。これは非常に重い操作。
* caller() は "ファイル名:行番号 in `メソッド名'" という文字列の配列を返す。
  ユーザは正規表現を使ってこの文字列をわざわざパースしなければならない。
  これも重い操作。

そのため、Kernel#called_from() を追加することを提案する。
このメソッドは caller() と比べて非常に動作が軽く、ベンチマークでは
called_from() は caller() と比べて20倍以上高速。


Spec
-----

call-seq:
   called_from(start=1)    -> array or nil

Returns file name, line number, and method name of the stack.
The optional _start_ parameter represents the number of stack
entries to skip.

Returns +nil+ if _start_ is greater than the size of
current execution stack.

Raises ArgumentError if _start_ is negative value.


Example code
------------

  # example.rb
   1:  def f1()
   2:    f2()
   3:  end
   4:  def f2()
   5:    f3()
   6:  end
   7:  def f3()
   8:    p called_from()    #=> ["example.rb", 5, "f2"]
   9:    p called_from(0)   #=> ["example.rb", 9, "f3"]
  10:    p called_from(1)   #=> ["example.rb", 5, "f2"]
  11:    p called_from(2)   #=> ["example.rb", 2, "f1"]
  12:    p called_from(3)   #=> ["example.rb", 15, "<main>"]
  13:    p called_from(4)   #=> nil
  14:  end
  15:  f1()


Use Case
--------

Case 1: logging method

  def log_info(message)
    filename, linenum, _ = called_from()   # !!!
    @logger.info "#{filename}:#{linenum}: #{message}"
  end


Case 2: debug print

  def debug(message)
    filename, linenum, _ = called_from()   # !!!
    $stderr.puts "*** DEBUG: #{filename}:#{linenum}: #{message}"
  end


Case 3: deprecation message

  def send(*args)
    filename, linenum, _ = called_from()   # !!!
    msg = "`send()' is deprecated. use `__send__()' instead."
    msg << " (file: #{filename}, line: #{linenum})"
    $stderr.puts "*** warning: #{msg}"
    __send__(*args)
  end


Case 4: ActiveSupport::Testing::Pending

  module ActiveSupport::Testing::Peding
    def pending(description = "", &block)
        :
      #caller[0] =~ (/(.*):(.*):in `(.*)'/)             # original
      #@@pending_cases << "#{$3} at #{$1}, line #{$2}"  # original
      #print "P"                                        # original
      filenemae, linenum, method = called_from()    # !!!
      @@pending_cases << "#{method} at #{filename}, line #{linenum}"
      print "P"
        :
    end
  end


Case 5: activesupport/lib/active_support/core_ext/module/delegation.rb

  class Module
    def delegate(*methods)
        :
      #file, line = caller.first.split(':', 2)  # original
      #line = line.to_i                         # original
      file, line, _ = called_from()             # !!!
        :
      module_eval(<<-EOS, file, line - 5)
        :
    end
  end


Case 6: caching helper for template system

  def cache_with(key)
    data, created_at = @_cache_store.get(key)
    filename, = called_from()   # !!!
    ## if template file is newer than cached data then clear cache.
    ## (performance is very important in this case.)
    if created_at < File.mtime(filename)
      data = nil
      @_cache_store.del(key)
    end
    ##
    if data.nil?
      len = @_buf.length
      yield
      data = @_buf[len..-1]
      @_cache_store.set(key, data)
    else
      @_buf << data
    end
    nil
  end
  
  ## in template file
  <% cache_with("orders/#{@order.id}") do %>
    <p>Order ID: <%=h @order.id %></p>
    <p>Customer: <%=h @order.customer.name %></p>
  <% end %>


Benchmark
---------

Attached benchmark shows that called_from() is much faster than caller().
This is very important for logging or template timestamp check.

    $ ./ruby -s bench.rb -N=100000
                                        user     system      total        real
    caller()[0]                     1.890000   0.010000   1.900000 (  1.941812)
    caller()[0] (retrieve)          2.190000   0.010000   2.200000 (  2.225966)
    called_from()                   0.100000   0.000000   0.100000 (  0.102810)
    called_from() (retrieve)        0.100000   0.000000   0.100000 (  0.102133)


Another Solutions
-----------------

Adding new gobal function may be refused.
The followings are another solutions instead of new global function.

* Extend caller() to take 'count' parameter.
  For example:

    start = 1
    count = 1
    caller(start, count)  #=> ["filename:linenum in `method'"]

* Extend caller() to take 'conbine' flag.
  For example:

    start = 1
    count = nil
    conbine = false
    caller(start, count, conbine)
                         #=> [["filename", linenum, "method"],
			 #    ["filename", linenum, "method"],
			 #    .... ]

* Add new standard library 'called_from.so' instead of Kernel#called_from().

新しいグローバル関数を導入するのは拒絶される可能性が高い。
その場合は、caller()を拡張してcalled_from()相当のことができるように
してもらえるとうれしい。
あるいは Kernel#called_from() ではなくても called_from.so を標準添付
する方針でもいい。


Note
----

* I tried to implement the above solutions, but failed because
  vm_backtrace_each() seems to search stack frames in the reverse
  order of what called_from() requires.

* I can implement called_from() as user library in Ruby 1.8.
  http://rubygems.org/gems/called_from
  It is allowed to access to stack frame in Ruby 1.8, but no in 1.9.
  This is why I submit this propose.

* 実は上記のanother solutionsを実装しようとしたが、called_from() では
  直近のスタックフレームから辿りたいのに対し、vm_backtrace_each() は
  逆の順番で辿ることしかできないようなので、実装を諦めた。

* Ruby 1.8 では拡張モジュールからスタックフレームにアクセスできるので
  ライブラリとして実装した。
  http://rubygems.org/gems/called_from
  けど1.9ではスタックフレームへのアクセスができないので、ライブラリが
  作れない。そのため今回このような提案をしてみた。


----------------------------------------
http://redmine.ruby-lang.org