rails debug helper for tracking mutating state across contexts

lkdebug.rb

# debugging helper for tracing variable changes across contexts in legacy code.  The context information such as file, line, 
# class and method are automatically logged for you so you can focus on tracing the state mutations through various contexts 
# with ease.
# @note this top-level method may be placed in config/initializers/lkdebug.rb and used anywhere
# @note this method does nothing outside of Rails.env.development
# @note legacy examples are intentionally bad code!! You should not write code like this, but if you have to debug code like this
#   you may want to dump state from various contexts within the program to understand what is going on.
#
# @param annotation [String] text comment providing context for the log.
# @param block [Proc] a valid Ruby expression evaluated in the context of the call. Both the Ruby source of the expression and 
#   its inspected value will be displayed in the log. 
#
# @example displaying variable state with context and a comment
#   # app/controllers/project_controller.rb:
#   def trial_project
#     ...
#     lkdebug("redirecting to new"){ params }
#     redirect_to(action: "new", params: params) and return
#     ...
#   end 
#   # => LKD: app/controllers/project_controller.rb:74 (ProjectController#trial_project) params => { :trial => true }  # redirecting to new
#
# @example using tail to trace state changes across contexts - discovery of shadowed variable
#   # app/models/user.rb:
#   def initialize(params)
#     lkdebug{ params[:admin_flag] }
#     @admin = params[:admin_flag] == "Y"
#     lkdebug{ @admin }
#   end 
#
#   # app/controllers/welcome_controller.rb:
#   before_action :load_user
# 
#   def login
#     ...
#     lkdebug("start of relogin scenario...")
#     lkdebug{ params[:admin_flag] }
#     user = User.new(params)       # <= error, using local var instead of existing @user
#     lkdebug("new should overwrite existing") { @user.admin }
#     lkdebug("ohhh!") { user.admin }
#     ...
#   end
#
#   def load_user
#     @user = User.new(session[:user_id])
#   end
# 
#   # console:
#   $ tail -f log/development.log | grep --line-buffered -E "^(Started|LKD)" | grep --line-buffered -v "/assets"
#   # => Started GET "/myroute" for x.x.x.x at 2018-12-20 12:39:06 -0500
#   # => LKD: # start of relogin scenario...
#   # => LKD: app/controllers/welcome_controller.rb:23 (WelcomeController#login) params[:admin_flag] => "Y"
#   # => LKD: app/models/user.rb:17 (User#initialize) params[:admin_flag] => "Y"
#   # => LKD: app/models/user.rb:19 (User#initialize) @admin => true
#   # => LKD: app/controllers/welcome_controller.rb:25 (WelcomeController#login) @user.admin => false  # new should overwrite existing
#   # => LKD: app/controllers/welcome_controller.rb:26 (WelcomeController#login) user.admin => true  # ohhh!
#
# @example use basic annotation only
#   lkdebug("transaction begins")
#   # => LKD: # transaction begins
#
def lkdebug(annotation="", &block)
  return unless Rails.env.development?

  context, expr, expr_value = nil

  if block_given?
    klass = eval("self.class", block.binding)
    meth  = eval("__method__", block.binding)
    line  = eval("__LINE__", block.binding)
    file  = eval("__FILE__", block.binding)
    file = Pathname.new(file).relative_path_from(Rails.root).to_s
    
    expr = block.source.match(/lkdebug[^\{]*\{(?<code>.*)\}\s*$/m)[:code].strip rescue block.source
    expr_value = block.call(block.binding)

    context = "#{file}:#{line} (#{klass}##{meth})"
  end

  msg = ""
  msg << "#{context} #{expr} => #{expr_value.inspect} " unless context.blank?
  msg << " # #{annotation}" unless annotation.blank?

  Rails.logger.debug("LKD: #{msg}")
end