`next` stops in the wrong place when blocks are called

[marianosimone]

Your environment

• ruby -v: 2.7.2p137
• rdbg -v: 1.6.2

To Reproduce
For a simple case:

1. Create a file like:

def with_block
 yield
end
 
with_block do
 1
end
puts("`next` should stop here")

2. Add a breakpoint in line 5
3. Try to move to next
4. See the debugger stop at line 6 (and then 7, and 3)

For more complex cases:

1. Create a file like:

class Bar
 define_method("dynamic") do
 true
 end

 def regular; false; end
end

def foo(a, b, c); end

bar = Bar.new
foo(
 bar.regular,
 bar.dynamic, # `next` stops here
 bar.regular
)
puts("`next` should stop here")

2. Add a breakpoint in line 12 (where the call to foo is)
3. Try to move to next
4. See the debugger stop at line 14

Expected behavior
The debugger should stop at line 8 in the simple example, and 17 in the complex one

Additional context
I included non-dynamically-defined methods, to show that next only behaves incorrectly for the dynamically-defined ones (as it doesn't stop at line 13 nor 15)

[marianosimone]

Here's a protocol test that should pass when the issue is fixed:

# frozen_string_literal: true

require_relative '../support/protocol_test_case'

module DEBUGGER__
 class NextDynamicMethodTest < ProtocolTestCase
 PROGRAM = <<~RUBY
 1| class Bar
 2| define_method("dynamic") do
 3| "dynamic"
 4| end
 5| 
 6| def regular
 7| "regular"
 8| end
 9| end
 10| 
 11| def foo(a, b, c); end
 12| 
 13| bar = Bar.new
 14| foo(
 15| bar.regular,
 16| bar.dynamic,
 17| bar.regular
 18| )
 19| bar
 RUBY

 def test_next_goes_to_the_next_statement
 run_protocol_scenario PROGRAM do
 req_next
 assert_line_num 2

 assert_locals_result(
 [
 { name: "%self", value: "Bar", type: "Class" },
 ]
 )
 req_next
 assert_line_num 6

 assert_locals_result(
 [
 { name: "%self", value: "Bar", type: "Class" },
 ]
 )
 req_next
 assert_line_num 11

 assert_locals_result(
 [
 { name: "%self", value: "main", type: "Object" },
 { name: "bar", value: "nil", type: "NilClass" }
 ]
 )
 req_next
 assert_line_num 13

 assert_locals_result(
 [
 { name: "%self", value: "main", type: "Object" },
 { name: "bar", value: "nil", type: "NilClass" }
 ]
 )

 req_next
 assert_line_num 14

 assert_locals_result(
 [
 { name: "%self", value: "main", type: "Object" },
 { name: "bar", value: /#<Bar/, type: "Bar" }
 ]
 )

 req_next
 assert_line_num 19

 assert_locals_result(
 [
 { name: "%self", value: "main", type: "Object" },
 { name: "bar", value: /#<Bar/, type: "Bar" }
 ]
 )
 req_terminate_debuggee
 end
 end
 end
end

[marianosimone]

cc @WillHalto. Just a heads up that #743 doesn't seem to make this worse, but given that you are already there and have some context, you might find it interesting.

[st0012]

A small tip: you can write the reproduction steps down like:

debugger(do: "b 6 ;; c ;; n ;; n ;; n")

def with_block
 yield
end

with_block do
 1
end

puts("`next` should stop here")

In this case, we only need to run

$ rdbg -n target.rb

And the reproduction steps can be executed automatically.

If you don't want to modify the script directly, you can achieve it with rdbg -e too:

def with_block
 yield
end

with_block do
 1
end

puts("`next` should stop here")

$ rdbg -e "b 5 ;; c ;; n ;; n ;; n" target.rb

[st0012]

After some investigation, I think the simple and complicated examples have different causes.

I can't really tell the cause of the simple case yet. But for the complicated example, I think it's caused by a bug in older Ruby versions.

Example

TracePoint.new(:b_return, :return) do |tp|
 puts [tp.event, caller_locations(1, 1).first].to_s
end.enable

class Bar
 define_method("dynamic") do
 true
 end # line 8
end

Bar.new.dynamic # line 11

If you execute this script with Ruby < 3.1, you'll get

❯ ruby test.rb
[:b_return, "test.rb:8:in `block in <class:Bar>'"]
[:return, "test.rb:11:in `<main>'"]

And you can see that b_return and return events' line numbers don't match. Ideally, they should both be 8.

However, if you run it with Ruby 3.1, they do match

❯ ruby test.rb
[:b_return, "test.rb:8:in `block in <class:Bar>'"]
[:return, "test.rb:8:in `block in <class:Bar>'"]

If you run the complicated case with Ruby 3.1, it actually works as expected:

❯ exe/rdbg -e "b 12 ;; c ;; n ;; n ;; n" target.rb
[1, 10] in target.rb
=> 1| class Bar
 2| define_method("dynamic") do
 3| true
 4| end
 5|
 6| def regular; false; end
 7| end
 8|
 9| def foo(a, b, c); end
 10|
=>#0 <main> at target.rb:1
(rdbg:commands) b 12
#0 BP - Line /Users/st0012/projects/debug/target.rb:12 (line)
(rdbg:commands) c
[7, 16] in target.rb
 7| end
 8|
 9| def foo(a, b, c); end
 10|
 11| bar = Bar.new
=> 12| foo(
 13| bar.regular,
 14| bar.dynamic, # `next` stops here
 15| bar.regular
 16| )
=>#0 <main> at target.rb:12

Stop by #0 BP - Line /Users/st0012/projects/debug/target.rb:12 (line)
(rdbg:commands) n
[12, 17] in target.rb
 12| foo(
 13| bar.regular,
 14| bar.dynamic, # `next` stops here
 15| bar.regular
 16| )
=> 17| puts("`next` should stop here")
=>#0 <main> at target.rb:17
(rdbg:commands) n
`next` should stop here

So I think it's more like a bug in older Ruby versions, but we may workaround it in debug.

[ko1]

It solved on Ruby 3.1.0 and later.
I agree it is an issue, but not so big problem I think so I left it.
Please reopen it if it is so important issue.

[marianosimone]

I don't know what your policy is in supporting Ruby < 3.1.0... but, as it is, with this issue and #760, the debugger has a really poor experience.

Given that we still have 6 months until the end of life of Ruby 2.6 (and no date for 2.7), I'd argue for at least keeping this open, and try to fix it.

[st0012]

Last time I tested, the simple case's issue also happened with Ruby 3.1+ so it needs more investigation.

❯ ruby -v
ruby 3.1.2p20 (2022-04-12 revision 4491bb740a) [x86_64-darwin21]

❯ be exe/rdbg target.rb
[1, 8] in target.rb
=> 1| def with_block
 2| yield
 3| end
 4|
 5| with_block do
 6| 1
 7| end
 8| puts("`next` should stop here")
=>#0 <main> at target.rb:1
(rdbg) b 5 # break command
#0 BP - Line /Users/st0012/projects/debug/target.rb:5 (line)
(rdbg) c # continue command
[1, 8] in target.rb
 1| def with_block
 2| yield
 3| end
 4|
=> 5| with_block do
 6| 1
 7| end
 8| puts("`next` should stop here")
=>#0 <main> at target.rb:5

Stop by #0 BP - Line /Users/st0012/projects/debug/target.rb:5 (line)
(rdbg) n # next command
[1, 8] in target.rb
 1| def with_block
 2| yield
 3| end
 4|
 5| with_block do
=> 6| 1
 7| end
 8| puts("`next` should stop here")
=>#0 block in <main> at target.rb:6
 #1 Object#with_block at target.rb:2
 # and 1 frames (use `bt' command for all frames)
(rdbg) n # next command
[2, 8] in target.rb
 2| yield
 3| end
 4|
 5| with_block do
 6| 1
=> 7| end
 8| puts("`next` should stop here")
=>#0 block in <main> at target.rb:7 #=> 1
 #1 Object#with_block at target.rb:2
 # and 1 frames (use `bt' command for all frames)

<===== Ideally this step shouldn't happen =====>

(rdbg) n # next command 
[1, 8] in target.rb
 1| def with_block
 2| yield
=> 3| end
 4|
 5| with_block do
 6| 1
 7| end
 8| puts("`next` should stop here")
=>#0 Object#with_block at target.rb:3 #=> 1
 #1 <main> at target.rb:5
(rdbg) n # next command
[3, 8] in target.rb
 3| end
 4|
 5| with_block do
 6| 1
 7| end
=> 8| puts("`next` should stop here")
=>#0 <main> at target.rb:8
(rdbg) n # next command
`next` should stop here

So based on that I think we should keep this issue opened until we're clear on both cases' causes.

[marianosimone]

It's also worth mentioning that, for anyone using Sorbet, trying to step with next always requires two steps. This is because Sorbet signatures are essentially wrapping methods in a block. Take the following example:

sig {returns(T::Boolean)}
def does_it_work?
 false
end

value = does_it_work?
puts("Does it work? #{value}")

Trying to step over 6 requires two next

[ko1]

I think additional next is not big problem but you think it is a big problem?

[marianosimone]

There are actually 2 problems (as identified by @st0012 above):

1. Extra steps when a block is involved (as in Sorbet). This might not seem like much, but if you are debugging a codebase where everything has a signature, it's essentially 2 nexts for each line you want to step over
2. next going to the wrong place

They are definitely a very bad experience when debugging anything but a trivial codebase

[ko1]

I understand the issue.

def iter
 yield
end # (iter/end)

iter do
 1
end # (*) Now stopping here

puts("`next` should stop here") # (putline)

• For a person who think the block is function, the next line of (*) should be (iter/end). They have interest how iter is implemented.
• For a person who think the block is a loop (or code block) of caller context (top on this case), the next line should be (putline). They don't have interest how iter is implemented.

Options:

1. next should ignore the iter internal and jump to (putline) (maybe the author of this issue wants)
2. next should not ignore iter internal and jump to (iter/end) (current behavior)

Now, next command consider the block is literally next, so option 1 seems preferable.

[marianosimone]

In the case above, 2 (at the line with end) is never what I'd expect to happen.

What I would expect is 1 (thus this ticket), but I'd be OK (as in: "I don't like this much, but at least doesn't surprise me") with either stopping inside the iter function (the line with yield) or inside the block (the line with 1).