Timeout running condition variable signal_spec.rb

[seven1m]

Timeout::Error: execution expired running: spec/core/conditionvariable/signal_spec.rb

[seven1m]

Probably a duplicate of #1966 but I'm leaving it here because the error is slightly different and I want double the satisfaction for fixing it. 😃

[seven1m]

I worked on this a bit this morning. I got a smaller reproduction of the issue, though it still takes about 5 minutes of repeatedly running with multiple processes to trigger the bug.

I marked the place in the code where the thread never joins.

m = Mutex.new
cv = ConditionVariable.new
repeats = 25
in_synchronize = false

t1 = Thread.new do
  m.synchronize do
    in_synchronize = true
    repeats.times do
      cv.wait(m)
      cv.signal
    end
  end
end

# Make sure t1 is waiting for a signal before launching t2.
Thread.pass until in_synchronize
Thread.pass until t1.stop?

t2 = Thread.new do
    m.synchronize do
      repeats.times do
      cv.signal
      cv.wait(m)
    end
  end
end

puts 'stuck here?'

# Check that both threads terminated without exception
t1.join # <================================================== NEVER JOINS

puts 'stuck here?'
t2.join
p m.locked?

[seven1m]

With this code:

m = Mutex.new
cv = ConditionVariable.new
repeats = 5
in_synchronize = false

t1 = Thread.new do
  m.synchronize do
    in_synchronize = true
    repeats.times do
      puts 't1 wait'
      cv.wait(m)
      puts 't1 signal'
      cv.signal
    end
  end
end

# Make sure t1 is waiting for a signal before launching t2.
Thread.pass until in_synchronize
Thread.pass until t1.stop?

t2 = Thread.new do
  m.synchronize do
    repeats.times do
      puts 't2 signal'
      cv.signal
      puts 't2 wait'
      cv.wait(m)
    end
  end
end

puts 'stuck here?'

# Check that both threads terminated without exception
t1.join # <================================================== NEVER JOINS
puts 'stuck here?'
t2.join
#puts 'stuck here?'
p m.locked?

When the process eventually hangs -- this took way longer to reproduce because all the printing seems to make it more stable -- it produces this output:

t1 wait
stuck here?
t2 signal
t2 wait
t1 signal
t1 wait
t2 signal
t2 wait
t1 signal
t1 wait
t2 signal
t2 wait
t1 signal
t1 wait
t2 signal
t2 wait

[seven1m]

This is what is happening here.

Thread 2 calls ConditionVariable#wait which uses Mutex#sleep internally. Mutex#sleep calls Mutex#unlock followed by Thread#sleep. But before Thread#sleep does its thing, Thread 1 gets unlocked and sends a Thread#wakeup to Thread 2. But since Thread 2 isn't yet sleeping, that wakeup gets lost and the thread gets stuck forever.

thread 1                       thread 2
==========================     ==========================
ConditionVariable#wait
  Mutex#sleep
    Mutex#unlock
    Thread#sleep
                               ConditionVariable#signal
                                 Thread#wakeup
                               ConditionVariable#wait
                                 Mutex#sleep
                                 Mutex#unlock
# thread 1 gets woken up
# before thread 2 sleeps
ConditionVariable#signal
  Thread#wakeup
                                 Thread#sleep