Upstream timed out

Fri Sep 7 05:18:49 MSD 2007

Igor Sysoev wrote:
> On Thu, Sep 06, 2007 at 11:12:25AM +0300, Vladimir Shiray wrote:
>
>   
>> в error.log постоянно попадают ошибки, типа:
>>     "upstream timed out (110: Connection timed out) while reading upstream"
>>
>> После очистки лога и перезапуска nginx, на 150000 подключений
>> получил 426 таких сообщений.
>>
>> Сам сервер запущен внутри OpenVZ окружения (CentOS 4.5 32bit). Перед 
>> последними
>> проверками, окружение было остановлено и запущено снова.
>> В /proc/user_beancounters и в логах ядра (2.6.18-ovz028stab039.1-smp) 
>> все "чисто".
>>
>> У сервера есть три upstream, один докальный в "соседнем" VPS и два удаленных
>> (rtt: 150ms и 60ms). Ошибки присутствуют для каждого из них.
>>
>> ------
>>
>> nginx-0.5.29  (c двумя патчами: patch-0.6.2.2, patch-0.6.5.1)
>>     
>
> Как уже посоветовали, можно логировать $upstream_response_time
>
> Эти ошибки на https'ных соединениях с бэкендами или на обычных ?
>
>   
В данном случае проблемы происходят на обычных соединениях.
На SSL с патчем 0.6.2.2 никаких проблем больше не обнаруживается.
Но как я понимаю, патч включен в состав 0.5.30

Вот обновил настройки для логирования:
    log_format  mylog '$http_host $remote_addr - $remote_user 
[$time_local] $request '
                      '"$status" $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" $bytes_sent 
$upstream_response_time $request_time';

Перестартовал полностью nginx и в течении первых 5 минут получил уже 
первую ошибку.
Извлек все записиси для этого же URL с момента старта сервера.
На всякий случай включил кусок лога (4 строки) за этот период для SSL.

2007/09/07 04:24:49 [error] 10215#0: *618 upstream timed out (110: 
Connection timed out) while reading upstream, client: 207.4.222.10, 
server: www.kabbalah.info, URL: "/pictures/kabbalah.gif", upstream: 
"http://64.40.103.100:80/pictures/kabbalah.gif", host: 
"www.kabbalah.info", referrer: "http://www.kabbalah.info/"

----- access.log   (grep /pictures/kabbalah.gif)

www.kabbalah.info 85.178.0.205 - - [07/Sep/2007:04:20:48 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "304" 0 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 
1.0.3705; .NET CLR 1.1.4322; Media Center PC 4.0; .NET CLR 2.0.50727)" 
212 0.311 0.311

www.kabbalah.info 84.109.97.57 - - [07/Sep/2007:04:21:55 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "304" 0 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; InfoPath.1)" 
212 0.848 0.848

www.kabbalah.info 75.171.34.92 - - [07/Sep/2007:04:23:23 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "304" 0 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; MRA 4.7 (build 
01670); .NET CLR 1.0.3705; .NET CLR 1.1.4322; Media Center PC 3.1; MSN 
9.0;MSN 9.1; MSNbQ002; MSNmen-us; MSNcOTH)" 212 0.313 0.313

www.kabbalah.info 212.12.28.1 - - [07/Sep/2007:04:23:28 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "200" 7079 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; InfoPath.1)" 
7396 0.472 0.472

www.kabbalah.info 70.22.177.14 - - [07/Sep/2007:04:23:36 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "200" 7079 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; SU 3.004; IEMB3; 
IEMB3)" 7396 0.465 0.465

www.kabbalah.info 171.159.192.10 - - [07/Sep/2007:04:24:14 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "200" 7079 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; InfoPath.1; 
.NET CLR 1.1.4322; .NET CLR 1.0.3705; .NET CLR 2.0.50727)" 7396 0.469 0.469

www.kabbalah.info 207.4.222.10 - - [07/Sep/2007:04:24:49 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "304" 0 "http://www.kabbalah.info/" 
"Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.6) 
Gecko/20070725 Firefox/2.0.0.6" 212 123.154 123.154

www.kabbalah.info 85.113.215.1 - - [07/Sep/2007:04:26:13 +0400] GET 
/pictures/kabbalah.gif HTTP/1.1 "200" 7079 "http://www.kabbalah.info/" 
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; InfoPath.2; 
.NET CLR 2.0.50727; .NET CLR 3.0.04506.30)" 7396 0.470 0.503

------ access_ssl.log    (all lines from 04:17:57 to 04:26:04)

84.228.157.194 - - [07/Sep/2007:04:17:57 +0400] GET 
/mail/src/left_main.php HTTP/1.1 "200" 2345 
"https://www.kabbalah.info/xxxxxxxxxxxxxxxxx/aaa.php"
 "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 
1.1.4322)" "-"

84.228.157.194 - - [07/Sep/2007:04:22:58 +0400] GET 
/mail/src/left_main.php HTTP/1.1 "200" 2352 
"https://www.kabbalah.info/xxxxxxxxxxxxxxxxx/aaa.php"
 "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 
1.1.4322)" "-"

65.55.210.90 - - [07/Sep/2007:04:26:02 +0400] GET /robots.txt HTTP/1.0 
"200" 199 "-" "msnbot/1.0 (+http://search.msn.com/msnbot.htm)" "-"

65.55.210.90 - - [07/Sep/2007:04:26:04 +0400] GET 
/polakab/publikacje/magik.php HTTP/1.0 "200" 1095 "-" "msnbot/1.0 
(+http://search.msn.com/
msnbot.htm)" "-"