Bug #13106: Timeout does not wait for more than 120 seconds

• Status: Rejected
• Assignee: -
• Target version: -
• ruby -v: ruby 2.3.0p0 (2015-12-25 revision 53290) [x86_64-linux]
• Backport: 2.2: UNKNOWN, 2.3: UNKNOWN, 2.4: UNKNOWN

[141984 (Gibu John George)]

Hi All,

I have encountered an issue where Timeout does not wait for more than 120 seconds when asked to wait for a greater period.

This is my ruby code, that supposed to wait for 250 seconds to check if an application deployed on tomcat is up or not. As seen in the logs, it exits are 120 seconds.

require 'timeout'
require 'socket'
require 'net/http'

ip = '127.0.0.1'
port = '8080'
url = 'http://127.0.0.1:8080/myApp/isUp'


  def wait_till_port_open(ip, port)
    TCPSocket.new(ip, port).close
    puts "#{port} is open"
    return true
  rescue Errno::ECONNREFUSED, Errno::EHOSTUNREACH, Errno::EADDRNOTAVAIL
    return false
  end

  def wait_till_port_close(ip, port)
    TCPSocket.new(ip, port).close
    puts "#{port} is open"
    return false
  rescue Errno::ECONNREFUSED, Errno::EHOSTUNREACH, Errno::EADDRNOTAVAIL
    return true
  end

  def wait_till_app_up(url)
    resp_code = Net::HTTP.get_response(URI.parse(url.to_s)).code
    if resp_code.eql?('200')
      puts 'Application is up'
      return true
    end
  rescue Errno::ECONNREFUSED, Errno::EHOSTUNREACH
    return false
  end

begin
  Timeout::timeout(250) do
    until wait_till_port_open(ip, port)
    end
  end
rescue Timeout::Error
  abort("Port #{port} not up after 250 seconds")
end
puts Time.now
begin
  Timeout::timeout(250) do
    until wait_till_app_up(url)
    end
  end
rescue Timeout::Error
  puts Time.now
  abort("Application #{url} not up after 250 seconds")
end

8080 is open
2017-01-05 13:58:49 +0530
sec : 250      -> added a puts at https://github.com/ruby/ruby/blob/0d74082eced0254a30b8f09a4d65fff357fdc6cd/lib/timeout.rb#L84 to ensure that value is correctly being passed.
2017-01-05 14:00:50 +0530

Why is this happening? Any fixes for this?

[141984 (Gibu John George)]

sorry. missed the last line of my output

8080 is open
2017-01-05 13:58:49 +0530
sec : 250      -> added a puts at https://github.com/ruby/ruby/blob/0d74082eced0254a30b8f09a4d65fff357fdc6cd/lib/timeout.rb#L84 to ensure that value is correctly being passed.
2017-01-05 14:00:50 +0530
Application http://127.0.0.1:8080/myApp/isUp not up after 250 seconds

[dstosik (David Stosik)]

I think this is not a bug.

It looks like you are catching the Timeout::Error raised by Net::HTTP.get_response.

Here is a sample code to illustrate this:

require 'timeout'
require 'benchmark'
require 'net/http'

puts Benchmark.measure {
  begin
    Timeout::timeout(250) do
      up = false
      until up
        # my server sleeps, never answers, and triggers a timeout
        code = Net::HTTP.get_response(URI.parse("http://localhost:3000/")).code
        up = code.eql?("200")
      end
    end
  rescue Timeout::Error => e
    puts "Rescued Timeout error: #{e}"
  end
}

And the result:

Rescued Timeout error: Net::ReadTimeout
  0.000000   0.000000   0.000000 (120.009394)

The Net::ReadTimeout (which inherits of Timeout::Error) was raised by Net::HTTP.get_response after 120s waiting, then rescued.

In order for your code to work as you expect it, you need to rescue once from Timeout::Error inside wait_till_app_up and return false. Then you'll be sure that the Timeout::Error you rescue at the end of your code comes from your Timeout::timeout(250) do block.

[jeremyevans0 (Jeremy Evans)]

• Status changed from Open to Rejected