Project

General

Profile

Feature #3917

Updated by ko1 (Koichi Sasada) over 6 years ago

=begin

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ではスタックフレームへのアクセスができないので、ライブラリが
作れない。そのため今回このような提案をしてみた。

=end

Back