Strange repeated errors

Tue May 22 16:21:52 UTC 2012

Hello!

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

> 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 ?

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 Dounin