00:00:07.600
y thank
00:00:08.840
you
00:00:10.480
well hello thank you for coming my name
00:00:14.679
is Dimitri pno I'm a team leader of Ruby
00:00:18.240
mind team in jet brains and today I will
00:00:21.640
talk about Ruby
00:00:23.480
debuggers we use rub bugers quite a lot
00:00:26.320
in our daily working process but pretty
00:00:28.840
few of us know how they work
00:00:31.320
internally in this talk I will cover
00:00:34.000
open source Ruby debuggers as well as
00:00:36.160
Ruby mind
00:00:37.840
debugger I've been working on Ruby mind
00:00:39.960
debugger for several years and also
00:00:42.520
investigated how open- Source Ruby
00:00:44.600
debuggers work today it's a chance for
00:00:47.719
me to share my experience and show you
00:00:50.000
main concept of Ruby just fix microphone
00:00:53.199
sorry Ruby debuggers thank
00:00:56.199
you um yep let's start
00:01:00.079
in this
00:01:01.000
talk I will answer five questions the
00:01:04.680
first one what tools do we have to find
00:01:07.479
bugs in rubby code then I will show you
00:01:11.080
what technologies do rubby buers use
00:01:14.320
after that we will see how do debuggers
00:01:17.680
work then I will show you which debugger
00:01:20.600
is the most performant and
00:01:23.720
finally uh we'll see how does the Ruby
00:01:26.759
mind debugger simplify debugging process
00:01:31.520
let's start from this first question
00:01:34.000
what tools do we have to find bus in
00:01:36.280
rubby
00:01:37.640
code and let's start from the simple
00:01:40.960
example here we have a method process
00:01:43.759
that takes one
00:01:45.399
argument and in this method we check
00:01:48.640
whether an argument has to string or
00:01:51.240
inspect
00:01:52.520
methods if it's true then we print
00:01:54.920
element is printable otherwise we print
00:01:57.640
element is not printable
00:02:01.079
and at the bottom we have two calls the
00:02:05.399
first is process of five that prin
00:02:08.119
element is printable and that is correct
00:02:10.840
because five has to string
00:02:13.280
method but the second call looks pretty
00:02:17.000
suspicious because process of basic
00:02:19.560
object wi's element is printable but in
00:02:22.920
fact basic object doesn't have to string
00:02:25.640
or inspect Methods at
00:02:27.800
all and apparently there is a bu
00:02:31.160
somewhere in this
00:02:32.760
code and I would like to ask you think
00:02:36.040
for a second and please raise your hand
00:02:38.920
if you know where the bu is in this
00:02:42.080
code don't worry I won't ask you about
00:02:47.920
that yeah yeah yeah well done yeah so
00:02:51.440
the real problem is here so this part
00:02:56.200
goes as an argument for defined method
00:02:59.480
and in that way method process prints
00:03:02.800
element is printable regardless of the
00:03:04.840
argument with any argument
00:03:08.239
possible we can fix this issue by adding
00:03:11.599
a couple of parentheses for the first
00:03:13.760
part of the if condition and after that
00:03:17.159
our output will be correct so now
00:03:20.400
process of basic object uh print element
00:03:23.440
is not
00:03:26.319
printable this was pretty basic example
00:03:29.840
is almost obvious bug but what tools
00:03:33.159
could we use to find real bugs in real
00:03:35.400
rubby
00:03:37.080
code the first thing that comes in mind
00:03:40.080
is putot
00:03:41.640
statement we can place several putot
00:03:44.159
statements to their suspicious place and
00:03:47.120
they will give us some hints about where
00:03:49.799
the problem is or what we need to do
00:03:52.920
next and also in the same way we can use
00:03:56.360
FS debugger gem that makes our out put
00:04:00.840
distinguishable between each
00:04:03.079
other and also you could use awesome
00:04:05.680
Prim Gems or similar ones just to make
00:04:07.920
our output more structured and easy to
00:04:12.079
read uh puts really great but they are
00:04:17.160
pretty basic we need something more
00:04:20.840
advanced and we have this tool we have
00:04:24.320
interactive console basically in Ruby we
00:04:27.479
have I and pry consoles
00:04:30.759
usually we need to place a special call
00:04:33.000
in our source code to make it work and
00:04:36.000
after that we will be able to introspect
00:04:38.199
their current context we will be able to
00:04:40.320
modify it and even evaluate some
00:04:43.960
Expressions but interactive consults has
00:04:48.520
one problem the lack of one important
00:04:51.320
feature and this feature is execution
00:04:54.039
control basically a stepping
00:04:58.280
feature and next tool
00:05:01.280
debuggers and rby debugger has all
00:05:03.800
necessary tools to find bugs in rubby
00:05:06.160
code and this is a most advanced tool
00:05:08.840
that we have in Ruby
00:05:11.400
world before we start with debuggers
00:05:14.759
let's think uh how often do developers
00:05:18.440
use a
00:05:21.319
debugger and the answer is here so every
00:05:25.280
thir run is a debak run basically 30 4%
00:05:30.639
of all runs are debug runs and this fact
00:05:34.280
is based on the anonymous studs from
00:05:36.600
Ruby mine version 202
00:05:39.400
24.2 and this fact means that debugging
00:05:43.840
process is a crucial part in our working
00:05:47.360
process we need to strive to make it
00:05:49.600
even better to make our to increase our
00:05:54.080
productivity and to get things done with
00:05:56.280
less
00:05:57.160
resources so that's why I'm here talking
00:05:59.919
about
00:06:02.400
debuggers let's move to the next
00:06:04.440
question and let me show you what
00:06:06.759
technologies dobers
00:06:09.599
use the first one is a trace Point Trace
00:06:14.240
point was introduced in Ruby 2.0 and it
00:06:17.080
mainly provides an ability to execute
00:06:19.599
some specific code on a certain event in
00:06:22.319
your code so it's basically provided a
00:06:26.000
way to trace your
00:06:27.639
code and Trace point1 works almost
00:06:30.280
everywhere it works in Threads it works
00:06:32.720
in fibers but it doesn't work in RoR yet
00:06:37.199
unfortunately hopefully it will be there
00:06:40.199
but unfortunately not
00:06:43.520
yet and let me show you an example how T
00:06:46.919
Point
00:06:48.160
Works uh here we have a method say hello
00:06:51.599
with a boots statement hello eura
00:06:55.720
2024 and also we have a trace point that
00:06:58.879
is targeted to call events in this Trace
00:07:02.400
point we have another good
00:07:04.520
statement and at the bottom we have a
00:07:07.199
call of our method and in commence we
00:07:10.879
have our output so first we have a
00:07:14.080
message from our Trace point and only
00:07:16.240
after that we have a message from our
00:07:18.520
method
00:07:19.560
itself and in this way Trace Point
00:07:22.400
traced our call by placing a additional
00:07:28.080
message having only Trace point we can
00:07:31.199
build a probably simplest possible
00:07:34.479
debugger the main difference from the
00:07:37.039
previous example is here
00:07:40.639
so this code in this code we take an
00:07:44.639
input from the user and we try to
00:07:46.919
evaluate it and print to the
00:07:49.599
console in that way we will be able to
00:07:52.199
introspect the context on each call
00:07:54.720
event so basically on each method
00:07:57.560
invocation and that's probably simplest
00:08:00.840
possible debug that we can ever create
00:08:04.120
and that's why Trace point is a crucial
00:08:07.039
part because without it it's not
00:08:09.000
possible to make it like
00:08:12.240
that let's move to the next uh
00:08:15.280
technology it is a ruby virtual machine
00:08:18.319
instruction
00:08:20.039
sequence instruction sequence is a
00:08:23.199
representation of compiled by code for a
00:08:25.520
ruby virtual
00:08:26.759
machine it depends on the Ruby version
00:08:29.720
because it's tightly related to virtual
00:08:31.960
machine
00:08:33.039
internals and it mainly provides an
00:08:35.800
access to lowlevel representation of
00:08:37.680
your rubby code with that technology you
00:08:41.320
can modify the bite code and adjust the
00:08:43.680
behavior of your program without
00:08:45.880
touching the source code of your
00:08:48.760
program let me show you an
00:08:51.920
example here we have the same method say
00:08:55.680
hello and then we take a method object
00:08:59.920
of this method and then we pass that
00:09:02.560
method object to instruction sequence at
00:09:05.279
the end we just PR our instruction
00:09:07.399
sequence to the console in some readable
00:09:09.959
way so let's take a look at the
00:09:14.720
output here it
00:09:16.800
is here we have several lines each line
00:09:20.800
is a separate
00:09:23.160
instruction also we have uh our argument
00:09:27.959
and we can read it right here without
00:09:30.399
any encoding or decoding problems it's
00:09:34.079
great and here is another
00:09:36.800
Point these marks and these marks show
00:09:40.279
events that will be emitted at the run
00:09:43.000
time uh pure Li stands for line event ca
00:09:47.200
for call event and re for return event
00:09:51.720
and in this way instru sequence
00:09:54.560
collaborates with the trace point
00:09:56.600
because Trace Point Targets on this
00:10:01.959
events that's basically about
00:10:04.560
Technologies for Ruby debuggers and
00:10:08.240
let's move to the next question how do
00:10:10.680
debuggers
00:10:13.320
work first I would like to start with
00:10:15.959
bubug debugger it's pretty well known it
00:10:19.480
provides all necessary features like
00:10:21.760
break points stepping and context
00:10:24.279
introspection it's default de buer for
00:10:26.640
old Ruby versions and old ra versions
00:10:30.320
also it requires modification to your
00:10:32.440
source code to make it work usually we
00:10:35.000
need to place a requir statement and I
00:10:37.480
call to make it work and additionally
00:10:41.600
this debugger provides common line
00:10:43.839
interface by default and there are
00:10:46.519
several PS code plugins to make it
00:10:50.279
work but how does buback
00:10:54.320
work let's figure
00:10:57.079
out here is a simple model of bubug
00:11:01.200
debugger all these code should be
00:11:03.639
invoked before the actual rubby
00:11:05.480
application that we are going to
00:11:07.320
debug and here on top we have two lists
00:11:11.920
the first list of breakpoints that
00:11:14.000
contains break points from the user and
00:11:17.279
the second list is list of Trace point
00:11:20.279
that contains uh one Trace Point per
00:11:23.600
each event type for example one Trace
00:11:27.279
point for line events one Trace point
00:11:29.560
for call events and so
00:11:31.519
on in each Trace point we have basically
00:11:34.720
the same
00:11:36.079
method uh in each Trace point we try to
00:11:39.920
find our break point at the certain
00:11:42.320
place if we find it then we move the
00:11:46.560
control to the user otherwise we just
00:11:49.440
continue our execution without any
00:11:51.760
additional
00:11:52.880
actions and that's fundamentally how it
00:11:56.800
works but this approach has one issue
00:12:00.839
and this issue is
00:12:03.160
performance the problem is that we do a
00:12:06.480
lot of checks to find our break point on
00:12:09.160
each event and that makes our code more
00:12:12.519
than 20 times slower than original run
00:12:15.680
without any
00:12:17.399
debugger this is a main disadvantage of
00:12:19.839
buyback debugger mainly because it's
00:12:22.360
could be hard to debug some complicated
00:12:24.839
Ruby or rails application uh with that
00:12:27.920
debugger
00:12:30.839
but next debugger debug gem solved this
00:12:35.399
problem but before we start with debug
00:12:37.920
gem um let the main feature that solved
00:12:41.839
this problem for debug
00:12:43.800
Gem and this feature is Trace Point
00:12:47.600
improvements Trace Point improvements
00:12:49.760
were introduced in Ruby 2.6 and it
00:12:52.680
mainly provides an ability to specify
00:12:55.519
Target line or I SEC for a trace point
00:12:59.639
with that Improvement you don't need to
00:13:02.680
do a lot of checks to find your break
00:13:04.600
point you can create your Trace point
00:13:06.959
and Target this Trace point to a certain
00:13:09.199
place where you have a break point for
00:13:12.839
sure and this approach works great
00:13:15.760
without any performance
00:13:17.680
issues let me show you an example how
00:13:20.560
this
00:13:22.320
works here we have uh two
00:13:25.959
methods say hello and Say Goodbye also
00:13:29.519
we have the same Trace Point as before
00:13:32.720
without any changes and the main point
00:13:35.720
is here here we target our Trace point
00:13:39.279
to the is SEC of the first
00:13:42.040
method and at the bottom we can see our
00:13:45.600
output so our Trace point was triggered
00:13:49.920
only once for the first method and was
00:13:52.399
ignored for the second one that's how it
00:13:56.399
works debug gem use set up approach uh
00:14:00.800
to solve performance issue and in fact
00:14:03.480
debug gem doesn't have any performance
00:14:05.600
issue which is
00:14:07.279
great also this debugger supports 3 2.7
00:14:11.600
and greater mainly because three point
00:14:14.079
wasn't ported to the previous
00:14:17.000
versions apart of that uh this debugger
00:14:20.279
supports several front ends like vort or
00:14:23.680
Chrome and finally this debugger bundle
00:14:27.399
in Ruby mine version .1 and
00:14:30.240
greater H and in fact this is a default
00:14:34.000
option for debugging your code for the
00:14:35.759
modern
00:14:36.839
Ruby especially if you don't have any
00:14:39.199
other
00:14:40.839
tools set it about debug Gem and let me
00:14:44.480
show you Ruby mine
00:14:48.519
debugger Ruby mine debugger is buled in
00:14:51.240
Ruby mine IDE with graphical user
00:14:53.360
interface by
00:14:54.839
default it provides seamless debugging
00:14:57.680
experience with this debugger you don't
00:15:00.279
need to modify your source code you
00:15:02.800
don't need to deal with some terminal
00:15:04.440
commands you don't need to configure
00:15:07.120
something it works out of the
00:15:09.920
box apart of that please deide your
00:15:12.519
supports rby 2.3 and greater so almost
00:15:15.680
all ruby versions that your application
00:15:18.079
could
00:15:18.880
use and with all these versions uh this
00:15:22.639
debugger doesn't have any performance
00:15:24.600
issues that's one of the main features
00:15:29.560
uh apart of that this debugger also has
00:15:32.600
an ability to attach to any Ruby process
00:15:35.560
so with this debugger you don't need to
00:15:37.759
start the debuger right from the start
00:15:39.920
you can attach it when really
00:15:44.240
needed but how is the pro mind debugger
00:15:50.440
structured here is the architecture of
00:15:53.639
Ruby mind debugger it contains three
00:15:56.959
components the first component is the
00:15:59.480
Bas Gem and it's mainly responsible for
00:16:02.639
lowlevel SC like ISC or frames
00:16:06.279
retrieving Trace Point creation and so
00:16:09.519
on the next component is prb ID gem this
00:16:14.440
component is main responsible for text
00:16:17.480
presentation of Ruby versions or of Ruby
00:16:20.079
values and for connection between Ruby
00:16:22.399
mine ID and
00:16:23.759
debugger and finally Ruby mine ID itself
00:16:29.160
this component is made responsible for
00:16:31.560
graphical user interface and user
00:16:35.560
experience generally architecture looks
00:16:38.399
like this but the real architecture is a
00:16:42.040
bit more
00:16:43.360
complicated instead of one uh branch of
00:16:47.040
gems we have two branches and the first
00:16:50.399
branch is targeted to all TR be it
00:16:53.440
contains a lot of lowlevel hacks to make
00:16:55.920
it
00:16:56.839
performant and it's really hard to
00:16:58.959
support and
00:17:00.319
maintain that's why we have second
00:17:03.040
Branch with uh that is targeted to
00:17:06.439
Modern Ruby it uses new Ruby
00:17:10.559
API it's much maintainable and it's easy
00:17:13.959
to add new features here that's why we
00:17:16.799
have two branches and this approach uh
00:17:20.199
makes our debugger maintainable and
00:17:24.360
manageable another aspect of Ruby mind
00:17:26.839
debugger is a question how how does
00:17:29.600
rubby mind connect to the
00:17:33.280
debugger suppose we need to debug multi
00:17:36.880
process Ruby application and this Ruby
00:17:40.080
application has two processes the main
00:17:43.240
process and child
00:17:45.000
process first uh PR mind starts the main
00:17:48.400
process and after that it connects using
00:17:51.600
default port to the main
00:17:53.760
process suppose after that main process
00:17:57.159
creates its child process and at this
00:17:59.840
point R needs to connect the child
00:18:02.400
process
00:18:03.640
too to achieve that uh child process
00:18:07.120
send a message with a new connection all
00:18:10.320
the way back to Ruby
00:18:11.880
mind and after that Ruby mind uses this
00:18:16.760
port to connect to the child
00:18:19.280
process and generally it works like R
00:18:23.000
mind connects to debugger not the vice
00:18:26.480
versa this approach works great in
00:18:29.120
almost all cases but there is one small
00:18:33.840
issues and the issue is related to doer
00:18:37.120
container environment because in doer
00:18:39.919
container we need to open all necessary
00:18:42.280
ports in advance but unfortunately we
00:18:45.679
can't predict how many ports arbitary
00:18:48.120
Ruby application will use and this is
00:18:51.640
the main
00:18:53.080
problem we solved that issue by opening
00:18:56.559
large number of ports in advance just to
00:18:59.360
provide a way for debugging almost any
00:19:03.600
Ruby application with do container but
00:19:07.159
this solution is not very elegant and
00:19:09.120
probably in future we can make even
00:19:12.480
better so that's my NE about how Ruby
00:19:16.000
debuggers work and let's see which
00:19:19.360
debugger is the most
00:19:22.640
performant to figure this out I created
00:19:26.720
simple experiment I I used Fibonacci
00:19:30.039
method and in this method I placed a
00:19:33.320
break point whenever hit this break
00:19:36.400
point and I need this break point just
00:19:39.440
to measure how a break point can affect
00:19:42.039
a debugger
00:19:44.000
performance also in this experiment I
00:19:46.840
use average uh metric of 100 R just to
00:19:51.880
make the results stable and
00:19:55.840
reproducible um in this experiment I
00:19:59.200
used all described versions and they
00:20:02.240
like all described debuggers and their
00:20:04.120
latest versions and for Ruby mine we
00:20:06.840
have two packs of gems the one pack was
00:20:10.200
for modern Ruby and another one for the
00:20:13.080
old
00:20:14.600
Ruby so let's take a look at the
00:20:18.520
results here they
00:20:20.720
are first I would like to highlight that
00:20:24.240
buyback gem really slow with old R it's
00:20:28.159
more than 20 times slower than original
00:20:30.440
run without any
00:20:32.000
debugger at the same turn Ruby mind
00:20:34.840
debugger Works fast without any
00:20:37.080
performance
00:20:38.320
issues and in fact Ruby mind debugger is
00:20:41.799
the only option to debug your code with
00:20:44.039
all trby without any performance issues
00:20:47.480
that's not really great because we don't
00:20:49.360
have different options to choose but
00:20:52.559
this what we have
00:20:54.440
here for the mod Ruby we have better
00:20:57.760
case they have debug Gem and rby mind
00:21:00.400
debugger they are both works on the same
00:21:03.559
level without any performance issue and
00:21:06.559
for the mod Ruby we have an option to
00:21:09.039
choose what we can use for each
00:21:13.039
case set main it about debugger
00:21:16.080
performance and let's move to the last
00:21:19.400
question how does rub debugger
00:21:22.240
simplified debuging
00:21:24.240
process generally Ruby mind debuger has
00:21:27.360
a lot of great features that could
00:21:29.080
streamline your debugging process but I
00:21:31.760
would like to highlight just a couple of
00:21:33.799
them and the first one is debug rails
00:21:37.400
application in one
00:21:39.679
click suppose we need to debug rails
00:21:43.840
application and this ra application
00:21:46.440
based on the uh Puma server here we can
00:21:51.200
see Puma config file and here we have
00:21:55.080
five threads and two workers it means
00:21:57.880
that our r application is multiprocess
00:22:02.039
application and suppose we need to debug
00:22:04.919
it uh let's say we need to debug method
00:22:07.880
home in our
00:22:09.360
controller and first we need to place a
00:22:12.640
breakpoint by one click on the
00:22:15.640
gapter and all we need after that is
00:22:19.120
just to click on the debug button and
00:22:21.400
that's it we don't need to modify our
00:22:24.400
source code we don't need to configure
00:22:26.320
something it works out of the box
00:22:28.200
without any additional
00:22:30.520
actions after that debugger process will
00:22:33.600
start and we will be able to hit our
00:22:35.640
break
00:22:36.679
points and this view we will see when we
00:22:39.880
hit a break point here we have a list of
00:22:44.240
frames special panel with variables and
00:22:47.600
values
00:22:49.919
and interactive console and other uh
00:22:53.279
important things for debugging process
00:22:58.559
that's main it about this
00:23:00.400
feature another feature is inline
00:23:03.159
divider
00:23:04.279
values suppose we have a method and it's
00:23:09.559
filter array it contains it takes two
00:23:12.520
arguments the first argument is list of
00:23:14.960
numbers the second argument is just a
00:23:17.440
number and for some reason we need to
00:23:20.360
debug this method so we have a break
00:23:23.679
point on the line
00:23:25.159
four suppose we start our debugger and
00:23:28.039
stop on the breakpoint and this view we
00:23:31.039
will
00:23:33.440
see um here we have a panel with
00:23:36.720
variables and their values and usually
00:23:39.799
in debugging process we need to match
00:23:42.440
variables in our editor with values in
00:23:45.600
with in this special panel so we need to
00:23:48.559
go back and forth to make this map in
00:23:50.520
our mind and it takes a lot of Mind
00:23:53.600
resources to keep it in mind and keep it
00:23:56.960
consistent um provides simpler solution
00:24:00.200
for this and rubby mind provides these
00:24:04.200
annotations WR in the editor they show
00:24:07.960
variables and their values right in the
00:24:10.240
editor near the place where you use
00:24:13.880
variable and uh this feature can
00:24:18.279
streamline your debugging process and
00:24:20.279
save your mind resources that's great I
00:24:23.840
guess that's it so let's move to the key
00:24:27.320
points
00:24:28.840
first I would like to highlight that
00:24:30.880
Ruby debuggers use Trace point and
00:24:33.679
instruction
00:24:35.000
sequence also I would like to emphasize
00:24:38.000
that debuger debug gem Works fast due to
00:24:41.279
trace Point
00:24:42.520
improvements and finally Ruby mind
00:24:45.080
debugger it works fast with all
00:24:48.159
supported Ruby versions it enables one
00:24:51.559
click debugging process for rail for
00:24:54.440
rails application and basically for Ruby
00:24:56.440
application too
00:24:58.600
and it provides in led by your values to
00:25:00.840
help you Deb back with pleasure that's
00:25:03.600
it thank
00:25:14.799
you lastly I would like to ask you take
00:25:17.919
your phones and scan this C code please
00:25:20.960
share your feedback about and rby minder
00:25:24.080
with me on LinkedIn it will be pleasure
00:25:26.440
to see your feedback together we can can
00:25:28.520
make our rubby tools even better thank
00:25:31.640
you
