debug icon indicating copy to clipboard operation
debug copied to clipboard
verified publisher icon ruby

Debugger stops at unexpected place when using `trace call`

Open ono-max opened this issue 2 years ago • 4 comments

Your environment

  • ruby -v:
  • ruby 3.1.0p0 (2021-12-25 revision fb4df44d16) [arm64-darwin21]
  • rdbg -v:
  • rdbg 1.7.1

To Reproduce

  1. Clone https://github.com/ono-max/testapp
  2. bundle install
  3. rails db:create
  4. rails db:migrate
  5. bin/rails s
$ bin/rails s
=> Booting Puma
=> Rails 7.0.4.2 application starting in development
=> Run `bin/rails server --help` for more startup options
Puma starting in single mode...
* Puma version: 5.6.5 (ruby 3.0.3-p157) ("Birdie's Version")
*  Min threads: 5
*  Max threads: 5
*  Environment: development
*          PID: 28208
* Listening on http://127.0.0.1:3000
* Listening on http://[::1]:3000
Use Ctrl-C to stop
  1. Go to localhost:3000, then it should stop as follows:
...
Use Ctrl-C to stop
Started GET "/" for ::1 at 2023-02-14 01:57:49 +0900
  ActiveRecord::SchemaMigration Pluck (0.1ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
Processing by StudentsController#index as HTML
[1, 10] in ~/workspace/testapp/app/controllers/students_controller.rb
     1| class StudentsController < ApplicationController
     2|   before_action :set_student, only: %i[ show edit update destroy ]
     3|
     4|   # GET /students or /students.json
     5|   def index
=>   6|     binding.break
     7|     student1 = Student.first
     8|     student2 = Student.last
     9|   end
    10|
=>#0	StudentsController#index at ~/workspace/testapp/app/controllers/students_controller.rb:6
  #1	ActionController::BasicImplicitRender#send_action(method="index", args=[]) at ~/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.4.2/lib/action_controller/metal/basic_implicit_render.rb:6
  # and 75 frames (use `bt' command for all frames)
  1. "trace call"
  2. Set a breakpoint at line 9
  3. Then continue.
  4. Stop at line 7
...
[2, 11] in ~/workspace/testapp/app/controllers/students_controller.rb
     2|   before_action :set_student, only: %i[ show edit update destroy ]
     3|
     4|   # GET /students or /students.json
     5|   def index
     6|     binding.break
=>   7|     student1 = Student.first
     8|     student2 = Student.last
     9|   end
    10|
    11|   # GET /students/1 or /students/1.json
=>#0	StudentsController#index at ~/workspace/testapp/app/controllers/students_controller.rb:7 #=> nil
  #1	ActionController::BasicImplicitRender#send_action(method="index", args=[]) at ~/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.4.2/lib/action_controller/metal/basic_implicit_render.rb:6
  # and 75 frames (use `bt' command for all frames)
...

Expected behavior It should stop at line 9.

Additional context Add any other context about the problem here.

ono-max avatar Feb 13 '23 17:02 ono-max

Should there be a step to run trace call?

st0012 avatar Feb 13 '23 17:02 st0012

Yes, here is the log without trace call.

 bin/rails s
=> Booting Puma
=> Rails 7.0.4.2 application starting in development
=> Run `bin/rails server --help` for more startup options
Puma starting in single mode...
* Puma version: 5.6.5 (ruby 3.0.3-p157) ("Birdie's Version")
*  Min threads: 5
*  Max threads: 5
*  Environment: development
*          PID: 34518
* Listening on http://127.0.0.1:3000
* Listening on http://[::1]:3000
Use Ctrl-C to stop
Started GET "/" for ::1 at 2023-02-14 12:57:41 +0900
  ActiveRecord::SchemaMigration Pluck (0.6ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
Processing by StudentsController#index as HTML
[1, 10] in ~/workspace/testapp/app/controllers/students_controller.rb
     1| class StudentsController < ApplicationController
     2|   before_action :set_student, only: %i[ show edit update destroy ]
     3|
     4|   # GET /students or /students.json
     5|   def index
=>   6|     binding.break
     7|     student1 = Student.first
     8|     student2 = Student.last
     9|   end
    10|
=>#0	StudentsController#index at ~/workspace/testapp/app/controllers/students_controller.rb:6
  #1	ActionController::BasicImplicitRender#send_action(method="index", args=[]) at ~/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.4.2/lib/action_controller/metal/basic_implicit_render.rb:6
  # and 75 frames (use `bt' command for all frames)
(rdbg) b 9    # break command
#0  BP - Line  /Users/s15236/workspace/testapp/app/controllers/students_controller.rb:9 (return)
(rdbg) c    # continue command
  Student Load (0.1ms)  SELECT "students".* FROM "students" ORDER BY "students"."id" ASC LIMIT ?  [["LIMIT", 1]]
  ↳ app/controllers/students_controller.rb:7:in `index'
  Student Load (0.1ms)  SELECT "students".* FROM "students" ORDER BY "students"."id" DESC LIMIT ?  [["LIMIT", 1]]
  ↳ app/controllers/students_controller.rb:8:in `index'
[4, 13] in ~/workspace/testapp/app/controllers/students_controller.rb
     4|   # GET /students or /students.json
     5|   def index
     6|     binding.break
     7|     student1 = Student.first
     8|     student2 = Student.last
=>   9|   end
    10|
    11|   # GET /students/1 or /students/1.json
    12|   def show
    13|   end
=>#0	StudentsController#index at ~/workspace/testapp/app/controllers/students_controller.rb:9 #=> nil
  #1	ActionController::BasicImplicitRender#send_action(method="index", args=[]) at ~/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.4.2/lib/action_controller/metal/basic_implicit_render.rb:6
  # and 75 frames (use `bt' command for all frames)

Stop by #0  BP - Line  /Users/s15236/workspace/testapp/app/controllers/students_controller.rb:9 (return)
Really quit? [Y/n] Exiting
Completed   in 7048ms (ActiveRecord: 0.5ms | Allocations: 301599)

ono-max avatar Feb 14 '23 03:02 ono-max

step "7 Set a breakpoint at line 9", maybe it needs to type "trace call". (not in the description) And I can repro (stop at line 7).

ko1 avatar Mar 25 '23 18:03 ko1

and I'm not sure what's happens...

ko1 avatar Mar 25 '23 18:03 ko1