Rack >= 2.2.2 tests skip Rack::Events#on_finish

[arielvalentin]

While working on migrating the OTel Instrumentation from using Rack middleware to the Events API we ran into some test failures starting with Rack >= 2.2.2.

It seems that the block passed into the EventedBodyProxy that contains a call to on_finish is no longer being executed during test runs.

https://github.com/open-telemetry/opentelemetry-ruby-contrib/actions/runs/4458505381/jobs/7834300742

There do not appear to be any changes between Rack 2.2.2 and 2.2.1 that would impact this behavior, but I do not think I see any buffered response tests in rack-test so its unclear if there is some incompatibility I may have glossed over.

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'
  gem 'minitest'
  gem 'rack', '2.2.2'
  gem 'rack-test', '2.1.0'
end

require 'minitest/autorun'
require 'rack/test'

class MyEventHandler
  include ::Rack::Events::Abstract

  MyError = Class.new(StandardError)

  def on_start(_, _)
    $stderr.puts __method__
  end

  def on_send(_, _)
    $stderr.puts __method__
  end

  def on_commit(_, _)
    $stderr.puts __method__
  end

  def on_finish(_, _)
    raise MyError, 'unexpected'
  end

  def on_error(_, _, _)
    $stderr.puts __method__
  end
end

class BufferedTest < MiniTest::Test
  include Rack::Test::Methods

  def app
    Rack::Builder.new.tap do |builder|
      builder.use Rack::Events, [MyEventHandler.new]
      builder.run ->(_env) { [200, { 'content-type' => 'text/plain' }, Rack::BodyProxy.new('All responses are OK') { puts 'Hello world' }] }
    end
  end

  def test_root
    assert_raises MyEventHandler::MyError do
      get '/'
    end
  end
end

> rack-test-failure(:|✔) %
🤘 ruby test.rb
Run options: --seed 35637

# Running:

on_start
on_commit
F

Finished in 0.004877s, 205.0441 runs/s, 205.0441 assertions/s.

  1) Failure:
BufferedTest#test_root [test.rb:50]:
MyEventHandler::MyError expected but nothing was raised.

1 runs, 1 assertions, 1 failures, 0 errors, 0 skips

Any suggestions or thoughts as to why we may be running into this problem?

[arielvalentin]

For comparison with Rack 2.2.1 and Rack-Test 2.1.0

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'
  gem 'minitest'
  gem 'rack', '2.2.1'
  gem 'rack-test', '2.1.0'
end

require 'minitest/autorun'
require 'rack/test'

class MyEventHandler
  include ::Rack::Events::Abstract

  MyError = Class.new(StandardError)

  def on_start(_, _)
    $stderr.puts __method__
  end

  def on_send(_, _)
    $stderr.puts __method__
  end

  def on_commit(_, _)
    $stderr.puts __method__
  end

  def on_finish(_, _)
    raise MyError, 'unexpected'
  end

  def on_error(_, _, _)
    $stderr.puts __method__
  end
end

class BufferedTest < MiniTest::Test
  include Rack::Test::Methods

  def app
    Rack::Builder.new.tap do |builder|
      builder.use Rack::Events, [MyEventHandler.new]
      builder.run ->(_env) { [200, { 'content-type' => 'text/plain' }, Rack::BodyProxy.new('All responses are OK') { puts 'Hello world' }] }
    end
  end

  def test_root
    assert_raises MyEventHandler::MyError do
      get '/'
    end
  end
end

vibora ~/github/rack-test-failure(:|✔) %
🤘 ruby test.rb
Run options: --seed 43962

# Running:

on_start
on_commit
Hello world
.

Finished in 0.005103s, 195.9632 runs/s, 195.9632 assertions/s.

1 runs, 1 assertions, 0 failures, 0 errors, 0 skips

[jeremyevans]

It helps if you pass Rack::BodyProxy a valid rack body :). Change to Rack::BodyProxy.new(['All responses are OK']) and the test works.

As to why the behavior is skipped for the invalid body, because it is a plain string (in a wrapper that still responds to to_str), Rack::Response treats it as a plain string, and implicitly wraps it in its own array, so the on_finish parts are never called. Potentially, you can consider that a bug in rack, but as you can only trigger it by providing an invalid rack response, it is debatable whether it is a bug or not. However, it's definitely not a bug in rack-test, so I'm closing this.

[arielvalentin]

Thanks @jeremyevans!!! I should have been more diligent in verifying my code was correct so I appreciate you taking the time to review this.

🙇🏼