IOError: closed stream

IOError: closed stream

[David Judd]

I'm getting "IOError: closed stream" from inside Unicorn occasionally
and I don't know what to make of it. The stack trace looks like this:

unicorn (4.5.0) lib/unicorn/stream_input.rb:129:in `kgio_read' unicorn
(4.5.0) lib/unicorn/stream_input.rb:129:in `read_all' unicorn (4.5.0)
lib/unicorn/stream_input.rb:60:in `read' unicorn (4.5.0)
lib/unicorn/tee_input.rb:84:in `read'
config/initializers/rack_request.rb:19:in `POST' rack (1.4.5)
lib/rack/request.rb:221:in `params'

Any suggestions what this might indicate? Is this what I should
legitimately expect to see if the browser closes the connection
abruptly?

It's happening only for POSTs, and a small percentage of them, but I
can't find any further pattern - a variety of content, usually quite
small content-lengths.

Currently we're running nginx in front of unicorn via a unix socket.
In this state the errors occur at an almost-negligible rate. I
experimented yesterday with moving instead to nginx in front of
varnish, on a separate machine, with varnish then talking to unicorn
via a TCP socket. In that configuration the errors increased
dramatically, although the majority of requests still succeeded.

As you can see we're running unicorn 4.5 and rack 1.4.5 - except that
I'm monkey-patching Rack::Request to backport the 1.5 POST method,
which transforms an earlier nil error in to this one. (On Ruby 2.0.0,
on an Ubuntu-precise box on AWS.)

Any relevant info or suggestions would be appreciated.

Apologies if this shows up as a double-post--my first attempt seems to
have been rejected because I didn't turn on plain text mode.

Thanks,
David
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: IOError: closed stream

[Eric Wong]

David Judd <david@academia.edu> wrote:
> I'm getting "IOError: closed stream" from inside Unicorn occasionally
> and I don't know what to make of it. The stack trace looks like this:
> 
> unicorn (4.5.0) lib/unicorn/stream_input.rb:129:in `kgio_read' unicorn
> (4.5.0) lib/unicorn/stream_input.rb:129:in `read_all' unicorn (4.5.0)
> lib/unicorn/stream_input.rb:60:in `read' unicorn (4.5.0)
> lib/unicorn/tee_input.rb:84:in `read'
> config/initializers/rack_request.rb:19:in `POST' rack (1.4.5)
> lib/rack/request.rb:221:in `params'
> 
> Any suggestions what this might indicate? Is this what I should
> legitimately expect to see if the browser closes the connection
> abruptly?

Not a client closing the connection, that would be EOFError,
Errno::ECONNRESET or another Errno::...

IOError means something in the unicorn process closed the connection
already, which should not happen there.

Do you have anything in your Rack app which does background processing
of rack.input after the response is written?

That would be the most likely explanation...

> It's happening only for POSTs, and a small percentage of them, but I
> can't find any further pattern - a variety of content, usually quite
> small content-lengths.
> 
> Currently we're running nginx in front of unicorn via a unix socket.
> In this state the errors occur at an almost-negligible rate. I
> experimented yesterday with moving instead to nginx in front of
> varnish, on a separate machine, with varnish then talking to unicorn
> via a TCP socket. In that configuration the errors increased
> dramatically, although the majority of requests still succeeded.

If varnish is used, your nginx -> varnish -> unicorn is what I would
recommend (not that I have much experience with varnish, but I when I
last looked at them, nginx was better at handling slow/idle
connections).

That said, I'm not sure what could cause the increase in errors...
Is varnish attempting to pre-connect?

Can you reproduce this error on a minimal Rack app from a client
you control?

> As you can see we're running unicorn 4.5 and rack 1.4.5 - except that
> I'm monkey-patching Rack::Request to backport the 1.5 POST method,
> which transforms an earlier nil error in to this one. (On Ruby 2.0.0,
> on an Ubuntu-precise box on AWS.)

For the mimimal rack test app, try just an unpatched Rack,
there could be a subtle compatibility problems from the monkey patch.

The basic idea is to eliminate variables and strange/uncommon things to
pinpoint the problem.

> Any relevant info or suggestions would be appreciated.

Since you're on 4.5, it would not be via rack.hijack ...

I'm not ruling out a bug in unicorn, but I don't think we've heard of
this problem before.  The code for handling rack.input hasn't been
changed much, either.  I beat the crap out of it, but usually for PUT
requests (but not using POST in Rack::Request).

> Apologies if this shows up as a double-post--my first attempt seems to
> have been rejected because I didn't turn on plain text mode.

Only saw this one.  You can check on gmane.comp.lang.ruby.unicorn.general
or http://rubyforge.org/pipermail/mongrel-unicorn
Mailman should be converting HTML to plain-text, but maybe it fails
sometimes...  I'd rather deal with an occasional double post than every
message being 2-3 times bigger due to HTML.
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: IOError: closed stream

[David Judd]

>
> Do you have anything in your Rack app which does background processing
> of rack.input after the response is written?
> That would be the most likely explanation...

Not that I'm aware of, and I can't find any references to rack.input
in our codebase aside from the monkeypatch.

> If varnish is used, your nginx -> varnish -> unicorn is what I would
> recommend (not that I have much experience with varnish, but I when I
> last looked at them, nginx was better at handling slow/idle
> connections).
> That said, I'm not sure what could cause the increase in errors...
> Is varnish attempting to pre-connect?

I realized when I was seeing the errors en masse, I was actually just
running varnish->unicorn, no nginx--I hadn't finished the switch to
nginx->varnish->unicorn which we had planned.

> Can you reproduce this error on a minimal Rack app from a client
> you control?

I'll give it a shot when I have some time, but suspect it will be
tough. Even with the 'bad' setup, it's an infrequent error with
production traffic that's pretty high-volume.

I'll also (actually, probably sooner) actually try the configuration
of nginx->varnish->unicorn. If that works, or mostly works, I may not
be able to justify investing the time to dig into this further.

> For the mimimal rack test app, try just an unpatched Rack,
> there could be a subtle compatibility problems from the monkey patch.
> The basic idea is to eliminate variables and strange/uncommon things to
> pinpoint the problem.

With an unpatched Rack, I get a NoMethodError due to
Rack::Request#POST returning nil. I think there's a one-to-one
correspondence between when one error would occur and when the other
would, but I can't confirm that - one started appearing as soon as the
other disappeared, at roughly the same rate. The seemingly relevant
commit (although the justification for the change doesn't seem
related): https://github.com/rack/rack/commit/b0593078ce792a380779528a6a135c066aa03515

Thanks,
David

On Tue, Sep 24, 2013 at 9:02 AM, David Judd <david@academia.edu> wrote:
> I'm getting "IOError: closed stream" from inside Unicorn occasionally
> and I don't know what to make of it. The stack trace looks like this:
>
> unicorn (4.5.0) lib/unicorn/stream_input.rb:129:in `kgio_read' unicorn
> (4.5.0) lib/unicorn/stream_input.rb:129:in `read_all' unicorn (4.5.0)
> lib/unicorn/stream_input.rb:60:in `read' unicorn (4.5.0)
> lib/unicorn/tee_input.rb:84:in `read'
> config/initializers/rack_request.rb:19:in `POST' rack (1.4.5)
> lib/rack/request.rb:221:in `params'
>
> Any suggestions what this might indicate? Is this what I should
> legitimately expect to see if the browser closes the connection
> abruptly?
>
> It's happening only for POSTs, and a small percentage of them, but I
> can't find any further pattern - a variety of content, usually quite
> small content-lengths.
>
> Currently we're running nginx in front of unicorn via a unix socket.
> In this state the errors occur at an almost-negligible rate. I
> experimented yesterday with moving instead to nginx in front of
> varnish, on a separate machine, with varnish then talking to unicorn
> via a TCP socket. In that configuration the errors increased
> dramatically, although the majority of requests still succeeded.
>
> As you can see we're running unicorn 4.5 and rack 1.4.5 - except that
> I'm monkey-patching Rack::Request to backport the 1.5 POST method,
> which transforms an earlier nil error in to this one. (On Ruby 2.0.0,
> on an Ubuntu-precise box on AWS.)
>
> Any relevant info or suggestions would be appreciated.
>
> Apologies if this shows up as a double-post--my first attempt seems to
> have been rejected because I didn't turn on plain text mode.
>
> Thanks,
> David
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying