Bug #86764 for POEx-HTTP-Server: "New request while we still have a request" leads to fatal error

Sun Jul 07 18:48:48 2013 dzsbsd [...] gmail.com - Ticket created

Subject:	"New request while we still have a request" leads to fatal error
Date:	Sun, 7 Jul 2013 15:48:33 -0700
To:	bug-POEx-HTTP-Server [...] rt.cpan.org
From:	Dzs Bsd <dzsbsd [...] gmail.com>

Using POEx::HTTP::Server v0.0901 with perl 5.8.8, the logic behind pending_push() / pending_next() seems incomplete because reset_req() is not called after the first response completes. As such, the second response leads to the server dying: "Responding more then once to a request at POEx/HTTP/Server.pm line 1048" The problem can be trivially created by sending two pipelined requests on the same socket connection: { printf "GET /one HTTP/1.1\nHost:server\n\nGET /two HTTP/1.1\nHost:server\n\n";sleep 1; } | nc server 8080 This demonstration requires a sleep because POEx:HTTP doesn't itself respond if the client closes its connection first (which looks to be another bug for you to fix). The following patch seems to correct an obvious part of the "new request" problem. The warn "New request while we still have a request" could also be removed. --- POEx/HTTP/Server.pm +++ POEx/HTTP/Server.pm @@ -1369,6 +1369,7 @@ { my( $self ) = @_; return unless $self->{pending} and @{ $self->{pending} }; + $self->reset_req; if( $self->{S}{shutdown} or $self->{S}{closing} ) { $self->D( "We are closing down with pending requests" ); $self->pending_reply;

Mon Jul 08 03:13:07 2013 perl [...] pied.nu - Correspondence added

On Sun Jul 07 18:48:48 2013, dzsbsd@gmail.com wrote: Show quoted text

>"Responding more then once to a request at > POEx/HTTP/Server.pm line 1048"

Unfortunatly, I can't reproduce this problem. What's more, I can't see how you have this problem due to my code. Client->respond sets {once} to 1, Client->reset_req sets it back to 0. So the error message you quote can only appear if Client->respond is called a second time before Client->reset_req is called. Client->reset_req is called from Client->input, which is called from (in this case) from Client->pending_next, which is called from Client->flushed, which happens when the Wheel flushes the response. I other words, Client->reset_req is called on a flushed event. So I strongly suspect your second Client->respond is not from the second request but from a bug in your code. Either that or it is a subtle timing issue and my dev server isn't fast enough to trigger it. Can you turn on cookie crumbs in your code? Setting DEBUG to 1 at the top of Server.pm will do so in POEx::HTTP::Server. In particular, a ->respond can come from multiple sources. We need to find out where the first and second one is coming from and why. Either that, or I'm missing something. Show quoted text

> This demonstration requires a sleep because POEx:HTTP doesn't itself > respond if the client closes its connection first (which looks to be > another bug for you to fix).

This is a feature. Why send a response over a connection we already know is closed?

Mon Jul 08 03:13:07 2013 The RT System itself - Status changed from 'new' to 'open'

Mon Jul 08 23:59:58 2013 dzsbsd [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #86764] "New request while we still have a request" leads to fatal error
Date:	Mon, 8 Jul 2013 20:59:45 -0700
To:	bug-POEx-HTTP-Server [...] rt.cpan.org
From:	Dzs Bsd <dzsbsd [...] gmail.com>

On Mon, Jul 8, 2013 at 12:13 AM, Philip Gwyn via RT < bug-POEx-HTTP-Server@rt.cpan.org> wrote: Show quoted text

> Unfortunatly, I can't reproduce this problem. What's more, I can't see > how you have this problem due to my code. >

If second pipelined request is malformed (eg: where the server would normally respond "Bad request"), then it dies as I described. Try this (with the server configured for "keepalive"): { printf "GET /one HTTP/1.1\nHost:server\n\nBad:Request\n\n"; sleep 1; } | nc server 8080 I thought it failed with two "good" requests, but I may be mistaken and cannot reproduce that problem now. Show quoted text

> This demonstration requires a sleep because POEx:HTTP doesn't itself

> > respond if the client closes its connection first (which looks to be > > another bug for you to fix).

> This is a feature. Why send a response over a connection we already know > is closed? >

The connection is *half closed*. The client is no longer writing but it is reading. RFC 2616 doesn't seem clear on this detail, though the Apache HTTP server seems to support it. Some load balancer heath checks also use this "half-close" trick (perhaps because it works with Apache).

Tue Jul 09 11:33:53 2013 perl [...] pied.nu - Correspondence added

On Mon Jul 08 23:59:58 2013, dzsbsd@gmail.com wrote: Show quoted text

> { printf "GET /one HTTP/1.1\nHost:server\n\nBad:Request\n\n"; sleep 1; } | > nc server 8080

Well, there's your problem; just don't send bad requests! Seriously, this is something I can fix, as I can reproduce it. Thank you for finding this bug. Could you test out the following dist to see if it fixes it to your satisfaction. http://pied.nu/Perl/POEx-HTTP-Server-0.0902-rc4.tar.gz Show quoted text

> The connection is *half closed*. The client is no longer writing but it is > reading. RFC 2616 doesn't seem clear on this detail, though the Apache HTTP > server seems to support it. Some load balancer heath checks also use this > "half-close" trick (perhaps because it works with Apache).

OK, now I'm confused. Did you mean closed as in "TCP connection closed" or as in "HTTP Close: header was sent" ? In the latter case, yes a response should be sent. In the former... I don't see how a response could be sent.

Wed Jul 10 22:47:18 2013 dzsbsd [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #86764] "New request while we still have a request" leads to fatal error
Date:	Wed, 10 Jul 2013 19:46:57 -0700
To:	bug-POEx-HTTP-Server [...] rt.cpan.org
From:	Dzs Bsd <dzsbsd [...] gmail.com>

On Tue, Jul 9, 2013 at 8:33 AM, Philip Gwyn via RT < bug-POEx-HTTP-Server@rt.cpan.org> wrote: Show quoted text

> Could you test out the following dist to see if it fixes it to your > satisfaction. > http://pied.nu/Perl/POEx-HTTP-Server-0.0902-rc4.tar.gz

Yes, this fixes the crash with my bad pipelined requests. Thanks. Show quoted text

> OK, now I'm confused. Did you mean closed as in "TCP connection closed" > or as in "HTTP Close: header was sent" ? In the latter case, yes a > response should be sent. In the former... I don't see how a response could > be sent. >

I'm referring to just the TCP connection being half closed, not a HTTP "Connection" header. Version 0.0902-rc4 does change the behavior so responses from the following are received reliably. Nice work! printf "GET /a HTTP/1.1\nHost:localhost\n\nGET /b HTTP/1.1\nHost:localhost\n\n" | time nc localhost 8080 5.14 real 0.00 user 0.00 sys However, the server waits keepalivetimeout seconds (5) before finally closing its response connection. This wait is unnecessary because the client closed its request side earlier. The same test with an Apache server closes immediately after the last response (eg: 0.00 real).

Wed Jul 10 23:03:08 2013 perl [...] pied.nu - Correspondence added

On Wed Jul 10 22:47:18 2013, dzsbsd@gmail.com wrote: Show quoted text

> I'm referring to just the TCP connection being half closed, not a HTTP > "Connection" header. Version 0.0902-rc4 does change the behavior so > responses from the following are received reliably. Nice work!

Hahahaha! Aren't I a genius! Uh. now wait. What I mean is : I have no idea (now) what I changed to make this the case. Maybe I did back when I changed it. Anyway, glad you like this RC. Show quoted text

> However, the server waits keepalivetimeout seconds (5) before finally > closing its response connection.

Do you know how to detect half closed connections?

Tue Sep 03 14:55:36 2013 perl [...] pied.nu - Correspondence added

At long last, 0.902 is now on the CPAN.

Tue Sep 03 14:55:37 2013 perl [...] pied.nu - Status changed from 'open' to 'resolved'