Last Updated: February 25, 2016
·
12.78K
· abdollar

Ruby timeouts are dangerous

Ruby timeouts (specifically using the MRI - Ruby 1.8, 1.9 and 2.0) are dangerous. Use them cautiously or just avoid them. The following bugs show that there are a few race conditions related to timeouts. See https://bugs.ruby-lang.org/issues/4266 as well as https://bugs.ruby-lang.org/issues/7503.

Ruby timeouts create a thread for each and every timeout. This thread then sleeps for a given amount of time before the code calls yield on the block provided. Here is the snippet from ruby 2.0

See timeout.rb (https://github.com/ruby/ruby/blob/trunk/lib/timeout.rb#L50)

def timeout(sec, klass = nil)   #:yield: +sec+
   ...
       begin  
         x = Thread.current
         y = Thread.start { ...  }
         return yield(sec)
       ensure
         if y
           y.kill
           y.join # make sure y is dead.
         end
       end

Let's use the mysql2 gem in combination with timeouts to see how "dangerous" this really is.

Create a mysql database and populate it with a few rows

CREATE DATABASE testsql;
USE testsql;
CREATE TABLE statements (id INT);
INSERT INTO statements (id) VALUES(9);
INSERT INTO statements (id) VALUES(11);

Lets run some code with timeouts. Use rvm with ruby 2.0 or even 1.9

require 'timeout'
require 'mysql2'
client = Mysql2::Client.new(:host => 'localhost',
                                :database => 'testsql',
                                :username => 'root',
                                :password => '')  
begin
  Timeout.timeout(1) {
    results = client.query("select * from statements where id = 17")
    puts "outer:#{results.count}"
    while(true) do
      Timeout.timeout(0.0001) {
        results = client.query("select * from statements where id = 9")
        puts "inner:#{results.count}"
      }
      sleep 0.2
    end
  }
  rescue Timeout::Error
    results = client.query("select * from statements where id = 9")
    puts "timeout:#{results.count}"
  end

Run this a few times and you will see some weird results which are race conditions in the mysql2 gem. Sometimes you will see this

in `query': closed MySQL connection (Mysql2::Error)

or this

in `query': This connection is still waiting for a result, try again once you have the result (Mysql2::Error)

and sometimes it just works without any errors.

If you look deep inside the c code of the mysql2 gem you will notice wrapper->active_thread which will return nil if its not the active thread. See https://github.com/brianmario/mysql2/blob/master/ext/mysql2/client.c.

If you use ruby 2.0 and tracepoint you will notice something like this; where the code calls into and out of C code from multiple threads.

line    timeout  Timeout
line 
c-call query Mysql2::Client
c-call       sleep   Kernel
c-return       sleep   Kernel
line     timeout  Timeout
c-call      raise   Thread
c-call   exception Exception
c-call  initialize Exception
c-return  initialize Exception
c-return   exception Exception
c-return      raise   Thread
c-return      query Mysql2::Client
line     timeout  Timeout

In general, avoid timeouts or avoid doing too much within a timeout that involves C code and extensions that may have re-entrency issues.

If you use timeouts (and they are firing) then you are running a multi-threaded application.

This old blog post gives some better context and seems still relevant - http://headius.blogspot.com/2008/02/rubys-threadraise-threadkill-timeoutrb.html.