Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improved stability for chrome debugging #893

Merged
merged 3 commits into from
Mar 7, 2023

Conversation

josegomezr
Copy link
Contributor

@josegomezr josegomezr commented Feb 9, 2023

Description

Describe your changes: Improved stability for chrome debugging

Display the greeting message regardless of the status of invocation of chrome.
This allows coming back to the debugger on a new tab when the window process by UI_CDP.run_new_chrome is killed.

Handle Errno::ESRCH in UI_CDP.cleanup_reader.
When the process by UI_CDP.run_new_chrome is killed, re-killing it breaks your debugging session and in turn the "debugee".

Background

I stumble upon this inconvenience when using it in a rails application, I noticed that after closing the chrome window I couldn't go back to it, and re-attaching with bin/rdbg -A --open=chrome gave more cryptic errors.

Also when restarting the app to get a hold of the debugging window, I noticed it throws Errno::ESRCH.

These changes should address the minor annoyances, out of ignorance I'd not venture into why "reattaching" as I tried to doesn't work 😅

Steps to reproduce

Do the following prelude before the testing the behavior.

OPT 1 (calling DEBUGGER__.open(nonstop: true, open: 'chrome'))

  1. Configure the debugger in your app with: DEBUGGER__.open(nonstop: true, open: 'chrome')
  2. Place a debugger breakpoint somewhere accessible
  3. Start your app
  4. Close the chrome window that just pops

OPT 2 (running the app with rdbg --open=chrome)

  1. Place a debugger breakpoint somewhere accessible
  2. Run your app with rdbg --open=chrome %your application here%
  3. Close the chrome window that just pops

Verify Changes

  1. See the app logs to recover the original devtools:// URL
  2. Open the devtools:// URL
    • See that the debugging session can be resumed
  3. Close/Stop your app
    • See that there's no #<Errno::ESRCH: No such process> line in the logs

P.S. 1: modified the description to include more details about how to reproduce & what to expect.

@ko1
Copy link
Collaborator

ko1 commented Mar 7, 2023

@ono-max san could you check it?

- Display the greeting message regardless of the status of invocation of
  chrome.

  This allows coming back to the debugger on a new tab when the window
  process by `UI_CDP.run_new_chrome` is killed.

- Handle `Errno::ESRCH` in `UI_CDP.cleanup_reader`.

  When the process by `UI_CDP.run_new_chrome` is killed, re-killing it
  breaks your debugging session and in turn the "debugee".
`UI_ServerBase#greeting` calls `#puts` with no arguments, this
breaks reconnections to the debugger.
`Session#process_protocol_request` gracefully handles `Errno::ENOENT`
when `eval`-ing `$FILENAME`, and it doens't exist.
@josegomezr josegomezr force-pushed the improve_stability_chrome_debugger branch from eb9e657 to fd70fb6 Compare March 7, 2023 12:29
@ono-max ono-max self-requested a review March 7, 2023 15:13
Copy link
Member

@ono-max ono-max left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for your investigation.

Also, I supported reattaching in #917 👍

@josegomezr
Copy link
Contributor Author

Looks like a flaky test in CI, I couldn't replicate exactly that error locally.

On a run I got:

================================================================================
Failure: test_eval_evaluates_arithmetic_expressions(DEBUGGER__::EvaluateOnSomeFramesTest):
  -------------------------
  | All Protocol Messages |
  -------------------------
  
  C>D {"id":2,"method":"Runtime.enable","params":{}}
  C>D {"id":3,"method":"Debugger.enable","params":{"maxScriptsCacheSize":10000000}}
  C>D {"id":4,"method":"Debugger.setPauseOnExceptions","params":{"state":"none"}}
  C>D {"id":5,"method":"Debugger.setAsyncCallStackDepth","params":{"maxDepth":32}}
  C>D {"id":6,"method":"Profiler.enable","params":{}}
  C>D {"id":7,"method":"Debugger.setBlackboxPatterns","params":{"patterns":[]}}
  C>D {"id":8,"method":"Runtime.runIfWaitingForDebugger","params":{}}
  C<D {"id":2,"result":{}}
  C<D {"method":"Runtime.executionContextCreated","params":{"context":{"id":"5bf22d216607f66d19472543b7c33d80","origin":"http://127.0.0.1:40667","name":""}}}
  C<D {"id":3,"result":{}}
  C<D {"id":4,"result":{}}
  C<D {"method":"Debugger.scriptParsed","params":{"scriptId":"1","url":"/tmp/debug-20230307-24941-p340pu.rb","startLine":0,"startColumn":0,"endLine":5,"endColumn":0,"executionContextId":1,"hash":"-1432932342203347699"}}
  C<D {"method":"Debugger.paused","params":{"reason":"other","callFrames":[{"callFrameId":"c42424b843bfb06e341efebeef791ab4","functionName":"<main>","functionLocation":{"lineNumber":0,"scriptId":"1"},"location":{"lineNumber":0,"scriptId":"1"},"url":"/tmp/debug-20230307-24941-p340pu.rb","scopeChain":[{"type":"local","object":{"type":"object","objectId":"0.13179598252195757"}},{"type":"script","object":{"type":"object","objectId":"0.5274198710080361"}},{"type":"global","object":{"type":"object","objectId":"0.5299307261086328"}}],"this":{"type":"object"}}]}}
  C>D {"method":"Debugger.setBreakpointByUrl","params":{"lineNumber":3,"urlRegex":"/tmp/debug\\-20230307\\-24941\\-p340pu\\.rb|file:///tmp/debug\\-20230307\\-24941\\-p340pu\\.rb","columnNumber":0,"condition":null},"id":9}
  C<D {"id":8,"result":{}}
  C<D {"id":9,"result":{"breakpointId":"1:3:/tmp/debug\\-20230307\\-24941\\-p340pu\\.rb|file:///tmp/debug\\-20230307\\-24941\\-p340pu\\.rb","locations":[{"scriptId":"1","lineNumber":3}]}}
  C>D {"method":"Debugger.resume","params":{},"id":10}
  C<D {"id":10,"result":{}}
  C<D {"method":"Debugger.resumed","params":{}}
  C<D {"method":"Debugger.scriptParsed","params":{"scriptId":"1","url":"/tmp/debug-20230307-24941-p340pu.rb","startLine":0,"startColumn":0,"endLine":5,"endColumn":0,"executionContextId":1,"hash":"-1432932342203347699"}}
  C<D {"method":"Debugger.scriptParsed","params":{"scriptId":"1","url":"/tmp/debug-20230307-24941-p340pu.rb","startLine":0,"startColumn":0,"endLine":5,"endColumn":0,"executionContextId":1,"hash":"-1432932342203347699"}}
  C<D {"method":"Debugger.paused","params":{"reason":"other","callFrames":[{"callFrameId":"5022645ee9fea35b6cae0168c40272e6","functionName":"Object#foo","functionLocation":{"lineNumber":1,"scriptId":"1"},"location":{"lineNumber":3,"scriptId":"1"},"url":"/tmp/debug-20230307-24941-p340pu.rb","scopeChain":[{"type":"local","object":{"type":"object","objectId":"0.7223071039239377"}},{"type":"script","object":{"type":"object","objectId":"0.1641509884962037"}},{"type":"global","object":{"type":"object","objectId":"0.2572593458436906"}}],"this":{"type":"object"}},{"callFrameId":"d8ddf71a761484bf9cb3833aec3be3c8","functionName":"<main>","functionLocation":{"lineNumber":0,"scriptId":"1"},"location":{"lineNumber":4,"scriptId":"1"},"url":"/tmp/debug-20230307-24941-p340pu.rb","scopeChain":[{"type":"local","object":{"type":"object","objectId":"0.848870945730477"}},{"type":"script","object":{"type":"object","objectId":"0.9562419561866253"}},{"type":"global","object":{"type":"object","objectId":"0.6200423110201154"}}],"this":{"type":"object"}}]}}
  C>D {"method":"Debugger.evaluateOnCallFrame","params":{"expression":"a","callFrameId":"5022645ee9fea35b6cae0168c40272e6","objectGroup":"console"},"id":11}
  C<D {"method":"Debugger.scriptParsed","params":{"scriptId":"2","url":"","startLine":0,"startColumn":0,"endLine":1,"endColumn":0,"executionContextId":1,"hash":"-1352897453031163333"}}
  C<D {"id":11,"result":{"result":{"type":"number","description":"4","value":4,"objectId":"0.7575177138908398"}}}
  C>D {"method":"Debugger.evaluateOnCallFrame","params":{"expression":"a","callFrameId":"d8ddf71a761484bf9cb3833aec3be3c8","objectGroup":"console"},"id":12}
  C<D {"method":"Debugger.scriptParsed","params":{"scriptId":"3","url":"","startLine":0,"startColumn":0,"endLine":1,"endColumn":0,"executionContextId":1,"hash":"-1352897453031163333"}}
  C<D {"id":12,"result":{"result":{"type":"number","description":"2","value":2,"objectId":"0.07936993312215757"}}}
  C>D {"method":"Runtime.terminateExecution","params":{},"id":13}
  C<D {"id":13,"result":{}}
  
  --------------------------
  | Last Protocol Messages |
  --------------------------
  
  {
    "id": 12,
    "result": {
      "result": {
        "type": "number",
        "description": "2",
        "value": 2,
        "objectId": "0.07936993312215757"
      }
    }
  }
  {
    "method": "Runtime.terminateExecution",
    "params": {
    },
    "id": 13
  }
  {
    "id": 13,
    "result": {
    }
  }
  
  --------------------
  | Debuggee Session |
  --------------------
  
  > DEBUGGER: Debugger can attach via TCP/IP (127.0.0.1:40667)
  > DEBUGGER: wait for debugger connection...
  > DEBUGGER: Connected.
  > DEBUGGER: Disconnected.
  > DEBUGGER: Connected.
  > DEBUGGER: Disconnected.
  > ["DEBUGGER Exception: /home/josegomezr/code/ruby-debug/lib/debug/thread_client.rb:1233",
  >  #<SignalException: SIGTERM>,
  >  ["/home/josegomezr/code/ruby-debug/lib/debug/thread_client.rb:874:in `pop'",
  >   "/home/josegomezr/code/ruby-debug/lib/debug/thread_client.rb:874:in `wait_next_action_'",
  >   "/home/josegomezr/code/ruby-debug/lib/debug/thread_client.rb:856:in `wait_next_action'",
  >   "/home/josegomezr/code/ruby-debug/lib/debug/thread_client.rb:320:in `suspend'",
  >   "/home/josegomezr/code/ruby-debug/lib/debug/thread_client.rb:251:in `on_breakpoint'",
  >   "/home/josegomezr/code/ruby-debug/lib/debug/breakpoint.rb:69:in `suspend'",
  >   "/home/josegomezr/code/ruby-debug/lib/debug/breakpoint.rb:178:in `block in setup'",
  >   "/tmp/debug-20230307-24941-p340pu.rb:4:in `foo'",
  >   "/tmp/debug-20230307-24941-p340pu.rb:5:in `<main>'"]]
  
  
  -------------------
  | Failure Message |
  -------------------
  
  Expected the debuggee program to finish.
/home/josegomezr/code/ruby-debug/test/support/assertions.rb:97:in `assert_block'
/home/josegomezr/code/ruby-debug/test/support/protocol_test_case.rb:372:in `execute_cdp_scenario_'
/home/josegomezr/code/ruby-debug/test/support/protocol_test_case.rb:379:in `execute_cdp_scenario'
/home/josegomezr/code/ruby-debug/test/support/protocol_test_case.rb:47:in `block in run_protocol_scenario'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/lib64/ruby/3.1.0/timeout.rb:107:in `block in timeout'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/lib64/ruby/3.1.0/timeout.rb:36:in `block in catch'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/lib64/ruby/3.1.0/timeout.rb:36:in `catch'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/lib64/ruby/3.1.0/timeout.rb:36:in `catch'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/lib64/ruby/3.1.0/timeout.rb:123:in `timeout'
/home/josegomezr/code/ruby-debug/test/support/protocol_test_case.rb:44:in `run_protocol_scenario'
/home/josegomezr/code/ruby-debug/test/protocol/eval_test.rb:38:in `test_eval_evaluates_arithmetic_expressions'
     35:     RUBY
     36: 
     37:     def test_eval_evaluates_arithmetic_expressions
  => 38:       run_protocol_scenario PROGRAM do
     39:         req_add_breakpoint 4
     40:         req_continue
     41:         assert_repl_result({value: '4', type: 'Integer'}, 'a', frame_idx: 0)
================================================================================
......................
Finished in 103.524598478 seconds.
--------------------------------------------------------------------------------
48 tests, 7355 assertions, 1 failures, 0 errors, 0 pendings, 0 omissions, 0 notifications
97.9167% passed
--------------------------------------------------------------------------------
0.46 tests/s, 71.05 assertions/s
rake aborted!
Command failed with status (1)
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/cli/exec.rb:58:in `load'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/cli/exec.rb:58:in `kernel_load'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/cli/exec.rb:23:in `run'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/cli.rb:491:in `exec'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/cli.rb:34:in `dispatch'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/cli.rb:28:in `start'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/exe/bundle:45:in `block in <top (required)>'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
/home/josegomezr/.rvm/gems/ruby-3.1.3/gems/bundler-2.4.6/exe/bundle:33:in `<top (required)>'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/bin/bundle:25:in `load'
/home/josegomezr/.rvm/rubies/ruby-3.1.3/bin/bundle:25:in `<main>'
/home/josegomezr/.rvm/gems/ruby-3.1.3/bin/ruby_executable_hooks:22:in `eval'
/home/josegomezr/.rvm/gems/ruby-3.1.3/bin/ruby_executable_hooks:22:in `<main>'
Tasks: TOP => test_protocol
(See full trace by running task with --trace)

but the next run was green (?), weird.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

3 participants