Async::Container::Process, SystemStackError: stack level too deep

[travisbell]

Hey Sam,

Sorry for just dumping this report in the async library. I think maybe it's technically a an async-pool(?) bug. Not 100% sure. There's so many repos now... 😉 Anywho, I've been playing async-http and when ctrl-c'ing an instance of Falcon, this gets dumped to the terminal:

error: Async::Container::Process [ec=0xd5fc] [pid=4882] [2024-04-21 17:58:24 +0000]
  |   SystemStackError: stack level too deep
        ... repeats many more times...
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:188 in `block in as_json'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187 in `each'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187 in `as_json'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:63 in `as_json'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:188 in `block in as_json'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187 in `each'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187 in `as_json'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:63 in `as_json'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/json/encoding.rb:23 in `encode'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/json/encoding.rb:23 in `encode'
  |     /usr/local/bundle/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:42 in `to_json'
  |     /usr/local/bundle/gems/console-1.23.7/lib/console/terminal/logger.rb:122 in `format_options'
  |     /usr/local/bundle/gems/console-1.23.7/lib/console/terminal/logger.rb:113 in `call'
  |     /usr/local/bundle/gems/console-1.23.7/lib/console/filter.rb:149 in `call'
  |     /usr/local/bundle/gems/console-1.23.7/lib/console/filter.rb:40 in `block (3 levels) in []'
  |     /usr/local/bundle/gems/async-pool-0.4.0/lib/async/pool/controller.rb:127 in `close'
  |     /usr/local/bundle/gems/async-pool-0.4.0/lib/async/pool/controller.rb:210 in `ensure in block in start_gardener'
  |     /usr/local/bundle/gems/async-pool-0.4.0/lib/async/pool/controller.rb:210 in `block in start_gardener'
  |     /usr/local/bundle/gems/async-2.10.2/lib/async/task.rb:163 in `block in run'
  |     /usr/local/bundle/gems/async-2.10.2/lib/async/task.rb:376 in `block in schedule'

I saw another bug you fixed somewhere for this, so I suspect you know what's happening.

Thanks as always.

[ioquatix]

Can you try updating to the latest version of protocol-http as I believe we addressed this issue.

#156

[travisbell]

Ah yes, that's the other report I found. The above error is with:

• async-http (0.64.1)
• protocol-http (0.26.4)

[travisbell]

So, a weird (possibly related behaviour) I'm seeing is that when a request is processed via Async::HTTP::Protocol::HTTPS, everything is fine. But for requests processed through Async::HTTP::Protocol::HTTP1::Client, I see the error.

Update with some code

Sync do
  endpoint = Async::HTTP::Endpoint.parse("http://hostname:80")
  client = Async::HTTP::Client.new(endpoint)
  client.get("/")
end

Results in the following error, which is slightly different than the one above:

/Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/instance_variables.rb:15:in `to_h': stack level too deep (SystemStackError)
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/instance_variables.rb:15:in `instance_values'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:63:in `as_json'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:188:in `block in as_json'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187:in `each'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187:in `as_json'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:63:in `as_json'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:188:in `block in as_json'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/object/json.rb:187:in `each'
	 ... 1042 levels...
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/async-pool-0.4.0/lib/async/pool/controller.rb:210:in `ensure in block in start_gardener'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/async-pool-0.4.0/lib/async/pool/controller.rb:210:in `block in start_gardener'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/async-2.10.2/lib/async/task.rb:163:in `block in run'
	from /Users/travisbell/.rbenv/versions/3.2.3/lib/ruby/gems/3.2.0/gems/async-2.10.2/lib/async/task.rb:376:in `block in schedule'

This request on the other hand returns successfully, with no error:

Sync do
  endpoint = Async::HTTP::Endpoint.parse("https://hostname:443")
  client = Async::HTTP::Client.new(endpoint)
  client.get("/")
end

Again, sorry about this not being in async-http, as it now seems like it should be. My bad.

[ioquatix]

Okay, let me take a look.

[ioquatix]

Are you able to make a complete reproduction for me, as I can't get it to fail:

Example code:

class WelcomeController < ApplicationController
  def index
    Sync do
      endpoint = Async::HTTP::Endpoint.parse("http://www.google.com")
      client = Async::HTTP::Client.new(endpoint)
      response = client.get("/")
      Console.info(self, response: response)
      puts response.inspect, response.read
    ensure
      response&.finish
      client&.close
    end
  end
end

Output:

 2.55s     info: WelcomeController: connected to #<Addrinfo: 142.250.66.228:80 TCP (www.google.com)> [fd=25] [oid=0x5fdc] [ec=0x4074] [pid=1635924] [2024-04-22 10:30:51 +1200]
               | {"response":{"version":"HTTP/1.1","status":200,"headers":{"date":"Sun, 21 Apr 2024 22:30:51 GMT","expires":"-1","cache-control":["private","max-age=0"],"content-type":"text/html; charset=ISO-8859-1","content-security-policy-report-only":["object-src 'none';base-uri 'self';script-src 'nonce-fKetK-YQus91Dayo7dzrNg' 'strict-dynamic' 'report-sample' 'unsafe-eval' 'unsafe-inline' https: http:;report-uri https://csp.withgoogle.com/csp/gws/other-hp"],"p3p":["CP=\"This is not a P3P policy! See g.co/p3phelp for more info.\""],"server":["gws"],"x-xss-protection":["0"],"x-frame-options":["SAMEORIGIN"],"set-cookie":["...snip..."],"accept-ranges":["none"],"vary":["accept-encoding"]},"body":{"class":"Protocol::HTTP::Body::Completable","body":{"class":"Protocol::HTTP1::Body::Chunked","length":null,"stream":false,"ready":false,"empty":false}},"protocol":null}}

[ioquatix]

Ah, I figured it out... hold on.

[ioquatix]

Okay, the first part, updating async-pool is done. This should at least prevent the main source of the issue, which is the implicit as_json added by Rails. I'll also update async-http to support as_json better.

[ioquatix]

Next set of fixes: 8afd1f1

[ioquatix]

Okay, I've released updates to both async-pool and async-http which should mitigate this issue, I'm also going to change console gem to use JSON.generate rather than thing.to_json as Rails also does weird things trying to escape the resulting JSON making it look pretty ugly.

After updating the gems, can you test it again? Thanks.

[travisbell]

Yup, looking good. I no longer see the error. 👏🏼

Thanks a ton for the quick turnaround, truly legendary.

[ioquatix]

I blame Rails for this - monkey patching the core classes (including Object!!) to do potentially broken things... I opened an issue on Rails to discuss further.

rails/rails#51626