Intro to Trace Inspector that displays Ruby trace logs with pretty UI

ono-max

Naoto Ono

Posted on May 24, 2023

Intro to Trace Inspector that displays Ruby trace logs with pretty UI

Trace Inspector, a tool that displays Ruby trace logs with pretty UI while debugging in VS Code, has recently landed in debug.gem. debug.gem is a Ruby standard debugger library and the default debugger in Rails. Since debug.gem supports VS Code, you can debug Ruby programs in vscode-rdbg.

What is unique about Trace Inspector compared to existing tracing tools is its cool UI. Trace Inspector give you the following benefits:

  • Intuitive viewing of the trace logs.
  • Check parameters and a return value for the trace log on the editor.
  • Record the backtrace and local variables if necessary.

Trace Inspector helps you to read complex code.

Use cases for Trace Inspector

We envisage two use cases:

  • Code reading to get a rough idea of the process
  • Tracking detailed behaivor during debugging

In other words, Trace Inspector is useful for code reading with a debugger. You may feel that code reading with a debugger is helpful, reading complex code is still hard. The difficulty of reading complex code with a debugger is that we have to remember all the different kinds of information at the points where we have paused until now. However, it's almost impossible. We may forget which method was called at a previous stopping point. Also, we may forget the method's parameters or a return value. This is a problem of code reading with a debugger.

To solve the problem, we can use Trace Inspector. If we use Trace Inspector, we don't have to remember all the different kinds of information. We can check the information anytime. Also, we can copy the parameters and return values by clicking the target log.

Comparison with existing tracing tools

There are some existing tools for tracing programs in Ruby. For example, ruby/tracer is one of the famous tracing tools. Also, debug.gem already had a feature for tracing programs in the terminal. One of the characteristics of the existing tools is that the terminal is used as a front-end. Although the terminal is helpful, we thought we could provide richer user experiences by using VS Code from the following advantages.

The first advantage is the way of displaying trace logs. The following are examples of tracing a program with debug.gem in the terminal and tracing a program with Trace Inspector. The white bordered area is a single trace log. If we use Trace Inspector, we can see only what we want to see by clicking. In this picture, the trace logs in target.rb:5 are collapsed. We can say "I'm not interested in the trace logs here, so let's just collapse it".

Example of tracing a program in the terminal
Tracing a program with debug.gem in the terminal
Example of tracing a program with Trace Inspector
Tracing a program with Trace Inspector

The second advantage is that trace logs can be viewed on the editor. If we click the specified log, the target file is opened, and the line is highlighted on the editor. Also, parameters and return values are displayed there.

a trace log on the editor

How to use Trace Inspector

How to start Trace Inspector

  1. Set a breakpoint where it says, "puts set a breakpoint here" in the code. Example of setting breakpoints
  2. Start debugging. Example of button for starting debugging
  3. Click "TRACE INSPECTOR" view in the Sidebar to open it. Example of closed "TRACE INSPECTOR" view
  4. Click "Enable Trace" button in "TRACE INSPECTOR" view. Example of "Enable Trace" button
  5. Click "Continue" in debug toolbar to resume the program. Example of "Continue" button
  6. The trace log appears in "TRACE INSPECTOR" view. Example of displaying trace logs

Congratulations! You were able to trace the log with Trace Inspector!

Diving into trace logs

Trace logs are arranged in the order in which they are executed. For example, target.rb:9 was executed before target.rb:10 in this case.

Example of trace logs

There are several kinds of icons in trace logs, as follows:

Line trace Log

An icon such as a location icon is a Line trace log. It traces which line is executed. If you click the Line Trace log, the target file is opened, and the line is highlighted.

Line trace log

Call trace log

A right arrow icon is the Call trace log. It traces which method is called. If you click the Call trace log, parameters are displayed on the editor in addition to the highlighting lines.

Call trace log

Return trace log

A left arrow icon is the Line trace log. It traces which method is returned. If you click the Call trace log, a return value is displayed on the editor in addition to the highlighting lines.

Return trace log

Recording mode

If we use Recording mode, we can record local variables and backtraces. Local variables and backtraces at the point of execution can be checked. For example, we can see how local variable A is assigned. The step to use this option is almost the same as described above. You need to click "•••" (more icon), then put a checkmark of "Record And Replay (Slow)" before clicking the "Enable Trace" button.

  1. Set a breakpoint where it says, "puts set a breakpoint here" in the code. Example of setting breakpoints
  2. Start debugging. Example of button for starting debugging
  3. Click "TRACE INSPECTOR" view in the Sidebar to open it. Example of closed "TRACE INSPECTOR" view
  4. Click "•••" (more icon), then put a checkmark of "Record And Replay (Slow)" Example of context menu
  5. Click "Enable Trace" button in "TRACE INSPECTOR" view. Example of "Enable Trace" button
  6. Click "Continue" in debug toolbar to resume the program. Example of "Continue" button
  7. The trace log appears in "TRACE INSPECTOR" view. Example of displaying trace logs

Options for tracing

"Trace Line" and "Trace Call/Return" is enabled in the default. The lower the table you go, the more log kinds you take.

Location Method name & Params Return Value Backtraces Local variables
Trace Line (Default) N/A N/A
Trace Call/Return (Default)
Record And Replay

Some tips

Tracing only matched events that match specified regular expressions

You can trace only the events that you want.

  1. Click "Apply filter by Regexp" Example of context menu in Trace Inspector
  2. Enter any string. (Also, you can filter by file path such as "target.rb") Example of entering string

Copying a trace log

You can copy trace logs as JSON objects.

  1. Right-click a log that you want to copy.
  2. Click "Copy Trace log"

Example of right-clicking a trace log

Here is an example of JSON objects.

{
  "method": "Object#bar",
  "location": { "path": "/Users/s15236/workspace/debug/target.rb", "line": 4 },
  "parameters": [
    { "name": "c", "value": "10" },
    { "name": "d", "value": "20" }
  ]
}
Enter fullscreen mode Exit fullscreen mode

Checking the process flow in frame-by-frame

By clicking the arrow, you can check the process flow in frame-by-frame. The down arrow goes to the next log such as "Step Into". The up arrow goes to the previous log such as "Step Back".

Example of arrows in the navigation bar

Configuring the maximum size of trace logs that a debugger will save

In the default, the maximum size of trace log stored by a debugger is 50000. If the size of trace logs exceeds the maximum size, the excess is removed from the oldest of the existing logs, and the new logs are inserted. You can change the setting as follows:

Example of Configuring the maximum size

Performance comparison for each option

Execution time always depends on the program. Thus, what we should focus is how much slower it is compared to normal. We can use Trace Line without worrying about anything since Trace Line is only 17 times slower than Normal run. We may feel a little slow when using Trace Call because Trace Call is only 203 times slower than Normal run. We need to accept that it will be a slow execution before starting Record And Replay. However, we plan to improve the perfomance for Record And Replay.

Execution Time(s) Ratio to Normal run
Normal run (Without tracing) 0.107 1.0
Trace Line 1.886 17.6
Trace Call/Return 21.729 203.1
Record And Replay 1,102.955 10,308.0

Here is a script for measuring performance. This script is the part of Rails application.

def index
  binding.break # <- Start a program here
  10_000.times {
    respond_to do |format|
      format.html # index.html.erb
    end
  }
end #<- Pause a program here
Enter fullscreen mode Exit fullscreen mode
  • ruby 3.2.1 (2023-02-08 revision 31819e82c8) [arm64-darwin21]
  • MacBook Pro (16-inch, 2021)
  • Chip: Apple M1 Max
  • Memory: 32 GB

Conclusion

I hope that you enjoy tracing Ruby programs with Trace Inspctor. Also, we look forward to your feedbacks!

Acknowlegement

Special thanks to Koichi Sasada-san. He helped me to design Trace Inspector!

💖 💪 🙅 🚩
ono-max
Naoto Ono

Posted on May 24, 2023

Join Our Newsletter. No Spam, Only the good stuff.

Sign up to receive the latest update from our blog.

Related

What was your win this week?
weeklyretro What was your win this week?

November 29, 2024

Where GitOps Meets ClickOps
devops Where GitOps Meets ClickOps

November 29, 2024

How to Use KitOps with MLflow
beginners How to Use KitOps with MLflow

November 29, 2024

Modern C++ for LeetCode 🧑‍💻🚀
leetcode Modern C++ for LeetCode 🧑‍💻🚀

November 29, 2024