upstream prematurely closed connection while reading response header from upstream...
sjtar
nginx-forum на nginx.us
Ср Апр 28 02:38:12 MSD 2010
Здравствуйте,
Имею связку nginx/0.7.65+apache2.2.14 на FreeBSD 8.0-RELEASE.
На некоторых страницах стал замечать ошибку 502, включил debug-лог, вот что пишет:
[code]
2010/04/28 01:08:53 [debug] 27796#0: *8 accept: 11.11.11.11 fd:3
2010/04/28 01:08:53 [debug] 27796#0: *8 event timer add: 3: 60000:1272402593067
2010/04/28 01:08:53 [debug] 27796#0: *8 kevent set event: 3: ft:-1 fl:0025
2010/04/28 01:08:53 [debug] 27796#0: *8 malloc: 0000000801FF4700:1256
2010/04/28 01:08:53 [debug] 27796#0: *8 malloc: 0000000801F06500:256
2010/04/28 01:08:53 [debug] 27796#0: *8 malloc: 0000000801F2A400:1024
2010/04/28 01:08:53 [debug] 27796#0: *8 malloc: 0000000801F4F000:4096
2010/04/28 01:08:53 [debug] 27796#0: *8 http process request line
2010/04/28 01:08:53 [debug] 27796#0: *8 recv: eof:0, avail:725, err:0
2010/04/28 01:08:53 [debug] 27796#0: *8 recv: fd:3 725 of 1024
2010/04/28 01:08:53 [debug] 27796#0: *8 http request line: "GET /cart.php HTTP/1.0"
2010/04/28 01:08:53 [debug] 27796#0: *8 http uri: "/cart.php"
2010/04/28 01:08:53 [debug] 27796#0: *8 http args: ""
2010/04/28 01:08:53 [debug] 27796#0: *8 http exten: "php"
2010/04/28 01:08:53 [debug] 27796#0: *8 http process request header line
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Host: mysite.ru"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.2.5pre) Gecko/20100424 Ubuntu/9.10 (karmic) Namoroka/3.6.5pre"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Accept-Language: en-us,en;q=0.5"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Accept-Encoding: gzip,deflate"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Referer: http://mysite.ru/cart.php"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Cookie: AWSUSER_ID=awsuser_id1261927370595r6399; AWSSESSION_ID=awssession_id1272401261379r3038; PHPSESSID=e297qtictcjkht248a4l8ocac1; SESSSEC=3977bd2de52eb31a0ce42ddb0e60cde6be3270e6"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Via: 1.1 myproxy.ru (squid/3.0.STABLE21)"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "X-Forwarded-For: 192.168.1.1"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Cache-Control: max-age=259200"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header: "Connection: keep-alive"
2010/04/28 01:08:53 [debug] 27796#0: *8 http header done
2010/04/28 01:08:53 [debug] 27796#0: *8 event timer del: 3: 1272402593067
2010/04/28 01:08:53 [debug] 27796#0: *8 generic phase: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 add cleanup: 0000000801F4FA30
2010/04/28 01:08:53 [debug] 27796#0: *8 generic phase: 1
2010/04/28 01:08:53 [debug] 27796#0: *8 test location: "/"
2010/04/28 01:08:53 [debug] 27796#0: *8 test location: ~ "^.+\.(jpg|jpeg|gif|png|js|css|swf|zip|rar|doc|xls|mp3|ico|txt)$"
2010/04/28 01:08:53 [debug] 27796#0: *8 using configuration "/"
2010/04/28 01:08:53 [debug] 27796#0: *8 http cl:-1 max:10485760
2010/04/28 01:08:53 [debug] 27796#0: *8 generic phase: 3
2010/04/28 01:08:53 [debug] 27796#0: *8 post rewrite phase: 4
2010/04/28 01:08:53 [debug] 27796#0: *8 generic phase: 5
2010/04/28 01:08:53 [debug] 27796#0: *8 add cleanup: 0000000801F4FAE0
2010/04/28 01:08:53 [debug] 27796#0: *8 generic phase: 6
2010/04/28 01:08:53 [debug] 27796#0: *8 generic phase: 7
2010/04/28 01:08:53 [debug] 27796#0: *8 access phase: 8
2010/04/28 01:08:53 [debug] 27796#0: *8 access phase: 9
2010/04/28 01:08:53 [debug] 27796#0: *8 post access phase: 10
2010/04/28 01:08:53 [debug] 27796#0: *8 http init upstream, client timer: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 kevent set event: 3: ft:-2 fl:0025
2010/04/28 01:08:53 [debug] 27796#0: *8 malloc: 0000000801F50000:4096
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "Host: "
2010/04/28 01:08:53 [debug] 27796#0: *8 http script var: "mysite.ru"
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "X-Real-IP: "
2010/04/28 01:08:53 [debug] 27796#0: *8 http script var: "11.11.11.11"
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "X-Forwarded-For: "
2010/04/28 01:08:53 [debug] 27796#0: *8 http script var: "192.168.1.1, 11.11.11.11"
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "
2010/04/28 01:08:53 [debug] 27796#0: *8 http script copy: "Connection: close
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.2.5pre) Gecko/20100424 Ubuntu/9.10 (karmic) Namoroka/3.6.5pre"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Accept-Language: en-us,en;q=0.5"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Accept-Encoding: gzip,deflate"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Referer: http://mysite.ru/cart.php"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Cookie: AWSUSER_ID=awsuser_id1261927370595r6399; AWSSESSION_ID=awssession_id1272401261379r3038; PHPSESSID=e297qtictcjkht248a4l8ocac1; SESSSEC=3977bd2de52eb31a0ce42ddb0e60cde6be3270e6"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Via: 1.1 myproxy.ru (squid/3.0.STABLE21)"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header: "Cache-Control: max-age=259200"
2010/04/28 01:08:53 [debug] 27796#0: *8 http proxy header:
2010/04/28 01:08:53 [debug] 27796#0: *8 http cleanup add: 0000000801F503F0
2010/04/28 01:08:53 [debug] 27796#0: *8 get rr peer, try: 1
2010/04/28 01:08:53 [debug] 27796#0: *8 socket 9
2010/04/28 01:08:53 [debug] 27796#0: *8 connect to 127.0.0.1:8181, fd:9 #9
2010/04/28 01:08:53 [debug] 27796#0: *8 kevent set event: 9: ft:-1 fl:0025
2010/04/28 01:08:53 [debug] 27796#0: *8 connected
2010/04/28 01:08:53 [debug] 27796#0: *8 http upstream connect: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 http upstream send request
2010/04/28 01:08:53 [debug] 27796#0: *8 chain writer buf fl:1 s:763
2010/04/28 01:08:53 [debug] 27796#0: *8 chain writer in: 0000000801F50428
2010/04/28 01:08:53 [debug] 27796#0: *8 writev: 763 of 763
2010/04/28 01:08:53 [debug] 27796#0: *8 chain writer out: 0000000000000000
2010/04/28 01:08:53 [debug] 27796#0: *8 event timer add: 9: 90000:1272402623069
2010/04/28 01:08:53 [debug] 27796#0: *8 http run request: "/cart.php?"
2010/04/28 01:08:53 [debug] 27796#0: *8 http upstream check client, write event:1, "/cart.php"
2010/04/28 01:08:53 [debug] 27796#0: *8 http upstream request: "/cart.php?"
2010/04/28 01:08:53 [debug] 27796#0: *8 http upstream process header
2010/04/28 01:08:53 [debug] 27796#0: *8 malloc: 0000000801F51000:4096
2010/04/28 01:08:53 [debug] 27796#0: *8 recv: eof:1, avail:0, err:0
2010/04/28 01:08:53 [error] 27796#0: *8 upstream prematurely closed connection while reading response header from upstream, client: 11.11.11.11, server: mysite.ru, request: "GET /cart.php HTTP/1.0", upstream: "http://127.0.0.1:8181/cart.php", host: "mysite.ru", referrer: "http://mysite.ru/cart.php"
2010/04/28 01:08:53 [debug] 27796#0: *8 http next upstream, 2
2010/04/28 01:08:53 [debug] 27796#0: *8 free rr peer 1 4
2010/04/28 01:08:53 [debug] 27796#0: *8 finalize http upstream request: 502
2010/04/28 01:08:53 [debug] 27796#0: *8 finalize http proxy request
2010/04/28 01:08:53 [debug] 27796#0: *8 free rr peer 0 0
2010/04/28 01:08:53 [debug] 27796#0: *8 close http upstream connection: 9
2010/04/28 01:08:53 [debug] 27796#0: *8 event timer del: 9: 1272402623069
2010/04/28 01:08:53 [debug] 27796#0: *8 http finalize request: 502, "/cart.php?" 1
2010/04/28 01:08:53 [debug] 27796#0: *8 http special response: 502, "/cart.php?"
2010/04/28 01:08:53 [debug] 27796#0: *8 http set discard body
2010/04/28 01:08:53 [debug] 27796#0: *8 xslt filter header
2010/04/28 01:08:53 [debug] 27796#0: *8 HTTP/1.1 502 Bad Gateway
2010/04/28 01:08:53 [debug] 27796#0: *8 write new buf t:1 f:0 0000000801F50618, pos 0000000801F50618, size: 150 file: 0, size: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 http write filter: l:0 f:0 s:150
2010/04/28 01:08:53 [debug] 27796#0: *8 http output filter "/cart.php?"
2010/04/28 01:08:53 [debug] 27796#0: *8 copy filter: "/cart.php?"
2010/04/28 01:08:53 [debug] 27796#0: *8 xslt filter body
2010/04/28 01:08:53 [debug] 27796#0: *8 http postpone filter "/cart.php?" 0000000801F507D0
2010/04/28 01:08:53 [debug] 27796#0: *8 write old buf t:1 f:0 0000000801F50618, pos 0000000801F50618, size: 150 file: 0, size: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 write new buf t:0 f:0 0000000000000000, pos 0000000000582180, size: 120 file: 0, size: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 write new buf t:0 f:0 0000000000000000, pos 00000000005811A0, size: 46 file: 0, size: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 http write filter: l:1 f:0 s:316
2010/04/28 01:08:53 [debug] 27796#0: *8 http write filter limit 0
2010/04/28 01:08:53 [debug] 27796#0: *8 writev: 316 of 316
2010/04/28 01:08:53 [debug] 27796#0: *8 http write filter 0000000000000000
2010/04/28 01:08:53 [debug] 27796#0: *8 copy filter: 0 "/cart.php?"
2010/04/28 01:08:53 [debug] 27796#0: *8 http finalize request: 0, "/cart.php?" 1
2010/04/28 01:08:53 [debug] 27796#0: *8 set http keepalive handler
2010/04/28 01:08:53 [debug] 27796#0: *8 http close request
2010/04/28 01:08:53 [debug] 27796#0: *8 http log handler
2010/04/28 01:08:53 [debug] 27796#0: *8 free: 0000000801F51000
2010/04/28 01:08:53 [debug] 27796#0: *8 free: 0000000801F4F000, unused: 0
2010/04/28 01:08:53 [debug] 27796#0: *8 free: 0000000801F50000, unused: 1777
2010/04/28 01:08:53 [debug] 27796#0: *8 event timer add: 3: 65000:1272402598071
2010/04/28 01:08:53 [debug] 27796#0: *8 free: 0000000801FF4700
2010/04/28 01:08:53 [debug] 27796#0: *8 free: 0000000801F2A400
2010/04/28 01:08:53 [debug] 27796#0: *8 hc free: 0000000000000000 0
2010/04/28 01:08:53 [debug] 27796#0: *8 hc busy: 0000000000000000 0
2010/04/28 01:08:53 [debug] 27796#0: *8 tcp_nodelay
2010/04/28 01:08:53 [debug] 27796#0: *8 http empty handler
[/code]
Возможно кто-то подскажет, в чем может быть проблема.
Posted at Nginx Forum: http://forum.nginx.org/read.php?21,80097,80097#msg-80097
Подробная информация о списке рассылки nginx-ru