Strange repeated errors

Hi,

I’ve a tail -f error.log running, and saw some strange errors, repeated
each minutes at same second (26), from same host and same URL :

2012/05/22 15:13:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.26:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:14:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.26:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:15:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.31:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:16:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.31:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:17:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.32:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:18:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.32:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:19:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.33:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:20:26 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.33:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:21:27 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.34:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:22:27 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.34:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:23:27 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.28:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:24:27 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.28:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:25:27 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.0.25:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com
2012/05/22 15:26:27 [error] 12410#0: *4714521 upstream timed out (110:
Connection timed out) while reading response header from upstream,
client: 177.65.240.189, server: www.mydomain1.com, request: “GET
/?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.25:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com

I’ve curl this URL, then ab (ApacheBench) it, and wasn’t able to
reproduce this error. Did you have an idea how to debug that ?

Hello!

On Tue, May 22, 2012 at 03:37:54PM +0200, Greg wrote:

http://10.0.0.26:80/?track=lang-BR&uid=159669961”, host:
request: “GET /?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
upstream, client: 177.65.240.189, server: www.mydomain1.com,
(110: Connection timed out) while reading response header from
2012/05/22 15:21:27 [error] 12410#0: *4714521 upstream timed out
sub.mydomain1.com
http://10.0.1.28:80/?track=lang-BR&uid=159669961”, host:
request: “GET /?track=lang-BR&uid=159669961 HTTP/1.1”, upstream:
http://10.0.1.25:80/?track=lang-BR&uid=159669961”, host:
sub.mydomain1.com

I’ve curl this URL, then ab (ApacheBench) it, and wasn’t able to
reproduce this error. Did you have an idea how to debug that ?

Looks like your upstream servers fail to respond in time for some
reason and nginx tries upstream servers configured as per
proxy_next_upstream (see http://nginx.org/r/proxy_next_upstream).

The reason why your backends time out is probably related to a
particular request properties, likely something user/cookie
related as you can’t reproduce it with just url. Try looking into
backend logs.

Maxim D.

Hi,

Le 22/05/2012 18:21, Maxim D. a crit :

Looks like your upstream servers fail to respond in time for some
reason and nginx tries upstream servers configured as per
proxy_next_upstream (see http://nginx.org/r/proxy_next_upstream).

The reason why your backends time out is probably related to a
particular request properties, likely something user/cookie
related as you can’t reproduce it with just url. Try looking into
backend logs.

You’re right !
But is that normal that next upstreams are tried infinitely ? How many
tries did NginX before considere that the request is really failed ?

Hello!

On Wed, May 23, 2012 at 09:17:11AM +0200, Greg wrote:

backend logs.

You’re right !
But is that normal that next upstreams are tried infinitely ? How
many tries did NginX before considere that the request is really
failed ?

Normally nginx will try all servers specified in an upstream{}
block before giving up.

Before 1.3.0 there were infinite loop over upstream servers
possible if there were “backup” servers specified in an upstream
block. It normally affected only setups with “proxy_next_upstream
http_404” used as well, but might also affect normal setups if
only specific requests fail and iteration of the loop over
backends takes more than fail_timeout.

Maxim D.