Overview
Ruby provides event tracing capabilities through the TracePoint API and related tracing mechanisms. These tools allow developers to monitor program execution by intercepting specific events like method calls, returns, line execution, and exception handling. The primary interface is the TracePoint class, which creates trace objects that respond to various execution events.
TracePoint objects attach to Ruby's internal tracing hooks and execute callback blocks when specified events occur. Ruby supports multiple event types including :call
, :return
, :line
, :class
, :end
, :c_call
, :c_return
, :b_call
, :b_return
, :thread_begin
, :thread_end
, :raise
, and :rescue
. Each event provides access to execution context through methods like #method_id
, #path
, #lineno
, and #binding
.
# Basic TracePoint creation
trace = TracePoint.new(:call) do |tp|
puts "Method called: #{tp.method_id} in #{tp.path}:#{tp.lineno}"
end
trace.enable
some_method_call
trace.disable
The tracing system integrates with Ruby's execution engine at a low level, providing visibility into program flow without requiring code modification. TracePoint objects can be enabled globally or for specific code blocks, making them suitable for debugging, profiling, and dynamic analysis.
# Multiple event types
trace = TracePoint.new(:call, :return, :line) do |tp|
case tp.event
when :call
puts "→ #{tp.method_id}"
when :return
puts "← #{tp.method_id} returns #{tp.return_value}"
when :line
puts " #{tp.path}:#{tp.lineno}"
end
end
Ruby also provides the older set_trace_func
method and Kernel#trace_var for variable tracing, though TracePoint represents the modern approach. The tracing system supports multiple active trace objects simultaneously, with each receiving events according to their configured event types.
Basic Usage
TracePoint objects are created by calling TracePoint.new
with one or more event symbols and a callback block. The block receives the TracePoint object as a parameter, providing access to event details through various methods.
# Method call tracing
tracer = TracePoint.new(:call) do |tp|
puts "Called #{tp.method_id} in #{tp.defined_class}"
end
tracer.enable
Math.sqrt(16) # Triggers the trace
String.new("hello").upcase # Triggers the trace
tracer.disable
Event types determine which execution points trigger the callback. The :call
event fires when Ruby methods are invoked, while :c_call
triggers for C extension methods. Line-level tracing with :line
executes the callback for each line of Ruby code.
# Line-by-line execution tracing
line_tracer = TracePoint.new(:line) do |tp|
puts "#{File.basename(tp.path)}:#{tp.lineno} - #{tp.binding.local_variables}"
end
line_tracer.enable do
x = 10
y = x * 2
puts y
end
# Automatically disables after block
The TracePoint object provides context methods that return different values depending on the event type. Method-related events populate #method_id
and #defined_class
, while all events provide #path
and #lineno
for source location.
# Exception tracing
exception_tracer = TracePoint.new(:raise) do |tp|
puts "Exception: #{tp.raised_exception.class} - #{tp.raised_exception.message}"
puts " at #{tp.path}:#{tp.lineno} in #{tp.method_id}"
end
exception_tracer.enable
begin
1 / 0
rescue ZeroDivisionError
puts "Caught division by zero"
end
exception_tracer.disable
Block-scoped enabling ensures traces are automatically disabled when execution leaves the block, preventing memory leaks and performance degradation. This pattern is recommended for temporary tracing during specific operations.
# Class definition tracing
class_tracer = TracePoint.new(:class, :end) do |tp|
case tp.event
when :class
puts "Defining class: #{tp.self}"
when :end
puts "Class definition complete: #{tp.self}"
end
end
class_tracer.enable do
class ExampleClass
def example_method
"hello"
end
end
end
Advanced Usage
Advanced tracing scenarios involve filtering events, accessing execution context, and combining multiple trace strategies. TracePoint objects can inspect the binding at trace points, allowing access to local variables, instance variables, and the call stack.
# Method profiling with return value inspection
class MethodProfiler
def initialize
@call_stack = []
@call_counts = Hash.new(0)
end
def start_profiling
@tracer = TracePoint.new(:call, :return) do |tp|
method_key = "#{tp.defined_class}##{tp.method_id}"
case tp.event
when :call
@call_stack.push({
method: method_key,
start_time: Time.now,
args: extract_arguments(tp.binding)
})
@call_counts[method_key] += 1
when :return
if call_info = @call_stack.pop
duration = Time.now - call_info[:start_time]
puts "#{call_info[:method]} (#{duration.round(4)}s) -> #{tp.return_value.inspect}"
end
end
end
@tracer.enable
end
def stop_profiling
@tracer&.disable
puts "\nCall counts:"
@call_counts.each { |method, count| puts " #{method}: #{count}" }
end
private
def extract_arguments(binding)
binding.local_variables.map { |var| [var, binding.local_variable_get(var)] }.to_h
end
end
Conditional tracing allows filtering events based on runtime conditions. This reduces overhead by limiting trace execution to relevant code paths or specific conditions.
# Conditional tracing based on call location
filtered_tracer = TracePoint.new(:call) do |tp|
# Only trace methods called from specific files
caller_location = caller_locations(1, 1).first
next unless caller_location.path.include?('application')
# Only trace methods with specific naming patterns
next unless tp.method_id.to_s.match?(/^(create|update|delete)_/)
puts "Database operation: #{tp.method_id} in #{tp.defined_class}"
puts " Arguments: #{tp.binding.local_variables.map { |v|
"#{v}=#{tp.binding.local_variable_get(v).inspect}"
}.join(', ')}"
end
TracePoint objects support method chaining and can be combined with other metaprogramming techniques. The #self
method returns the current object context, while #binding
provides full access to the execution environment.
# Dynamic method instrumentation
module MethodInstrumentation
def self.instrument_class(klass, pattern: /.*/)
instrumented_methods = []
tracer = TracePoint.new(:call) do |tp|
next unless tp.defined_class == klass
next unless tp.method_id.to_s.match?(pattern)
method_name = tp.method_id
unless instrumented_methods.include?(method_name)
instrumented_methods << method_name
# Access to instance variables through binding
instance_vars = tp.self.instance_variables.map do |var|
"#{var}=#{tp.self.instance_variable_get(var).inspect}"
end.join(', ')
puts "First call to #{klass}##{method_name}"
puts " Instance state: #{instance_vars}" unless instance_vars.empty?
end
end
tracer.enable
tracer
end
end
Multiple TracePoint objects can operate simultaneously, each responding to different event types or conditions. This enables complex monitoring scenarios where different aspects of program execution require separate handling.
# Multi-layered tracing system
class ExecutionMonitor
def initialize
@active_traces = []
end
def monitor_database_calls
db_tracer = TracePoint.new(:call) do |tp|
if tp.defined_class.to_s.match?(/ActiveRecord|Sequel|Database/)
puts "DB: #{tp.defined_class}##{tp.method_id}"
end
end
@active_traces << db_tracer
db_tracer.enable
end
def monitor_exceptions
error_tracer = TracePoint.new(:raise) do |tp|
exception = tp.raised_exception
puts "ERROR: #{exception.class}: #{exception.message}"
puts " Location: #{tp.path}:#{tp.lineno}"
puts " Method: #{tp.method_id}" if tp.method_id
end
@active_traces << error_tracer
error_tracer.enable
end
def disable_all
@active_traces.each(&:disable)
@active_traces.clear
end
end
Error Handling & Debugging
Event tracing encounters specific error conditions that require careful handling. TracePoint callbacks can raise exceptions, potentially disrupting program execution or creating infinite recursion scenarios.
# Safe tracer with exception handling
class SafeTracer
def initialize(events, &block)
@tracer = TracePoint.new(*events) do |tp|
begin
block.call(tp)
rescue StandardError => e
# Log trace errors without disrupting program flow
STDERR.puts "Trace error: #{e.class}: #{e.message}"
STDERR.puts " at #{tp.path}:#{tp.lineno}"
# Disable tracer to prevent cascading errors
@tracer.disable
end
end
end
def enable(*args, &block)
@tracer.enable(*args, &block)
rescue StandardError => e
STDERR.puts "Failed to enable tracer: #{e.message}"
false
end
def disable
@tracer&.disable
rescue StandardError => e
STDERR.puts "Failed to disable tracer: #{e.message}"
false
end
end
Recursive tracing scenarios occur when trace callbacks trigger additional traceable events. This commonly happens when trace code calls methods that generate their own trace events, leading to stack overflow or infinite loops.
# Recursion detection and prevention
class RecursionSafeTracer
def initialize
@tracing_depth = 0
@max_depth = 10
end
def create_tracer(events)
TracePoint.new(*events) do |tp|
# Prevent recursive tracing
next if @tracing_depth > 0
@tracing_depth += 1
begin
# Guard against deep recursion
if @tracing_depth > @max_depth
puts "Trace depth limit reached, disabling tracer"
tp.disable
next
end
# Safe trace logic here
handle_trace_event(tp)
ensure
@tracing_depth -= 1
end
end
end
private
def handle_trace_event(tp)
# Avoid calling methods that might generate trace events
output = String.new
output << "Event: #{tp.event}"
output << " Method: #{tp.method_id}" if tp.respond_to?(:method_id) && tp.method_id
puts output
end
end
Debugging trace behavior requires understanding event timing and context availability. Some TracePoint methods are only valid for specific event types, and accessing them incorrectly raises NoMethodError.
# Robust event handling with type checking
def debug_trace_event(tp)
event_info = {
event: tp.event,
path: tp.path,
lineno: tp.lineno
}
# Safely access event-specific information
case tp.event
when :call, :c_call, :return, :c_return
if tp.respond_to?(:method_id)
event_info[:method] = tp.method_id
event_info[:class] = tp.defined_class if tp.respond_to?(:defined_class)
end
when :return, :c_return
if tp.respond_to?(:return_value)
event_info[:return_value] = tp.return_value.inspect
end
when :raise
if tp.respond_to?(:raised_exception)
event_info[:exception] = {
class: tp.raised_exception.class,
message: tp.raised_exception.message
}
end
end
# Safely access binding information
if tp.respond_to?(:binding) && tp.binding
begin
event_info[:local_vars] = tp.binding.local_variables.length
rescue StandardError
event_info[:binding_error] = "Could not access binding"
end
end
event_info
end
TracePoint objects must be explicitly disabled to prevent memory leaks and performance degradation. Failing to disable traces in long-running applications leads to accumulating overhead and potential memory exhaustion.
# Automatic cleanup with finalizers
class ManagedTracer
def initialize(events, &block)
@tracer = TracePoint.new(*events, &block)
@enabled = false
# Ensure cleanup on garbage collection
ObjectSpace.define_finalizer(self, self.class.create_finalizer(@tracer))
end
def self.create_finalizer(tracer)
proc { tracer.disable if tracer }
end
def enable
return false if @enabled
@tracer.enable
@enabled = true
# Register for cleanup on exit
at_exit { disable }
true
end
def disable
return false unless @enabled
@tracer.disable
@enabled = false
true
end
def enabled?
@enabled
end
end
Performance & Memory
Event tracing imposes significant performance overhead, particularly for high-frequency events like :line
tracing. Each trace callback execution adds method call overhead and potential memory allocation, making careful event selection critical for production use.
# Performance comparison of different trace strategies
require 'benchmark'
def performance_test
iterations = 100_000
# Baseline performance without tracing
baseline_time = Benchmark.realtime do
iterations.times { |i| calculate_fibonacci(10) }
end
# Method call tracing overhead
call_trace_time = Benchmark.realtime do
tracer = TracePoint.new(:call) { |tp| } # Empty callback
tracer.enable
iterations.times { |i| calculate_fibonacci(10) }
tracer.disable
end
# Line tracing overhead
line_trace_time = Benchmark.realtime do
tracer = TracePoint.new(:line) { |tp| } # Empty callback
tracer.enable
iterations.times { |i| calculate_fibonacci(10) }
tracer.disable
end
puts "Baseline: #{baseline_time.round(4)}s"
puts "Call tracing: #{call_trace_time.round(4)}s (#{(call_trace_time / baseline_time).round(2)}x slower)"
puts "Line tracing: #{line_trace_time.round(4)}s (#{(line_trace_time / baseline_time).round(2)}x slower)"
end
def calculate_fibonacci(n)
return n if n < 2
calculate_fibonacci(n - 1) + calculate_fibonacci(n - 2)
end
Memory consumption increases with trace complexity and callback logic. TracePoint objects retain references to binding objects and local variables, potentially preventing garbage collection of large data structures.
# Memory-conscious tracing implementation
class MemoryEfficientTracer
def initialize(events)
@event_counts = Hash.new(0)
@sample_interval = 100
@sample_counter = 0
@tracer = TracePoint.new(*events) do |tp|
@event_counts[tp.event] += 1
# Sample only every nth event to reduce memory pressure
@sample_counter += 1
next unless (@sample_counter % @sample_interval) == 0
# Store minimal information, avoid retaining large objects
log_sampled_event(tp)
end
end
def enable
# Clear counters to start fresh
@event_counts.clear
@sample_counter = 0
GC.start # Clean up before enabling
@tracer.enable
end
def disable
@tracer.disable
# Force garbage collection after disabling
GC.start
# Report statistics without retaining trace data
@event_counts.each do |event, count|
puts "#{event}: #{count} events"
end
@event_counts.clear
end
private
def log_sampled_event(tp)
# Create minimal data structure, avoid binding retention
event_data = {
event: tp.event,
method: tp.method_id&.to_s, # Convert to string to avoid symbol retention
path: File.basename(tp.path), # Use basename to reduce string size
line: tp.lineno
}
# Log immediately rather than storing
puts "Sample: #{event_data}"
end
end
Selective tracing reduces overhead by filtering events based on specific criteria before executing callback logic. This approach minimizes the performance impact while maintaining useful monitoring coverage.
# High-performance selective tracing
class SelectiveTracer
def initialize
@target_classes = Set.new
@target_methods = Set.new
@enabled = false
end
def add_class_filter(*classes)
@target_classes.merge(classes.map(&:to_s))
end
def add_method_filter(*methods)
@target_methods.merge(methods.map(&:to_s))
end
def start_tracing
return if @enabled
@tracer = TracePoint.new(:call) do |tp|
# Fast filtering using string comparison
class_name = tp.defined_class.to_s
method_name = tp.method_id.to_s
# Skip early if not in target classes
next unless @target_classes.empty? || @target_classes.include?(class_name)
# Skip early if not in target methods
next unless @target_methods.empty? || @target_methods.include?(method_name)
# Only perform expensive operations for filtered events
handle_filtered_event(tp, class_name, method_name)
end
@tracer.enable
@enabled = true
end
def stop_tracing
return unless @enabled
@tracer.disable
@tracer = nil
@enabled = false
end
private
def handle_filtered_event(tp, class_name, method_name)
# Minimize object creation and method calls
timestamp = Process.clock_gettime(Process::CLOCK_MONOTONIC)
puts "#{timestamp}: #{class_name}##{method_name}"
end
end
Thread Safety & Concurrency
TracePoint objects are not thread-safe by default, and enabling tracing from multiple threads can lead to race conditions and inconsistent behavior. Each thread maintains its own trace state, but callback execution can interfere with shared data structures.
# Thread-safe tracing with synchronization
class ThreadSafeTracer
def initialize(events)
@tracer = TracePoint.new(*events) do |tp|
thread_id = Thread.current.object_id
@mutex.synchronize do
@thread_events[thread_id] ||= []
@thread_events[thread_id] << {
event: tp.event,
method: tp.method_id,
thread: Thread.current.name || thread_id,
timestamp: Time.now
}
end
end
@mutex = Mutex.new
@thread_events = {}
@enabled = false
end
def enable
@mutex.synchronize do
return false if @enabled
@thread_events.clear
@tracer.enable
@enabled = true
end
end
def disable
@mutex.synchronize do
return false unless @enabled
@tracer.disable
@enabled = false
# Report per-thread statistics
@thread_events.each do |thread_id, events|
puts "Thread #{thread_id}: #{events.length} events"
end
@thread_events.clear
end
end
end
Concurrent tracing scenarios require careful coordination to prevent data corruption and ensure consistent reporting. Multiple threads enabling or disabling traces simultaneously can create undefined behavior.
# Multi-threaded application with coordinated tracing
class ConcurrentTracer
def initialize
@global_tracer = nil
@control_mutex = Mutex.new
@event_queue = Queue.new
@worker_thread = nil
@running = false
end
def start_monitoring
@control_mutex.synchronize do
return false if @running
# Start background worker for event processing
@running = true
@worker_thread = Thread.new { event_processor }
# Enable global tracing
@global_tracer = TracePoint.new(:call, :return) do |tp|
# Queue events for background processing
event_data = {
thread_id: Thread.current.object_id,
thread_name: Thread.current.name,
event: tp.event,
method: tp.method_id,
class: tp.defined_class,
timestamp: Process.clock_gettime(Process::CLOCK_MONOTONIC)
}
# Non-blocking queue operation
@event_queue << event_data rescue nil
end
@global_tracer.enable
true
end
end
def stop_monitoring
@control_mutex.synchronize do
return false unless @running
@running = false
@global_tracer&.disable
# Signal worker thread to stop
@event_queue << :stop
@worker_thread&.join(5) # Wait up to 5 seconds
@global_tracer = nil
@worker_thread = nil
true
end
end
private
def event_processor
thread_stats = Hash.new { |h, k| h[k] = Hash.new(0) }
while @running
begin
event = @event_queue.pop
break if event == :stop
# Process events in background thread
thread_id = event[:thread_id]
thread_stats[thread_id][event[:event]] += 1
# Periodic reporting to avoid memory buildup
if thread_stats.values.sum { |stats| stats.values.sum } % 1000 == 0
report_statistics(thread_stats)
thread_stats.clear
end
rescue StandardError => e
puts "Event processing error: #{e.message}"
end
end
report_statistics(thread_stats) unless thread_stats.empty?
end
def report_statistics(stats)
puts "Thread activity summary:"
stats.each do |thread_id, events|
total = events.values.sum
puts " Thread #{thread_id}: #{total} events (#{events})"
end
end
end
Thread-local tracing allows monitoring specific threads without affecting global performance. This approach enables focused debugging of concurrent issues while minimizing system-wide overhead.
# Thread-specific tracing utilities
module ThreadLocalTracing
def self.trace_current_thread(events, duration: nil)
current_thread = Thread.current
thread_tracer = TracePoint.new(*events) do |tp|
# Only trace events in the current thread
next unless Thread.current == current_thread
puts "[#{current_thread.name || current_thread.object_id}] #{tp.event}: #{tp.method_id}"
end
thread_tracer.enable
if duration
# Automatic timeout
Timer.new(duration) { thread_tracer.disable }
end
# Return tracer for manual control
thread_tracer
end
def self.trace_thread_lifecycle
TracePoint.new(:thread_begin, :thread_end) do |tp|
case tp.event
when :thread_begin
puts "Thread started: #{Thread.current.name || Thread.current.object_id}"
when :thread_end
puts "Thread ending: #{Thread.current.name || Thread.current.object_id}"
end
end.tap(&:enable)
end
class Timer
def initialize(duration, &block)
Thread.new do
sleep duration
block.call
end
end
end
end
Reference
TracePoint Class Methods
Method | Parameters | Returns | Description |
---|---|---|---|
TracePoint.new(*events, &block) |
events (Symbol Array), block (Proc) |
TracePoint |
Creates new trace object for specified events |
TracePoint.trace(*events, &block) |
events (Symbol Array), block (Proc) |
Object |
Creates and enables trace for block execution |
TracePoint Instance Methods
Method | Parameters | Returns | Description |
---|---|---|---|
#enable(&block) |
block (optional Proc) |
TracePoint |
Enables tracing globally or for block |
#disable |
None | TracePoint |
Disables active tracing |
#enabled? |
None | Boolean |
Returns current trace status |
#event |
None | Symbol |
Current event type |
#method_id |
None | Symbol |
Method name for call/return events |
#defined_class |
None | Class |
Class defining the traced method |
#path |
None | String |
Source file path |
#lineno |
None | Integer |
Source line number |
#binding |
None | Binding |
Execution context binding |
#self |
None | Object |
Current object context |
#return_value |
None | Object |
Return value for return events |
#raised_exception |
None | Exception |
Exception object for raise events |
Supported Event Types
Event | Triggered When | Available Methods |
---|---|---|
:call |
Ruby method called | method_id , defined_class , self , binding |
:return |
Ruby method returns | method_id , defined_class , self , return_value |
:c_call |
C extension method called | method_id , defined_class , self |
:c_return |
C extension method returns | method_id , defined_class , self , return_value |
:line |
Ruby line executed | binding , self |
:class |
Class/module definition begins | self |
:end |
Class/module definition ends | self |
:b_call |
Block called | binding , self |
:b_return |
Block returns | binding , self , return_value |
:raise |
Exception raised | raised_exception , self |
:rescue |
Exception rescued | raised_exception , self |
:thread_begin |
Thread starts | None |
:thread_end |
Thread ends | None |
Legacy Tracing Methods
Method | Parameters | Returns | Description |
---|---|---|---|
set_trace_func(proc) |
proc (Proc or nil) |
Proc |
Sets global trace function |
Kernel#trace_var(symbol, cmd) |
symbol (Symbol), cmd (Proc/String) |
nil |
Traces global variable changes |
Kernel#untrace_var(symbol, cmd) |
symbol (Symbol), cmd (optional) |
Array |
Removes variable trace |
Performance Characteristics
Operation | Relative Cost | Notes |
---|---|---|
No tracing | 1x | Baseline performance |
:call events |
2-5x | Method call overhead |
:line events |
10-50x | Very high frequency events |
:return events |
2-5x | Similar to call events |
Complex callbacks | 5-100x | Depends on callback logic |
Multiple active traces | Additive | Each trace adds overhead |
Common Event Combinations
Use Case | Recommended Events | Notes |
---|---|---|
Method profiling | :call , :return |
Measure execution time |
Exception debugging | :raise , :rescue |
Track error propagation |
Line-by-line debugging | :line |
Very high overhead |
Class loading | :class , :end |
Monitor definitions |
Block execution | :b_call , :b_return |
Trace block invocations |
Thread monitoring | :thread_begin , :thread_end |
Lifecycle tracking |
Full execution trace | All events | Maximum overhead |
Error Types
Error Class | Common Causes | Prevention |
---|---|---|
RuntimeError |
Accessing invalid trace methods | Check event type before access |
SystemStackError |
Recursive trace callbacks | Implement recursion detection |
NoMethodError |
Wrong method for event type | Use conditional method access |
ArgumentError |
Invalid event symbols | Validate events before creation |
ThreadError |
Concurrent trace operations | Implement thread synchronization |