CI: Failed ObjectSpaceInputTest

[Watson1978]

Describe the bug

Now ObjectSpaceInputTest causes following error.

ObjectSpaceInputTest: 
  test_configure:                                                                                                                                               .: (0.001749)
  test_emit:                                                                                                                                                    F
=======================================================================================================================================================================================
Failure: test_emit(ObjectSpaceInputTest):
      assert{ emits.length > 0 }
              |     |      |
              |     |      false
              |     0
              []
/home/watson/src/fluentd/test/plugin/test_in_object_space.rb:58:in `test_emit'
     55:     d.run(expect_emits: 3)
     56: 
     57:     emits = d.events
  => 58:     assert{ emits.length > 0 }
     59: 
     60:     emits.each { |tag, time, record|
     61:       assert_equal d.instance.tag, tag
=======================================================================================================================================================================================
: (300.285955)

To Reproduce

bundle exec rake

Expected behavior

No error

Your Environment

- Fluentd version:
- Package version:
- Operating system:
- Kernel version:

Your Configuration

none

Your Error Log

Ref. https://github.com/fluent/fluentd/actions/runs/16896497001

Additional context

No response

[Watson1978]

Reproduce

Seems we can reproduce with following:

$ bundle exec ruby -I"lib:test" -Eascii-8bit:ascii-8bit ~/.rbenv/versions/3.3.9/lib/ruby/gems/3.3.0/gems/rake-13.3.0/lib/rake/rake_test_loader.rb \
    "test/plugin/test_in_object_space.rb" "test/plugin_helper/test_event_emitter.rb" -v

Or, if we specify test/plugin/test_input.rb instead of test/plugin_helper/test_event_emitter.rb, we can reproduce the problem too.

bundle exec ruby -I"lib:test" -Eascii-8bit:ascii-8bit ~/.rbenv/versions/3.3.9/lib/ruby/gems/3.3.0/gems/rake-13.3.0/lib/rake/rake_test_loader.rb \
    "test/plugin/test_in_object_space.rb"  "test/plugin/test_input.rb" -v

Result

$ bundle exec ruby -I"lib:test" -Eascii-8bit:ascii-8bit ~/.rbenv/versions/3.3.9/lib/ruby/gems/3.3.0/gems/rake-13.3.0/lib/rake/rake_test_loader.rb \
    "test/plugin/test_in_object_space.rb" "test/plugin_helper/test_event_emitter.rb" -v
Loaded suite /Users/watson/.rbenv/versions/3.3.9/lib/ruby/gems/3.3.0/gems/rake-13.3.0/lib/rake/rake_test_loader
Started
EventEmitterTest:
  test: #router should return source_only_router during source-only:		.: (0.003777)
  test: #router should return the root router by default:			.: (0.003341)
  test: can be configured with valid router:					.: (0.000293)
  test: can be instantiated to be able to emit with router:			.: (0.000296)
  test: get root router:							.: (0.000183)
  test: get router:								.: (0.000367)
  test: should have event_emitter_router:					.: (0.000177)
  test: should not have event_emitter_router:					.: (0.000207)
ObjectSpaceInputTest:
  test_configure:								.: (0.007941)
  test_emit:									F
======================================================================================================
Failure: test_emit(ObjectSpaceInputTest):
      assert{ emits.length > 0 }
              |     |      |
              |     |      false
              |     0
              []
/Users/watson/src/fluentd/test/plugin/test_in_object_space.rb:58:in `test_emit'
     55:     d.run(expect_emits: 3)
     56:
     57:     emits = d.events
  => 58:     assert{ emits.length > 0 }
     59:
     60:     emits.each { |tag, time, record|
     61:       assert_equal d.instance.tag, tag
======================================================================================================
: (300.327173)

Finished in 300.344654 seconds.
------------------------------------------------------------------------------------------------------
10 tests, 22 assertions, 1 failures, 0 errors, 0 pendings, 0 omissions, 0 notifications
90% passed
------------------------------------------------------------------------------------------------------
0.03 tests/s, 0.07 assertions/s

[Watson1978]

If I downgrade flexmock version to 2.4.2, the tests will be passed.

Or, If I removed

fluentd/test/plugin_helper/test_event_emitter.rb

Lines 63 to 73 in fd711c5

	test 'get router' do
	router_mock = flexmock('mytest')
	label_mock = flexmock('mylabel')
	label_mock.should_receive(:event_router).twice.and_return(router_mock)
	Fluent::Engine.root_agent.labels['@mytest'] = label_mock
	d = Dummy.new
	d.configure(config_element('ROOT', '', {'@label' => '@mytest'}))
	router = d.event_emitter_router("@mytest")
	assert_equal router_mock, router
	end

, the tests will be passed.

[Watson1978]

Since doudou/flexmock@4c07690 commit, we can reproduce the problem...

どうやら BasicObject を使用した実装に変更されたことによって、以下の箇所の obj.class がおかしな挙動を示すようだ。

fluentd/lib/fluent/plugin/in_object_space.rb

Lines 68 to 77 in fd711c5

	ObjectSpace.each_object {|obj|
	klass = obj.class rescue Object
	if c = map[klass]
	c.incr!
	else
	c = Counter.new(klass, 1)
	array << c
	map[klass] = c
	end
	}

以下のコードで再現できる。

class CompositeExpectation < BasicObject
  def initialize
    @expectations = []
  end

  def method_missing(sym, *args, &block)
    @expectations.each do |expectation|
      expectation.send(sym, *args, &block)
    end
    self
  end
end

obj = CompositeExpectation.new

map = {}
map[obj.class] = "test"

$ ruby t.rb
t.rb:16:in '<main>': can't convert CompositeExpectation to Integer (CompositeExpectation#to_int gives CompositeExpectation) (TypeError)

map[obj.class] = "test"
    ^^^^^^^^^^^^^^^^^^^

このように想定外の例外が発生するようになってしまい、 on_timer で router.emit(@tag, now, record) が実行されなくなってしまった。

テストでは３回イベントが emit されることを期待しているのだが、router.emit(@tag, now, record) が実行されないのでタイムアウトが発生し続けるまで待ち続け、タイムアウトによりテストが失敗している。

fluentd/test/plugin/test_in_object_space.rb

Line 55 in fd711c5

d.run(expect_emits: 3)

test_event_emitter.rb と test_input.rb で Fluent::Engine.root_agent.labels['@mytest'] = label_mock のように flexmock で作成したオブジェクトを保持し続けているため、そのオブジェクトの参照が消えずオブジェクトが生き続けてしまい ObjectSpaceInputTest のテストで不必要に反応してしまうのが良くないのだろう。
テスト終了時に Fluent::Engine.root_agent.labels['@mytest'] に nil を代入するなどして参照関係を断ち切れば、flexmock オブジェクトが GC によって回収されるのでテストが成功するようになりそう。