[squid-users] read_timeout and "fwdServerClosed: re-forwarding"

From: Chris Hostetter <hossman_squid@dont-contact.us>
Date: Wed, 21 Nov 2007 16:27:13 -0800 (PST)

Greetings,

I'm trying to make sense of some behavior I'm observing related to the
"read_timeout".

I'm dealing with an accelerator setup, where I'd rather return stale
content (or an error) then wait for the origin server to return fresh
content if it is taking too long to respond.

I was hoping that setting the read_timeout to something very low,
(ie: a few seconds) I could get the behavior -- granted, if the origin
server sent back a few bytes every second, squid would keep waiting,
but as I said: accelerator setup; I know how the origin server
behaves, for every request it does a bunch of data crunching (which
occasionally takes a while) before it ever writes a single byte back
to the client.

What I've observed from testing with a simple JSP that does a "sleep"
before writing back the response is that anytime the read_timeout is
exceeded, squid will retry the request, and if that retry also exceeds
the read_timeout, it will retry again, up to a a total of 10 times (10
retries, 11 total requests to the origin server) before responding
back to the client. It will do these retries even if there is a stale
entry in the cache for this request (returning the stale content
eventually -- but without a 'Warning' header).

Debugging logs for these retries look like this...

2007/11/20 14:04:10| checkTimeouts: FD 13 Expired
2007/11/20 14:04:10| checkTimeouts: FD 13: Call timeout handler
2007/11/20 14:04:10| httpTimeout: FD 13: 'http://localhost/test-read-timeout.jsp?123'
2007/11/20 14:04:10| fwdFail: ERR_READ_TIMEOUT "Gateway Time-out"
         http://localhost/test-read-timeout.jsp?123
    ...
2007/11/20 14:04:10| fwdServerClosed: FD 13 http://localhost/test-read-timeout.jsp?123
2007/11/20 14:04:10| fwdServerClosed: re-forwarding (2 tries, 12 secs)
    ...
2007/11/20 14:04:16| checkTimeouts: FD 13 Expired
2007/11/20 14:04:16| checkTimeouts: FD 13: Call timeout handler
2007/11/20 14:04:16| httpTimeout: FD 13: 'http://localhost/test-read-timeout.jsp?123'
2007/11/20 14:04:16| fwdFail: ERR_READ_TIMEOUT "Gateway Time-out"
         http://localhost/test-read-timeout.jsp?123
    ...
2007/11/20 14:04:16| fwdServerClosed: FD 13 http://localhost/test-read-timeout.jsp?123
2007/11/20 14:04:16| fwdServerClosed: re-forwarding (3 tries, 18 secs)

This seems very counter intuitive to me -- if the origin server accepts a
connection, but takes a really long time to respond, in my experience that
typically means it's overloaded and slamming it with 11 times the number
of requests isn't going to help anything.

The only config option I could find that seemed to relate to retries
was "maximum_single_addr_tries" but setting it to "1" had no affect, I
did however notice this comment in it's docs...

# Note: This is in addition to the request re-forwarding which
# takes place if Squid fails to get a satisfying response.

...this sounds like what I'm seeing -- is there an option to control
the number of "re-forwarding" attempts (to be something smaller then
"10"), or any further documentation on the definition of "a satisfying
response" ?

-Hoss
Received on Wed Nov 21 2007 - 17:27:15 MST

This archive was generated by hypermail pre-2.1.9 : Sat Dec 01 2007 - 12:00:02 MST