perlbal reissuing POSTs to backend?

[Jonathan Swartz]

I'm seeing a situation where a reverse-proxy POST request sent to a
backend that does not return for a while will get reissued. Our
backend ends up processing the same POST request many times. Each
replay is about 40 seconds apart.

Is this expected behavior? If so, is there any way to turn it off?

My reverse proxy conf looks like:

SET role = reverse_proxy
SET pool = webs
SET persist_backend = on
SET verify_backend = on
SET buffer_uploads = off
SET blind_proxy = on
SET always_trusted = on

Thanks
Jon

[Jonathan Swartz]

Update on this:
* I'm able to reproduce this with a POST to a very simple page that
just sleeps.
* This only happens with Safari! With every other client I tried
(firefox, chrome, and lwp-request), the connection is closed when
perlbal times out and the client shows a blank page or an error page.
With Safari, the connection is never closed and perlbal repeatedly
issues the same POST to the backend.
* I'm able to affect the replay time by changing
persist_client_timeout. e.g. When I set persist_client_timeout to 10,
the replay occurs every 15 seconds or so.

[Brad Fitzpatrick]

A tcpdump / wireshark packet capture from the Perlbal box would be interesting, but I'm unlikely to be able to find any time to fix.  There should be people on this list with more time + business desire to see it fixed, though.

[Mark Smith]

Weird. Are you sure that's not a Safari problem? Perlbal should only
replay GET requests, and only when you turn that feature on. I'm a bit
weirded out that you're getting POST replays.

Do you use any custom or non-standard plugins?

--
Mark Smith
ma...@qq.is

[Jonathan Swartz]

Ok, I've gotten this to a minimal reproducible state. Using perl 5.12.2 and latest versions of all modules below. Have seen with both OS X and Linux.

1. cpanm Plack Perlbal Starlet IO::AIO

2. Create perlbal.conf:

CREATE POOL webs
POOL webs ADD 127.0.0.1:5000
SERVER aio_mode = ioaio

CREATE SERVICE dynamic
SET listen = 0.0.0.0:8080

SET role = reverse_proxy
SET pool = webs

SET idle_timeout = 5
ENABLE dynamic

3. Create sleep.psgi:

my $form = '<form action="/sleep" method=post><input name="upfile" type=file><input type=submit></form>';
my $app = sub {
my $env = shift;
my $uri = $env->{REQUEST_URI};
if ($uri eq '/form') {
return [ 200, [ "Content-Type" => "text/html" ], [ $form ] ];
}
elsif ($uri eq '/sleep') {
print "$$ sleeping...\n";
sleep(60);
return [ 200, [ "Content-Type" => "text/html" ], [ "I slept" ] ];
}
else {
return [ 404, [], [ "not found" ] ];
}
};

4. Run "perlbal --config=perlbal.conf" in one shell

5. Run "plackup -r -s Starlet --max-workers=5 sleep.psgi" in another shell

6. Hit localhost:8080/form with Safari

7. Choose any small file and hit submit

8. You should see multiple "sleeping" messages as perlbal repeatedly forwards the post. The safari request will never stop.

Notes:
* You don't need IO::AIO, I just included that to kill the warning.
* It's still reproducible, though not as bad, without the file upload input. perlbal will forward the post three times or so, but then the safari request will stop with "server closed the connection".
* Doesn't seem to happen with any browser other than safari.

Can someone try to reproduce this and let me know whether they succeed?

Thanks!

Jon

[Ask Bjørn Hansen]

Can you (with tcpdump) check if it's Safari re-issuing the requests?

- ask

[Jonathan Swartz]

Ouch, you're right, it is Safari re-issuing the requests. But I can only reproduce it when posting to perlbal. Could it be something strange about the way perlbal is closing the connection with Safari?

Here's the verbose TCP dump of port 8080 (perlbal):

http://dpaste.com/hold/274293/

Notice there are three POSTs to /sleep, and eventually three responses, even though I hit submit once.

I'm not familiar with tcp dumps :) so not sure if there's any useful information here.

Jon

[dormando]

What happens if you set the idle_timeout = 90?

I see in your test that the idle_timeout is set really low (5)... I think
this value ends up closing the connection on safari after ~10 seconds, so
it reissues the POST (stupidly?)

And you don't see this happening if you run it against plackup directly
instead of via perlbal?

Def smells like the timeout + some safari specific behavior is the issue.

On Thu, 11 Nov 2010, Jonathan Swartz wrote:

> Ouch, you're right, it is Safari re-issuing the requests. But I can only reproduce it when posting to perlbal. Could it be something strange about the way perlbal is closing the connection with Safari?
>
> Here's the verbose TCP dump of port 8080 (perlbal):
>
> http://dpaste.com/hold/274293/
>
> Notice there are three POSTs to /sleep, and eventually three responses, even though I hit submit once.
>
> I'm not familiar with tcp dumps :) so not sure if there's any useful information here.
>
> Jon
>

[Jonathan Swartz]

Right, I'm not really setting it that low in reality...it was just to easily reproduce the problem. If I set the idle_timeout=90, then it takes 90 seconds to repost. We were running into that initially (90 is the default I believe).

On Nov 15, 2010, at 1:07 AM, dormando wrote:

> What happens if you set the idle_timeout = 90?
>
> I see in your test that the idle_timeout is set really low (5)... I think
> this value ends up closing the connection on safari after ~10 seconds, so
> it reissues the POST (stupidly?)
>
> And you don't see this happening if you run it against plackup directly
> instead of via perlbal?
>
> Def smells like the timeout + some safari specific behavior is the issue.
>
> On Thu, 11 Nov 2010, Jonathan Swartz wrote:
>
>> Ouch, you're right, it is Safari re-issuing the requests. But I can only reproduce it when posting to perlbal. Could it be something strange about the way perlbal is closing the connection with Safari?
>>
>> Here's the verbose TCP dump of port 8080 (perlbal):
>>
>> http://dpaste.com/hold/274293/
>>
>> Notice there are three POSTs to /sleep, and eventually three responses, even though I hit submit once.
>>
>> I'm not familiar with tcp dumps :) so not sure if there's any useful information here.
>>
>> Jon
>>

[Jonathan Swartz]

And no, I don't get it if run against plackup directly...but then again plackup isn't timing out. Not sure how to make it do so. I tried to use Starlet's timeout setting but it didn't seem to work for this.

[dormando]

Try running an apache CGI with apache's Timeout set to 5s or similar?

This doesn't seem like something we can do differently... Set the
idle_timeout to higher than your POST-processing time would be, and use
nonce's or something.

I'm having a pretty good fail at getting google to tell me why safari is a
special child in this case, but I'm not sure what difference it would make
anyway.

-Dormando

[Jonathan Swartz]

In this case Apache will return a 500, with "Timeout waiting for output from CGI script" in the error log.

However, I have been able to reproduce this by killing the Apache child while it is processing the request. Safari will reissue the post and it will go to another child. I can do this many times in a row.

Is it possible that no other web server closes the connection the way that perlbal does, which would explain the failure to find references to this in google? What if perlbal handled a timeout the way Apache did, by returning a 500? Is that a more appropriate response?

Jon

[Jan Kantert]

Hi,

this is a good point. We had issues with the way perlbal closes
connections on timeout in the past, too. Most browser will just render a
white page without an error or show a strange error message. A 500 with
a little error message would be nice. We could also get the error page
via a backend (different url/backend).This would allow us to log the
incident and show an appropriate error message.

Regards,
Jan

--
CIPHRON GmbH
Tel.: +49 (5 11) 51 51 33 - 0 Fax: +49 (5 11) 51 51 33 - 29
Web: http://www.ciphron.de/ Support: +49 (5 11) 51 51 33 - 11
Ust.Id.: DE263362886 Gesch�ftsf�hrer: Sebastian Horzela
Amtsgericht Hannover, HRB 203590

[dormando]

+1.

There're a lot of cases where perlbal seems to kill the connection for the
sake of not knowing what's going on. It should be possible to have it 500
on timeout (as is proper?)

[Mark Smith]

> There're a lot of cases where perlbal seems to kill the connection for the
> sake of not knowing what's going on. It should be possible to have it 500
> on timeout (as is proper?)

I wasn't sure, so I researched. Yes, this is proper. As per RFC 2616 (http://www.w3.org/Protocols/rfc2616/rfc2616-sec8.html#sec8.2.4):

---
8.2.4 Client Behavior if Server Prematurely Closes Connection

If an HTTP/1.1 client sends a request which includes a request body, but which does not include an Expect request-header field with the "100-continue" expectation, and if the client is not directly connected to an HTTP/1.1 origin server, and if the client sees the connection close before receiving any status from the server, the client SHOULD retry the request.
---

Clients are supposed to watch or error statuses while they are transmitting (section 8.2.2), so we should make it so that every error close also transmits some sort of error message.

--
Mark Smith
ma...@qq.is

[Jonathan Swartz]

On Nov 22, 2010, at 11:06 AM, Mark Smith wrote:

>> There're a lot of cases where perlbal seems to kill the connection for the
>> sake of not knowing what's going on. It should be possible to have it 500
>> on timeout (as is proper?)
>
> I wasn't sure, so I researched. Yes, this is proper. As per RFC 2616 (http://www.w3.org/Protocols/rfc2616/rfc2616-sec8.html#sec8.2.4):
>
> ---
> 8.2.4 Client Behavior if Server Prematurely Closes Connection
>
> If an HTTP/1.1 client sends a request which includes a request body, but which does not include an Expect request-header field with the "100-continue" expectation, and if the client is not directly connected to an HTTP/1.1 origin server, and if the client sees the connection close before receiving any status from the server, the client SHOULD retry the request.
> ---

Huh - so does this mean Safari is actually acting properly, and the other browsers (at least Firefox, Chrome) are not?

Still, it would be more appropriate if perlbal returned a 500 error.

[Mark Smith]

> Huh - so does this mean Safari is actually acting properly, and the other browsers (at least Firefox, Chrome) are not?

Standards aren't perfect. There are a lot of problems with reissuing requests, and I think that in this case, the behavior of Firefox, Chrome, et al is superior. Once you've *sent* a packet, you have no way to know where the failure occurs.

Server software *should* be written to respond appropriately to repeated requests, i.e., to not duplicate actions, but the sad fact is most engineers don't think about that or don't plan for it and you can get a lot of bad interactions this way.

Anyway, yes, Safari seems to be operating according to the letter of the law, even if the law is (IMO) vague and wrong (and in fact, optional, 'SHOULD').

> Still, it would be more appropriate if perlbal returned a 500 error.

Yes, it would.

--
Mark Smith
ma...@qq.is

[Jonathan Swartz]

Ah, didn't realize SHOULD was optional, but I don't read standards enough. :)

Anyway, completely agree - replaying POSTs when you don't know what happened to the original request seems like a terrible idea, note for instance that most/all browsers will warn you before replaying POSTs if you hit reload.

Jon