stream closed (IOError)

[Eric Will]

This code:

puts "closed?: %s" % @socket.closed?.to_s

begin
@socket.close
rescue Exception => e
return
rescue IOError => e
return
rescue Errno => e
return
end

outputs this:

closed?: false
/Users/rakaur/Sources/wc/ruby/synapse/trunk/lib/xmppd/xmpp/stream.rb:231:in
`ioloop': stream closed (IOError)
from /Users/rakaur/Sources/wc/ruby/synapse/trunk/lib/xmppd.rb:196:in `loop'
from /Users/rakaur/Sources/wc/ruby/synapse/trunk/lib/xmppd.rb:196:in `ioloop'
from ./bin/xmppd:20
praxis:trunk rakaur$

Latest stable Ruby (1.8.7-p72). I don't see how this is possible.
Google seems mostly silent on the matter unless you speak Japanese.

Any ideas?

 

[Eric Will]

Line 231 is the @socket.close line. Nothing gets done to the socket
after this, or if it is, it's not getting to it because it crashes on
@socket.close. Nothing should even be touching the entire object after
this, because it sets a flag saying "I'm dead, please GC me."

It's a large program, and the code is available at
http://synapse.malkier.net/browser. The socket closing is in
lib/xmppd/xmpp/stream.rb. The code right there doesn't have the
exception catching written in, because I removed the thing that causes
this to happen, which is this:

# Check for connection timeouts.
#Timer::Timer.new('check connection timeouts', 60, true) do
# $connections.each do |c|
# c.error('connection-timeout') if ($time - c.rtime) >= 30
# end

I'll try putting the exception around this. One second.

No, that doesn't work. Nor does this:

# Check for connection timeouts.
Timer::Timer.new('check connection timeouts', 60, true) do
$connections.each do |c|
next if c.dead? or c.socket.closed?
c.error('connection-timeout') if ($time - c.rtime) >= 30
end

The socket.closed? returns false, then ONE LINE LATER when I call
socket.close, the IOError is raised and cannot seem to be rescued.

Ok, I've updated the code in svn. Relevant files are
http://synapse.malkier.net/browser/trunk/lib/xmppd.rb (which is where
the Timer is started),
http://synapse.malkier.net/browser/trunk/lib/xmppd/timer.rb (which is
the Timers themselves), and
http://synapse.malkier.net/browser/trunk/lib/xmppd/xmpp/stream.rb
(which is where the socket is closing.

This code outputs this:

/Users/rakaur/Sources/wc/ruby/synapse/trunk/lib/xmppd/xmpp/stream.rb:230:in
`ioloop': stream closed (IOError)
from /Users/rakaur/Sources/wc/ruby/synapse/trunk/lib/xmppd.rb:197:in `loop'
from /Users/rakaur/Sources/wc/ruby/synapse/trunk/lib/xmppd.rb:197:in `ioloop'
from ./bin/xmppd:20

Perhaps it has to do with the timers running in a separate thread?
Putting begin/rescue in the tread doesn't catch it, either.

Thanks.

 

[Eric Will]

I don't think we can trust line numbers here, maybe due to bugs. The
back trace does not make sense at all.
[...]
stream.rb:230 is not within ioloop; xmppd:20 does not call ioloop.
The fact rescue does not catch the exception also suggest the wrong
line numbers. How about stopping using timer library, as a start?

Hey matz. Thanks for your help. Everything is within ioloop.
bin/xmppd:20 is `XMPPd.instance.ioloop`
When I don't use the timers, this doesn't happen. In fact, it doesn't
happen until I use that specific Timer to do connection timeouts in
lib/xmppd.rb.

matz.

-- Eric Will

 

[Iñaki Baz Castillo]

El Domingo, 5 de Octubre de 2008, Eric Will escribi=F3:

I don't think we can trust line numbers here, maybe due to bugs. The
back trace does not make sense at all.
[...]
stream.rb:230 is not within ioloop; xmppd:20 does not call ioloop.
The fact rescue does not catch the exception also suggest the wrong
line numbers. How about stopping using timer library, as a start?

Hey matz. Thanks for your help. Everything is within ioloop.
bin/xmppd:20 is `XMPPd.instance.ioloop`
When I don't use the timers, this doesn't happen. In fact, it doesn't
happen until I use that specific Timer to do connection timeouts in
lib/xmppd.rb.

Not sure if your problem could be related to this post:

http://blog.headius.com/2008/02/rubys-threadraise-threadkill-timeoutrb.html




=2D-=20
I=F1aki Baz Castillo

 

[Eric Will]

Not sure if your problem could be related to this post:

http://blog.headius.com/2008/02/rubys-threadraise-threadkill-timeoutrb.ht=

ml

Not sure I grasp everything going on there. I don't use threads for
anything EXCEPT running my timers, which use Timeout. This could
potentially be the culprit, but I have no idea how that helps me.
Trying to rescue the IOError in my Timer library hasn't worked,
either.

matz, any input on this?

Thanks guys.

-- Eric Will

 

[Eric Will]

Since I still can not reproduce the problem, I can not say clearly, but:

* timer callback may touch the socket right after it's closed.
* you've mixed fork and threads, which may not work properly.
* you don't need timeout.rb. try attached simpler version.

Thanks. I should have thought of that to begin with.

It doesn't have to do with fork. In all my tests I run it with
--nofork (which skips forking). The only thing using threads was
timer.rb.

Googling found me some Japanese posts, but that didn't help. The rest
seemed to be fixed by checking socket#closed? first.

Thanks so much.

matz.

-- Eric Will

 

[Eric Will]

Show me the URL if you need further info, since I can read some
Japanese. ;-)

I'm not sure if these are relevant, since Google now shows lots of
this thread.

http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/ruby-dev/7000
http://133.44.98.95/cgi-bin/vframe.rb/ruby/ruby-list/31677?31634-32001
http://www.rubyist.net/~nobu/t/20031028.html
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/ruby-list/31645

matz.

-- Eric Will

 

[Eric Will]

* you don't need timeout.rb. try attached simpler version.

While simpler version, this causes the same error...

matz.

-- Eric Will

 

[Eric Will]

Hmm, let's step forward one by one. You have two timers, which one is
causing the problem? What if wrapping timer callbacks with begin and
rescue?

I've tried wrapping the start method in timer.rb, wrapping the Timer
callbacks outside of "Timer.new" and inside of "Timer.new" (ie, part
of the callback), and none of these rescue it. When I wrap the call to
ioloop (which is the ENTIRE program, basically) it catches it... which
doesn't really narrow it down much.

I'm trying as I'm writing this, so bare with me for a moment...
wrapping c.read in lib/xmppd.rb catches it... wrapping parse in
Stream#read with it does NOT catch it. So it's somewhere between
Stream#read's call to Stream#parse.

matz.

I'll keep playing with this, but I don't know that I'm getting very
far... I still think it has something to do with threads.

-- Eric Will

 

[Eric Will]

I'll keep playing with this, but I don't know that I'm getting very
far... I still think it has something to do with threads.

Yeah, that's as far as I can get. Wrapping different parts of
Stream#read doesn't catch it.

This seems impossible unless it's something to do with threads, which
I know next to nothing about.

I was going to try with ruby1.9, but the IDN gem doesn't work.

-- Eric Will