getappmap / appmap-ruby

AppMap client agent for Ruby
https://appland.org
Other
98 stars 11 forks source link

ActionCable results in `http_server_response` with status code -1 #346

Closed dustinbyrne closed 8 months ago

dustinbyrne commented 8 months ago

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: https://github.com/getappmap/appmap-js/pull/1459

kgilpin commented 8 months ago

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 commented 8 months ago
env.request:

"HTTP_UPGRADE"=>"websocket"
kgilpin commented 8 months ago

:tada: This issue has been resolved in version 0.102.2 :tada:

The release is available on:

Your semantic-release bot :package::rocket: