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

Debugger crashes when frame no longer exists #452

Closed
lukaszsamson opened this issue Jan 7, 2021 · 0 comments · Fixed by #457
Closed

Debugger crashes when frame no longer exists #452

lukaszsamson opened this issue Jan 7, 2021 · 0 comments · Fixed by #457
Labels
bug Something isn't working

Comments

@lukaszsamson
Copy link
Collaborator

lukaszsamson commented Jan 7, 2021

Extracted from #451

Environment

  • Elixir & Erlang versions (elixir --version): all
  • Operating system: all
  • Editor or IDE name (e.g. Emacs/VSCode): all
  • Editor Plugin/LSP Client name: 0.6.2

Logs

If I now set a breakpoing to page_controller.ex at line 5 and I visit the page with a browser, the debugger stops at that line, but if I wait more or less one minute the debugger process crashes. This is the log:

(Debugger) Terminating because an exception was raised:
    ** (MatchError) no match of right hand side value: nil
        (elixir_ls_debugger 0.6.2) lib/debugger/server.ex:291: ElixirLS.Debugger.Server.handle_request/2
        (elixir_ls_debugger 0.6.2) lib/debugger/server.ex:90: ElixirLS.Debugger.Server.handle_cast/2
        (stdlib 3.12) gen_server.erl:637: :gen_server.try_dispatch/4
        (stdlib 3.12) gen_server.erl:711: :gen_server.handle_msg/6
        (stdlib 3.12) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
ElixirLS debugger has crashed
[error] GenServer ElixirLS.Debugger.Server terminating
** (MatchError) no match of right hand side value: nil
    (elixir_ls_debugger 0.6.2) lib/debugger/server.ex:291: ElixirLS.Debugger.Server.handle_request/2
    (elixir_ls_debugger 0.6.2) lib/debugger/server.ex:90: ElixirLS.Debugger.Server.handle_cast/2
    (stdlib 3.12) gen_server.erl:637: :gen_server.try_dispatch/4
    (stdlib 3.12) gen_server.erl:711: :gen_server.handle_msg/6
    (stdlib 3.12) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Last message: {:"$gen_cast", {:receive_packet, %{"arguments" => %{"frameId" => 2}, "command" => "scopes", "seq" => 11, "type" => "request"}}}
State: %ElixirLS.Debugger.Server{breakpoints: %{"/tmp/hello_world/lib/hello_world_web/controllers/page_controller.ex" => [{HelloWorldWeb.PageController, 5}]}, client_info: %{"adapterID" => "Elixir", "clientID" => "vscode", "clientName" => "Visual Studio Code", "columnsStartAt1" => true, "linesStartAt1" => true, "locale" => "en-us", "pathFormat" => "path", "supportsRunInTerminalRequest" => true, "supportsVariablePaging" => true, "supportsVariableType" => true}, config: %{"cwd" => "/tmp/hello_world", "name" => "Elixir::Phoenix<10>", "program" => nil, "projectDir" => "/tmp/hello_world", "request" => "launch", "task" => "phx.server", "taskArgs" => nil, "type" => "Elixir"}, next_id: 24, output: ElixirLS.Debugger.Output, paused_processes: %{#PID<0.1338.0> => %ElixirLS.Debugger.Server.PausedProcess{frames: %{16 => %ElixirLS.Debugger.Stacktrace.Frame{args: [%Plug.Conn{adapter: {Plug.Cowboy.Conn, :...}, assigns: %{}, before_send: [#Function<33.103228614/1 in :dbg_ieval.expr/3>, #Function<33.103228614/1 in :dbg_ieval.expr/3>], body_params: %{}, cookies: %{"_bolgia_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio", "_hello_world_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, halted: false, host: "localhost", method: "GET", owner: #PID<0.1338.0>, params: %{}, path_info: [], path_params: %{}, port: 4000, private: %{HelloWorldWeb.Router => {[], %{}}, :phoenix_endpoint => HelloWorldWeb.Endpoint, :phoenix_request_logger => {"request_logger", "request_logger"}, :phoenix_router => HelloWorldWeb.Router, :plug_session_fetch => #Function<33.103228614/1 in :dbg_ieval.expr/3>}, query_params: %{}, query_string: "", remote_ip: {127, 0, 0, 1}, req_cookies: %{"_bolgia_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio", "_hello_world_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, req_headers: [{"accept", "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"}, {"accept-encoding", "gzip, deflate"}, {"accept-language", "it,en;q=0.7,en-US;q=0.3"}, {"cache-control", "max-age=0"}, {"connection", "keep-alive"}, {"cookie", "_bolgia_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio; _hello_world_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, {"dnt", "1"}, {"host", "localhost:4000"}, {"sec-gpc", "1"}, {"upgrade-insecure-requests", "1"}, {"user-agent", "Mozilla/5.0 (Windows NT 10.0; rv:78.0) Gecko/20100101 Firefox/78.0"}], request_path: "/", resp_body: nil, resp_cookies: %{}, resp_headers: [{"cache-control", "max-age=0, private, must-revalidate"}, {"x-request-id", "Flf8OOCTPs9cm2cAAAFD"}], scheme: :http, script_name: [], secret_key_base: :..., state: :unset, status: nil}, {%{conn: nil, log: :debug, path_params: %{}, pipe_through: [:browser], plug: HelloWorldWeb.PageController, plug_opts: :index, route: "/"}, #Function<39.103228614/2 in :dbg_ieval.expr/3>, #Function<33.103228614/1 in :dbg_ieval.expr/3>, {HelloWorldWeb.PageController, :index}}], bindings: %{___STACKTRACE__@1: [], _conn@1: %Plug.Conn{adapter: {Plug.Cowboy.Conn, :...}, assigns: %{}, before_send: [#Function<33.103228614/1 in :dbg_ieval.expr/3>, #Function<33.103228614/1 in :dbg_ieval.expr/3>], body_params: %{}, cookies: %{"_bolgia_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio", "_hello_world_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, halted: false, host: "localhost", method: "GET", owner: #PID<0.1338.0>, params: %{}, path_info: [], path_params: %{}, port: 4000, private: %{HelloWorldWeb.Router => {[], %{}}, :phoenix_endpoint => HelloWorldWeb.Endpoint, :phoenix_request_logger => {"request_logger", "request_logger"}, :phoenix_router => HelloWorldWeb.Router, :plug_session_fetch => #Function<33.103228614/1 in :dbg_ieval.expr/3>}, query_params: %{}, query_string: "", remote_ip: {127, 0, 0, 1}, req_cookies: %{"_bolgia_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio", "_hello_world_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, req_headers: [{"accept", "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"}, {"accept-encoding", "gzip, deflate"}, {"accept-language", "it,en;q=0.7,en-US;q=0.3"}, {"cache-control", "max-age=0"}, {"connection", "keep-alive"}, {"cookie", "_bolgia_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio; _hello_world_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, {"dnt", "1"}, {"host", "localhost:4000"}, {"sec-gpc", "1"}, {"upgrade-insecure-requests", "1"}, {"user-agent", "Mozilla/5.0 (Windows NT 10.0; rv:78.0) Gecko/20100101 Firefox/78.0"}], request_path: "/", resp_body: nil, resp_cookies: %{}, resp_headers: [{"cache-control", "max-age=0, private, must-revalidate"}, {"x-request-id", "Flf8OOCTPs9cm2cAAAFD"}], scheme: :http, script_name: [], secret_key_base: :..., state: :unset, status: nil}, _conn@2: %Plug.Conn{adapter: {Plug.Cowboy.Conn, :...}, assigns: %{}, before_send: [#Function<33.103228614/1 in :dbg_ieval.expr/3>, #Function<33.103228614/1 in :dbg_ieval.expr/3>], body_params: %{}, cookies: %{"_bolgia_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio", "_hello_world_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, halted: false, host: "localhost", method: "GET", owner: #PID<0.1338.0>, params: %{}, path_info: [], path_params: %{}, port: 4000, private: %{HelloWorldWeb.Router => {[], %{}}, :phoenix_endpoint => HelloWorldWeb.Endpoint, :phoenix_request_logger => {"request_logger", "request_logger"}, :phoenix_router => HelloWorldWeb.Router, :plug_session_fetch => #Function<33.103228614/1 in :dbg_ieval.expr/3>}, query_params: %{}, query_string: "", remote_ip: {127, 0, 0, 1}, req_cookies: %{"_bolgia_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio", "_hello_world_key" => "SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, req_headers: [{"accept", "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"}, {"accept-encoding", "gzip, deflate"}, {"accept-language", "it,en;q=0.7,en-US;q=0.3"}, {"cache-control", "max-age=0"}, {"connection", "keep-alive"}, {"cookie", "_bolgia_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYbjUtVXZZY2YwZjFOUHBMdmk4YjVfeXNG.Q8tKVpXGZnIO-r8VPA9b6AhslXZv6QwGDsSeZFpBcio; _hello_world_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVUMxTlVvRG9GY1V0QkZyanAzT01XcXF4.TK47nkYvBBd_jjdmBzfkIdBccPFau4K5FTHYHosPfzU"}, {"dnt", "1"}, {"h (truncated)

The crash happens in

{pid, frame} = find_frame(state.paused_processes, frame_id)

Most likely a timeout in cowboy http request handler is killing the debugged process, which is not properly handled.

@lukaszsamson lukaszsamson added the bug Something isn't working label Jan 7, 2021
lukaszsamson added a commit that referenced this issue Jan 10, 2021
lukaszsamson added a commit that referenced this issue Jan 10, 2021
axelson pushed a commit that referenced this issue Jan 14, 2021
* remove legacy io_request handlers

we don't support OTP < R15B

* rescue MatchError in :int calls

Fixes #455

* make output device better conform to erlang I/O protocol

see https://erlang.org/doc/apps/stdlib/io_protocol.html for details

* return WireProtocol.send error to the caller

no need to IO.warn if write fails

* we are redirection stderr to stdout, use stdout as underlying device

* inspect error

* monitor debugged processes

add test for mix task exit
Fixes #454

* avoid debugger crashes when handling requests for no longer existing thread, frame and variable ids

Fixes #452

* add test

* forbid changes of underlying device opts

* refactor and add tests coverage to invalid requests

* Map.pop! is available since elixir 1.10

* run formatter
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant