Bug #19996: `RUBY_MN_THREADS=1` triggers Action Cable unit test failures

• Status: Closed
• Assignee: ko1 (Koichi Sasada)
• Target version: -
• ruby -v: ruby 3.3.0dev (2023-11-09T16:24:15Z :detached: c49adfab5d) +MN [x86_64-linux]
• Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN

[yahonda (Yasuo Honda)]

Steps to reproduce

1. Install ruby 3.3.0dev
2. Set RUBY_MN_THREADS=1 environment variable
3. Follow these steps

git clone https://github.com/rails/rails
cd rails
rm Gemfile.lock
bundle install
cd actioncable
bin/test test/channel/base_test.rb test/subscription_adapter/redis_test.rb test/channel/test_case_test.rb test/subscription_adapter/redis_test.rb test/client_test.rb --seed 14800

Expected behavior

It should pass as not setting RUBY_MN_THREADS.

$ unset RUBY_MN_THREADS
$ bin/test test/channel/base_test.rb test/subscription_adapter/redis_test.rb test/channel/test_case_test.rb test/subscription_adapter/redis_test.rb test/client_test.rb --seed 14800
/home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/minitest-5.20.0/lib/minitest.rb:3: warning: mutex_m which will no longer be part of the default gems since Ruby 3.4.0. Add mutex_m to your Gemfile or gemspec.
Run options: --seed 14800

# Running:

.........................................................................

Finished in 12.031310s, 6.0675 runs/s, 46.7115 assertions/s.
73 runs, 562 assertions, 0 failures, 0 errors, 0 skips
$

Actual behavior

It usually fails as follows.

$ bin/test test/channel/base_test.rb test/subscription_adapter/redis_test.rb test/channel/test_case_test.rb test/subscription_adapter/redis_test.rb test/client_test.rb --seed 14800
/home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/minitest-5.20.0/lib/minitest.rb:3: warning: mutex_m which will no longer be part of the default gems since Ruby 3.4.0. Add mutex_m to your Gemfile or gemspec.
Run options: --seed 14800

# Running:

..................................................F

Failure:
RedisAdapterTest::AlternateConfiguration#test_channel_prefix [/home/yahonda/src/github.com/rails/rails/actioncable/test/subscription_adapter/common.rb:35]:
Expected #<Concurrent::Event:0x00007f0b2698d4f0 @__Lock__=#<Thread::Mutex:0x00007f0b26f8cab8>, @__Condition__=#<Thread::ConditionVariable:0x00007f0b26f8ca90>, @set=false, @iteration=0> to be set?.


bin/test test/subscription_adapter/channel_prefix.rb:6

.F

Failure:
RedisAdapterTest::AlternateConfiguration#test_multiple_broadcast [/home/yahonda/src/github.com/rails/rails/actioncable/test/subscription_adapter/common.rb:35]:
Expected #<Concurrent::Event:0x00007f0b2698a4d0 @__Lock__=#<Thread::Mutex:0x00007f0b26fac688>, @__Condition__=#<Thread::ConditionVariable:0x00007f0b26fac4f8>, @set=false, @iteration=0> to be set?.


bin/test test/subscription_adapter/common.rb:74

E

Error:
ClientTest#test_interacting_clients:
ThreadError: queue empty
    <internal:thread_sync>:18:in `pop'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:168:in `read_message'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:241:in `block (2 levels) in test_interacting_clients'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:218:in `block (2 levels) in concurrently'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/promises.rb:1583:in `evaluate_to'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/promises.rb:1766:in `block in on_resolvable'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `run_task'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:343:in `block (3 levels) in create_worker'
    <internal:kernel>:187:in `loop'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block (2 levels) in create_worker'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `catch'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `block in create_worker'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/promises.rb:1258:in `raise'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/promises.rb:1258:in `wait_until_resolved!'
    /home/yahonda/.rbenv/versions/trunk/lib/ruby/gems/3.3.0+0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/promises.rb:988:in `value!'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:218:in `map'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:218:in `concurrently'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:240:in `block in test_interacting_clients'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:90:in `with_puma_server'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:234:in `test_interacting_clients'


bin/test test/client_test.rb:233

E

Error:
ClientTest#test_disappearing_client:
ThreadError: queue empty
    <internal:thread_sync>:18:in `pop'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:168:in `read_message'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:275:in `block in test_disappearing_client'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:90:in `with_puma_server'
    /home/yahonda/src/github.com/rails/rails/actioncable/test/client_test.rb:273:in `test_disappearing_client'


bin/test test/client_test.rb:272

..................

Finished in 1323.812615s, 0.0551 runs/s, 0.3830 assertions/s.
73 runs, 507 assertions, 2 failures, 2 errors, 0 skips
$

[yahonda (Yasuo Honda)]

• Description updated (diff)

[yahonda (Yasuo Honda)]

• Description updated (diff)

[hsbt (Hiroshi SHIBATA)]

• Status changed from Open to Assigned
• Assignee set to ko1 (Koichi Sasada)

[ko1 (Koichi Sasada)]

Re-checked on 2026-09-08.

Not reproducible on current master (4d185cce78, ruby 4.1.0dev).

To make sure my environment can actually show the bug, I reconstructed the
original setup: Rails 8c593873a5 (2023-11-09) with its committed Gemfile.lock
(puma 6.3.0, nio4r 2.5.9, redis 5.0.5, concurrent-ruby 1.2.2), redis-server 7,
and Ruby built at c2a8141634 (3.3.0dev 2023-11-08), the same revision as in the
report. Command and seed as reported.

ruby rails / gems MN off MN on
c2a8141634 2023 rails / 2023 lock 0/3 fail 5/5 fail
3.3.0 release 2023 rails / 2023 lock 0/3 fail 4/5 fail
master 4d185cce78 2023 rails / 2023 lock* - no MN-specific failure (0/8)
master 4d185cce78 rails main / current gems 0/10 fail 0/10 fail

c2a8141634 2023 rails / current gems 0/3 fail 0/5 fail

The failures I reproduced are #1 and #2 of the report,
RedisAdapterTest::AlternateConfiguration#test_channel_prefix and
#test_multiple_broadcast ("Expected Concurrent::Event to be set?"), sometimes
also #test_subscribe_and_unsubscribe. The ClientTest "ThreadError: queue empty"
errors (#3 and #4) did not appear in my environment.

Two things worth noting:

• The gem generation matters more than Ruby here. With today's gems, even the
  originally reported Ruby revision passes (last row). So the bug is only
  visible with the 2023 gem set.

• (*) For the master row I had to bump nio4r (2.5.9 -> 2.7.5), stringio and ffi,
  because they do not build on Ruby 4.1. nio4r is the IO loop Action Cable
  actually runs on, so I cannot fully separate "Ruby fixed it" from "nio4r
  changed". The single failure remaining on master
  (BaseTest#test_does_not_log_filtered_parameters) is the Ruby 3.4 Hash#inspect
  format change and happens with and without RUBY_MN_THREADS=1.

Given that it no longer reproduces on master, I close this, but
please reopen if you can reproduce the issue.

[ko1 (Koichi Sasada)]

• Status changed from Assigned to Closed