TimerTask uses timeout interval

[lmarburger]

Fixes #525. I modified the existing timeout spec to execute immediately and asserts that a timeout occurs but I could just as easily create a new spec to test this behavior.

[jdantonio]

This change makes the test invalid. The idea here is this:

1. Create a task that begins its execution 0.1 seconds after creation.
2. Tell the task to issue a timeout error if the task does not complete after 0.1 seconds.
   • The timeout error should be issued 0.2 seconds after subject.execute is called.
3. Add an observer to track the results.
4. Execute the task, beginning the 0.1 second timer before the block is run.
5. Wait 1.0 seconds then check for a timeout.

Since the total time of the task should be approximately 0.2 seconds, we should see the timeout error before the countdown latch expires. If we change the execution_interval to 500 seconds then the block will not execute before the latch expires. We should not see a timeout error. The fact that the test passes indicates an error, but I believe the error is with the handling of timeout_interval and not execution_interval.

I'll look at this in more detail over the weekend.

[lmarburger]

Thanks for that extremely detailed description. That makes sense.

Here's a failing test that better exposes the bug I'm seeing with timeout_interval not being used.

it 'should not timeout' do
  subject = TimerTask.new(execution: 0.1, timeout: 1) { sleep(0.5); 42 }
  subject.add_observer(observer)
  subject.execute
  observer.latch.wait(2)
  expect(observer.ex).to be_nil
  expect(observer.value).to eq(42)
  subject.kill
end

# Failures:
# 
#   1) Concurrent::TimerTask observation should not timeout
#      Failure/Error: expect(observer.ex).to be_nil
#        expected: nil
#             got: #<Concurrent::TimeoutError: Concurrent::TimeoutError>
#      # ./spec/concurrent/timer_task_spec.rb:250:in `block (3 levels) in <module:Concurrent>'

Execute a task every 0.1s that takes 0.5s to complete with a 1s timeout. This task will be timed out after 0.1s because execution_interval is used to trigger the timeout.

My modification of the existing timeout test was to expose the other side of this same bug. Create a long-running task that runs immediatley with a short timeout_interval and long enough execution_interval to make it clear it won't be run more than once during the test. I expect the task to time out after timeout_interval is exceeded but the result is the test will fail after waiting for the task to complete.

[waynerobinson]

We have exactly the same problem.

If you look over the project you'll see that the value for timeout_interval isn't being used at all.

In our particular case it is causing thread leaking because the timeout_task just keeps scheduling new executions even though the original task is still running (because nothing actually seems to kill the running task).

And because the timeout is happening at the execution_interval, rather than the timeout_interval we're having problems.

[waynerobinson]

For example, we have the following code in https://github.com/phstc/shoryuken causing a thread-leaking issue: ruby-shoryuken/shoryuken#338

HEARTBEAT_INTERVAL = 0.1
@heartbeat = Concurrent::TimerTask.new(run_now: true,
                                       execution_interval: HEARTBEAT_INTERVAL,
                                       timeout_interval: 60) { dispatch }

Sometimes dispatch can take 20+ seconds to execute.

Because the timeout_interval is never actually used, the task is being rescheduled every 0.1 seconds.

By the time the job gets around to being executed again, there are 200 extra requests waiting to be run and this just repeats ad-infinitum until the process runs out of threads.

[pitr-ch]

I am closing this PR and I'll fix #525 in a different PR.

[pitr-ch]

@waynerobinson Thanks for letting us know about the leaking threads, that's serious I have a look.