Details

    • Number of attachments :
      0

      Description

      When open_timeout is exceeded the connection is still established even though it throws Timeout::Error, and the socket is left open. The following code will leave an established connection that you can see in netstat. Trying to call finish throws an IO error.

        begin
          puts 'STARTING CONNECTION'
          @conn = Net::HTTP.new("www.google.com",80)
          @conn.open_timeout = 0.001
          @conn.start
        rescue Timeout::Error => e
          puts 'CONNECTION TIMEOUT'
          #@conn.finish
          puts "CONNECTION FINISHED"
        end
        sleep 1000
      

        Issue Links

          Activity

          Hide
          Chris Ochs added a comment -

          FYI cruby 1.8.7 works correctly and does not leave an open connection.

          Show
          Chris Ochs added a comment - FYI cruby 1.8.7 works correctly and does not leave an open connection.
          Hide
          Chris Ochs added a comment -

          This is really strange. So the line in Net::HTTP that makes the socket connection is wrapped in a timeout like so:

          s = timeout(@open_timeout)

          { TCPSocket.open(conn_address(), conn_port()) }

          Timeout::Error is being thrown, but the socket still gets connected?

          Show
          Chris Ochs added a comment - This is really strange. So the line in Net::HTTP that makes the socket connection is wrapped in a timeout like so: s = timeout(@open_timeout) { TCPSocket.open(conn_address(), conn_port()) } Timeout::Error is being thrown, but the socket still gets connected?
          Hide
          Charles Oliver Nutter added a comment -

          If I'm reading this right, here's the netstat entry:

          tcp4       0      0  192.168.0.4.52299      74.125.225.114.80      TIME_WAIT
          

          On UNIX, sockets that are closed go into TIME_WAIT state to ensure all data has been sent, so it looks like this has been closed ok. Do you get something different?

          I also get the same error message with MRI 1.8.7 when I uncomment the "finish" line:

          system ~/projects/jruby $ jruby -rtimeout -rnet/http timeout_thing.rb 
          STARTING CONNECTION
          CONNECTION TIMEOUT
          IOError: HTTP session not yet started
            finish at /Users/headius/projects/jruby/lib/ruby/1.9/net/http.rb:820
            (root) at timeout_thing.rb:5
          
          system ~/projects/jruby $ ruby -rtimeout -rnet/http timeout_thing.rb 
          STARTING CONNECTION
          CONNECTION TIMEOUT
          /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/net/http.rb:602:in `finish': HTTP session not yet started (IOError)
          	from timeout_thing.rb:8
          

          I do not see the netstat entry, but it's possible your timeout is so short MRI hasn't even attempted to make the connection yet...

          Show
          Charles Oliver Nutter added a comment - If I'm reading this right, here's the netstat entry: tcp4 0 0 192.168.0.4.52299 74.125.225.114.80 TIME_WAIT On UNIX, sockets that are closed go into TIME_WAIT state to ensure all data has been sent, so it looks like this has been closed ok. Do you get something different? I also get the same error message with MRI 1.8.7 when I uncomment the "finish" line: system ~/projects/jruby $ jruby -rtimeout -rnet/http timeout_thing.rb STARTING CONNECTION CONNECTION TIMEOUT IOError: HTTP session not yet started finish at /Users/headius/projects/jruby/lib/ruby/1.9/net/http.rb:820 (root) at timeout_thing.rb:5 system ~/projects/jruby $ ruby -rtimeout -rnet/http timeout_thing.rb STARTING CONNECTION CONNECTION TIMEOUT /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/net/http.rb:602:in `finish': HTTP session not yet started (IOError) from timeout_thing.rb:8 I do not see the netstat entry, but it's possible your timeout is so short MRI hasn't even attempted to make the connection yet...
          Hide
          Charles Oliver Nutter added a comment -

          More eyes on this one (rather than JRUBY-6607) so I'm commenting here on the evenings explorations.

          JRuby 1.6 or 1.7 both appear to drop the connection just fine with no lingering TIME_WAIT state when running on Java 7. I'm starting to think there's some JVM bug or improvement at play.

          TIME_WAIT is the state that a socket goes into when closed if there's a possibility of packets still on the wire. It holds the socket in place to handle those rogue packets if they show up, and prevents additional connections that might be confused by those roque packets.

          The length of time a socket will be in TIME_WAIT is determined at the kernel or system-global level.

          I have read through MRI code again, and can't find anything they're doing to allow incomplete connections to disappear completely without TIME_WAIT. Evidence seems to be leading me to the conclusion that something OpenJDK/Sun JDK/Oracle JDK versions 1.6.x and lower are doing is causing these connections to hang around for a while.

          FWIW, I see the following line in rbx for the script from JRUBY-6607, which is also very confusing:

          vm      69644 headius    5u  IPv4 0xffffff8018dfb5e8        0t0      TCP 192.168.0.8:60211->10.255.255.1:http (SYN_SENT)
          

          I'm not sure how to proceed with either this one or JRUBY-6607 at this point. I have tried various combinations of socket flags, and nothing appears to change behavior. I've added additional layers of closing and finishing in RubyTCPSocket.initialize, and not had any luck. The only thing that works for me seems to be using Java 7.

          Can anyone else confirm this bug or JRUBY-6607 work as expected for them on Java 7 builds?

          Show
          Charles Oliver Nutter added a comment - More eyes on this one (rather than JRUBY-6607 ) so I'm commenting here on the evenings explorations. JRuby 1.6 or 1.7 both appear to drop the connection just fine with no lingering TIME_WAIT state when running on Java 7. I'm starting to think there's some JVM bug or improvement at play. TIME_WAIT is the state that a socket goes into when closed if there's a possibility of packets still on the wire. It holds the socket in place to handle those rogue packets if they show up, and prevents additional connections that might be confused by those roque packets. The length of time a socket will be in TIME_WAIT is determined at the kernel or system-global level. I have read through MRI code again, and can't find anything they're doing to allow incomplete connections to disappear completely without TIME_WAIT. Evidence seems to be leading me to the conclusion that something OpenJDK/Sun JDK/Oracle JDK versions 1.6.x and lower are doing is causing these connections to hang around for a while. FWIW, I see the following line in rbx for the script from JRUBY-6607 , which is also very confusing: vm 69644 headius 5u IPv4 0xffffff8018dfb5e8 0t0 TCP 192.168.0.8:60211->10.255.255.1:http (SYN_SENT) I'm not sure how to proceed with either this one or JRUBY-6607 at this point. I have tried various combinations of socket flags, and nothing appears to change behavior. I've added additional layers of closing and finishing in RubyTCPSocket.initialize, and not had any luck. The only thing that works for me seems to be using Java 7. Can anyone else confirm this bug or JRUBY-6607 work as expected for them on Java 7 builds?
          Hide
          Charles Oliver Nutter added a comment -

          The fixes for JRUBY-6607 appear to have fixed this as well.

          Show
          Charles Oliver Nutter added a comment - The fixes for JRUBY-6607 appear to have fixed this as well.

            People

            • Assignee:
              Charles Oliver Nutter
              Reporter:
              Chris Ochs
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: