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

ActionCable results in http_server_response with status code -1 #346

Closed
dustinbyrne opened this issue Nov 3, 2023 · 3 comments · Fixed by #347
Closed

ActionCable results in http_server_response with status code -1 #346

dustinbyrne opened this issue Nov 3, 2023 · 3 comments · Fixed by #347
Labels
bug Something isn't working released

Comments

@dustinbyrne
Copy link
Contributor

dustinbyrne commented Nov 3, 2023

When requesting a websocket connection, the following is recorded:

"http_server_request": {
  "request_method": "GET",
  "path_info": "/cable",
  "normalized_path_info": "/cable",
  "headers": {
    "Version": "HTTP/1.1",
    "Host": "localhost:3000",
    "Connection": "Upgrade",
    "Pragma": "no-cache",
    "Cache-Control": "no-cache",
    "User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36",
    "Upgrade": "websocket",
    "Origin": "http://localhost:3000",
    "Sec-Websocket-Version": "13",
    "Accept-Encoding": "gzip, deflate, br",
    "Accept-Language": "en-US,en;q=0.9",
    "Sec-Websocket-Key": "ZXhhbXBsZQo=",
    "Sec-Websocket-Extensions": "permessage-deflate; client_max_window_bits",
    "Sec-Websocket-Protocol": "actioncable-v1-json, actioncable-unsupported"
  }
},
"http_server_response": {
  "status_code": -1,
  "headers": {
    "Cache-Control": "no-cache",
    "Set-Cookie": "session=; path=/; expires=Sun, 03 Nov 2024 21:35:39 GMT; HttpOnly",
    "X-Request-Id": "9ec7a0f1-c228-4704-b89d-b8a629c9ca61",
    "X-Runtime": "0.006866"
  }
}

This leads to the generation of a nonconforming OpenAPI definition

paths:
  /cable:
    get:
      responses:
        '-1':
          content: {}

Related: getappmap/appmap-js#1459

@kgilpin
Copy link
Contributor

kgilpin commented Nov 5, 2023

Context in which this occurs:

[74, 83] in /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/handler/rails/request_handler.rb
   74: 
   75:           class << self
   76:             def build_from_invocation(parent_id, return_value, elapsed, response, event: HTTPServerResponse.new)
   77:               event ||= HTTPServerResponse.new
   78:               byebug
=> 79:               event.status = response[:status] || response.status
   80:               event.headers = (response[:headers] || response.headers).dup
   81:               AppMap::Event::MethodReturn.build_from_invocation parent_id, return_value, nil, elapsed: elapsed, event: event, parameter_schema: true
   82:             end
   83:           end
(byebug) response.status
-1
(byebug) response
#<ActionDispatch::Response:0x0000000112903a18 @mon_data=#<Monitor:0x00000001129036f8>, @mon_data_owner_object_id=122880, @header={"Cache-Control"=>"no-cache", "Set-Cookie"=>"appland_session=f%2Bli0P7CmfnGho8YMvyaWjS37ANr0wVHSi9TptkmVtPQdIqG6aVnfo82QGlq2vOzhk9HJId21RdpT0eBh5Er1WuwjkhDatmnEcsXl3PkQH8DIFYkMfx1xX03g2WjRrp5%2F8PZWu%2F60FBa9%2BtPSvaXZy%2BTaMLyGL8eXptiJO4%2BIm%2FoJFEkHIlBGGpMO1ce9L5qbAP9dVEslFFili%2Bd2eGz5QjLxGXHnC496Kk7tbVhoCbOR8taRDRqd08zDJjUpDifCUSlmqVPvj1qC3nRQJ5OfZ7%2FgtrHNZtFG2FfNHH2vHTS%2BlusSKwLexrGmVPoY%2Fis1fJCCTTi7xE1cB2D8FIeD%2FafjHO9reFpbhsreH%2BSUIk8Q8TqKlYLBuMXIJ7Hs0TEbsFwOkfz3UMiJFJU6lRyaFpSPaWK%2BJWpW5FF8mxUv4MUnYz4aACOX2HheVjNipV9VYglFDFl92lQWe4n6aRKzrEOWDBvi%2F9pTC4yff%2Feg0jPvqRNAu0cPRAQFx37q%2FLqlx1uM35GSBQV9djbAzVJKCSSr4bnb%2FNPRig822F64JG0UmuzAmmFQySP5gAyvLqfWK7D0pmL8v1sdykSTVCzIPJQZoovJnbJKFoPCk3jOn0feKDj6pEcSmY%2B3j4OkuG3FdsjpRw5dJXao9Kn5s78K67ijcn0qAE4yAuqUrJx0%2FvdG4%2BDXPMSSLkXAk9AdATgsGxtV5AR9%2Fay56l5oc%2BQ0lhhh7MznqQnwgECXNwWc2QRzTsQH5SJsy6sE9kFXI1K1A%3D%3D--2TwiuwhD5jItpmGb--ioXatnv1gGSiZE6EBWQ4jA%3D%3D; path=/; expires=Tue, 05 Nov 2024 15:28:10 GMT; HttpOnly", "X-Request-Id"=>"812671b1-2f24-435f-bf29-4f2f53aa0f88", "X-Runtime"=>"0.032273"}, @stream=#<ActionDispatch::Response::Buffer:0x0000000112902e88 @response=#<ActionDispatch::Response:0x0000000112903a18 ...>, @buf=#<Rack::BodyProxy:0x00000001129083b0 @body=#<Rack::BodyProxy:0x0000000112908a90 @body=#<Rack::BodyProxy:0x000000011290b240 @body=#<Rack::BodyProxy:0x0000000112609678 @body=[], @block=#<Proc:0x00000001126091f0 /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-2.2.8/lib/rack/tempfile_reaper.rb:16>, @closed=false>, @block=#<Proc:0x0000000112909fd0 /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/railties-6.1.4.1/lib/rails/rack/logger.rb:38>, @closed=false>, @block=#<Proc:0x0000000112908770 /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/activesupport-6.1.4.1/lib/active_support/cache/strategy/local_cache_middleware.rb:30>, @closed=false>, @block=#<Proc:0x0000000112908180 /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/actionpack-6.1.4.1/lib/action_dispatch/middleware/executor.rb:15>, @closed=false>, @closed=false, @str_body=nil>, @status=-1, @cv=#<MonitorMixin::ConditionVariable:0x0000000112902be0 @monitor=#<Monitor:0x00000001129036f8>, @cond=#<Thread::ConditionVariable:0x00000001129028c0>>, @committed=false, @sending=false, @sent=false, @cache_control={:no_cache=>true}>
(byebug) bt
--> #0  #<Class:AppMap::Handler::Rails::RequestHandler::HTTPServerResponse>.build_from_invocation(parent_id#Integer, return_value#NilClass, elapsed#Float, response#ActionDispatch::Response, event#AppMap::Handler::Rails::RequestHandler::HTTPServerResponse) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/handler/rails/request_handler.rb:79
    #1  AppMap::Handler::Rails::RequestHandler::RackHook.after_hook(_receiver#ActionDispatch::Executor, call_event#AppMap::Handler::Rails::RequestHandler::HTTPServerRequest, elapsed_before#Float, elapsed#Float, after_hook_start_time#Float, rack_return#Array, _exception#NilClass) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/handler/rails/request_handler.rb:164
    #2  block in AppMap::Hook::Method.block in trace_call(call_event#AppMap::Handler::Rails::RequestHandler::HTTPServerRequest, elapsed_before#Float, receiver#ActionDispatch::Executor, *args#Array, kwargs#Hash, &block#NilClass) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/hook/method/ruby3.rb:55
    #3  AppMap::Hook::Method.with_disabled_hook at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/hook/method.rb:125
    #4  AppMap::Hook::Method.trace_call(call_event#AppMap::Handler::Rails::RequestHandler::HTTPServerRequest, elapsed_before#Float, receiver#ActionDispatch::Executor, *args#Array, kwargs#Hash, &block#NilClass) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/hook/method/ruby3.rb:55
    #5  AppMap::Hook::Method.call(receiver#ActionDispatch::Executor, *args#Array, kwargs#Hash, &block#NilClass) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/hook/method/ruby3.rb:16
    #6  block in ActionDispatch::Executor.block in hook_method_def(env#NilClass) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/hook/method/ruby3.rb:63
    #7  AppMap::Middleware::RemoteRecording.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/appmap-0.102.1/lib/appmap/middleware/remote_recording.rb:131
    #8  ActionDispatch::Static.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/actionpack-6.1.4.1/lib/action_dispatch/middleware/static.rb:24
    #9  Rack::Sendfile.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-2.2.8/lib/rack/sendfile.rb:110
    #10 ActionDispatch::HostAuthorization.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/actionpack-6.1.4.1/lib/action_dispatch/middleware/host_authorization.rb:92
    #11 Rack::MiniProfiler.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-mini-profiler-2.3.3/lib/mini_profiler/profiler.rb:249
    #12 Rack::Cors.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-cors-1.1.1/lib/rack/cors.rb:100
    #13 Rack::Rewrite.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-rewrite-1.5.1/lib/rack/rewrite.rb:24
    #14 Rails::Engine.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/railties-6.1.4.1/lib/rails/engine.rb:539
    #15 block in Rack::URLMap.block in call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-2.2.8/lib/rack/urlmap.rb:74
    ͱ-- #16 Array.each at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-2.2.8/lib/rack/urlmap.rb:58
    #17 Rack::URLMap.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-2.2.8/lib/rack/urlmap.rb:58
    #18 Rack::Builder.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/rack-2.2.8/lib/rack/builder.rb:244
    #19 Capybara::Server::Middleware.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/capybara-3.38.0/lib/capybara/server/middleware.rb:60
    #20 Puma::Configuration::ConfigMiddleware.call(env#Hash) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/configuration.rb:270
    #21 block in Puma::Request.block in handle_request(client#Puma::Client, requests#Integer) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/request.rb:98
    #22 Puma::ThreadPool.with_force_shutdown at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/thread_pool.rb:340
    #23 Puma::Request.handle_request(client#Puma::Client, requests#Integer) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/request.rb:97
    #24 Puma::Server.process_client(client#Puma::Client) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/server.rb:431
    #25 block in Puma::Server.block in run(background#TrueClass, thread_name#String) at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/server.rb:233
    #26 block in Puma::ThreadPool.block in spawn_thread at /Users/kgilpin/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/puma-6.2.2/lib/puma/thread_pool.rb:147

@kgilpin
Copy link
Contributor

kgilpin commented Nov 5, 2023

env.request:

"HTTP_UPGRADE"=>"websocket"

@kgilpin
Copy link
Contributor

kgilpin commented Nov 7, 2023

🎉 This issue has been resolved in version 0.102.2 🎉

The release is available on:

Your semantic-release bot 📦🚀

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

Successfully merging a pull request may close this issue.

2 participants