Как я могу регистрировать каждый метод, который вызывается в программе Ruby?

Я унаследовал большую кучу кода Ruby, который, честно говоря, почти невозможно понять для такого смертного, как я. Это на самом деле Rspec unit test код, но структура "очень необычна", чтобы сделать это красиво.

То, что я хотел бы сделать, это запустить код и записать следующую информацию:

каждый метод, который вызывается, включая имя класса, определяющего метод, и имя файла, в котором был указан метод, вызываемый (да, у нас есть тот же класс/метод, определенный в нескольких разных файлах, и это трудно узнать, что вызывается)
(необязательно) параметры, переданные каждому вызванному методу

С этим я мог бы попытаться реорганизовать его. Без этого задача будет очень сложной, чтобы выправить ее из-за размера базы кода (20k + unit test).

Я не могу позволить себе входить и выполнять опционные изменения в выполняемом коде, потому что он ломается, когда вы даже используете грубый язык вокруг него (то есть часто). Вместо этого мне нужно иметь возможность управлять кодом в его существующем состоянии или с минимальными изменениями в том, что существует сейчас.

Есть ли способ регистрации этого уровня детализации без внесения оптовых изменений в базу кода? Я посмотрел на профилировщик Ruby, чтобы увидеть, может ли это помочь, и, возможно, это возможно; Мне любопытно, есть ли лучший способ (в частности, регистрировать имя файла, содержащего вызванный метод).

Заранее спасибо

Ответ 1

Это определенно возможно - на самом деле, есть даже метод для этого! Просто добавьте это где-нибудь в свой код до того момента, когда вы хотите начать регистрировать вещи:

set_trace_func proc { |event, file, line, id, binding, classname|
  printf "%8s %s:%-2d %10s %8s\n", event, file, line, id, classname
}

Секретный соус, который вы хотите, приходит от Kernel#set_trace_func, как указано выше:

set_trace_func (proc) = > proc

set_trace_func (nil) = > nil
Устанавливает proc как обработчик для трассировки или отключает трассировку, если параметр nil. proc принимает до шести параметров: имя события, имя файла, номер строки, идентификатор объекта, привязку и имя класса. proc вызывается всякий раз, когда происходит событие. События: c-call (вызов подпрограммы на языке C), c-return (возврат из подпрограммы на языке C), call (вызов метода Ruby), class (начало определения класса или модуля) end (завершите определение класса или модуля), line (выполните код в новой строке), raise (поднимите исключение) и return (возврат из метода Ruby). Трассировка отключена в контексте proc.

Вот удобный пример:

class Test
  def test
    a = 1
    b = 2
  end
end

set_trace_func proc { |event, file, line, id, binding, classname|
  printf "%8s %s:%-2d %10s %8s\n", event, file, line, id, classname
}

t = Test.new
t.test

(Примечание: не пытайтесь использовать это в irb, если вам не нужен огромный экран прокрутки текста.) Результат:

    line test.rb:11               false
  c-call test.rb:11        new    Class
  c-call test.rb:11 initialize   Object
c-return test.rb:11 initialize   Object
c-return test.rb:11        new    Class
    line test.rb:12               false
    call test.rb:2        test     Test
    line test.rb:3        test     Test
    line test.rb:4        test     Test
  return test.rb:4        test     Test

Вы можете играть со строкой форматирования выше, чтобы получить только те результаты, которые хотите записать (например, похоже, что вас интересуют только события call). Надеюсь, что это поможет, и удачи в сортировке всех этих модульных тестов!

Ответ 2

Я хотел включить секунды, прошедшие за минуту, когда событие произошло, а также сколько времени было потрачено на каждую функцию

start = DateTime.now.strftime('%Q').to_i / 1000.0
set_trace_func proc { |event, file, line, id, binding, classname|
  now_ms = DateTime.now.strftime('%Q').to_i / 1000.0
  duration = '%.3f' % (now_ms - start)
  start = DateTime.now.strftime('%Q').to_i / 1000.0
  printf "%s %s %8s %s:%-2d %10s %8s\n", DateTime.now.strftime("%S.%L"), duration, event, file, line, id, classname
}

AdminUser.create(password: "password", password_confirmation: "password", email: email)

set_trace_func nil

Я пытался отлаживать, почему так долго нужно создавать пользователей и входить в ActiveAdmin.

05.761 0.000 c-return /Users/nperry/.rvm/gems/[email protected]/gems/bcrypt-3.1.7/lib/bcrypt/engine.rb:51       to_s   String
05.761 0.000   c-call /Users/nperry/.rvm/gems/[email protected]/gems/bcrypt-3.1.7/lib/bcrypt/engine.rb:51 __bc_crypt BCrypt::Engine
09.736 63.975 c-return /Users/nperry/.rvm/gems/[email protected]/gems/bcrypt-3.1.7/lib/bcrypt/engine.rb:51 __bc_crypt BCrypt::Engine
09.736 0.000   return /Users/nperry/.rvm/gems/[email protected]/gems/bcrypt-3.1.7/lib/bcrypt/engine.rb:59 hash_secret BCrypt::Engine
09.736 0.000   c-call /Users/nperry/.rvm/gems/[email protected]/gems/bcrypt-3.1.7/lib/bcrypt/password.rb:46        new    Class

И из этого я знаю, что Руби провел больше минуты в __bc_crypt.

Ответ 3

В последнее время set_trace_func устарели:

Примечание: этот метод устарел, вместо этого используйте TracePoint.

Мы можем использовать TracePoint, который поддерживает set_trace_func, вместо этого:

trace = TracePoint.new(:call) do |tp|
  puts "#{tp.defined_class}##{tp.method_id} got called (#{tp.path}:#{tp.lineno})"
end

trace.enable
# do stuff here
trace.disable

Это на самом деле даже более мощное, чем set_trace_func, потому что вы можете включать и отключать в удобное для вас время. Вы можете выборочно подключаться к следующим событиям: :line, :class, :end, :call, :return, :c_call, :c_return, :raise, :b_call, :b_return, :thread_begin, :thread_end

Вот полный пример:

class MyClass
  def initialize
  end
  def y
    z
  end
  def z
   1 + 1
  end
end

trace = TracePoint.new(:call) do |tp|
  puts "#{tp.defined_class}##{tp.method_id} got called (#{tp.path}:#{tp.lineno})"
end

trace.enable # note
MyClass.new.y
trace.disable
  # MyClass#initialize got called (./trace.rb:4)
  # MyClass#y got called (./trace.rb:7)
  # MyClass#z got called (./trace.rb:10)