post_action и код возврата 499
Matvei Elyutin
melyutin at gmail.com
Tue Dec 25 19:08:02 MSK 2007
Не совсем понятно поведение в следующем случае:
nginx отдает контент пользователю исходя из ответа апача (скорость,
файл, итд). Запрос сначала идет в апач, который возвращает параметры
сессии пользователя, здесь и должен запускаться post_action и начинаться
отдача файла. Так и происходит в большинстве случаев. Если в соединение
было прервано клиентом в тот момент, когда апач еще не ответил nginx'у
мы получается код ответа 499:
ip.ip.ip.ip - - [25/Dec/2007:18:31:28 +0300] "GET
/34/mysql-5.0.18-win32.zip HTTP/1.0" 499 0 "-" "Wget/1.10.2"
и при этом post_action не срабатывает. Мне кажется это не правильно.
Дебаг лог:
2007/12/25 18:31:28 [debug] 2762#0: *191784 accept: 80.68.244.35 fd:5
2007/12/25 18:31:28 [debug] 2762#0: *191784 event timer add: 5:
30000:300843110
2007/12/25 18:31:28 [debug] 2762#0: *191784 epoll add event: fd:5 op:1
ev:80000001
2007/12/25 18:31:28 [debug] 2762#0: *191784 post event B7D944CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 delete posted event B7D944CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 malloc: 0939AA30:632
2007/12/25 18:31:28 [debug] 2762#0: *191784 malloc: 0939ACB0:1024
2007/12/25 18:31:28 [debug] 2762#0: *191784 malloc: 0938E170:4096
2007/12/25 18:31:28 [debug] 2762#0: *191784 http process request line
2007/12/25 18:31:28 [debug] 2762#0: *191784 recv: fd:5 189 of 1024
2007/12/25 18:31:28 [debug] 2762#0: *191784 http request line: "GET
/34/mysql-5.0.18-win32.zip HTTP/1.0"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http uri:
"/34/mysql-5.0.18-win32.zip"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http args: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http exten: "zip"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http process request header line
2007/12/25 18:31:28 [debug] 2762#0: *191784 http header: "User-Agent:
Wget/1.10.2"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http header: "Accept: */*"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http header: "Host:
be2.filehosting.relax.ru"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http header: "Connection:
Keep-Alive"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http header: "Cookie:
PHPSESSID=822e94871d3899fcda6d8b66d287df22"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http header done
2007/12/25 18:31:28 [debug] 2762#0: *191784 event timer del: 5: 300843110
2007/12/25 18:31:28 [debug] 2762#0: *191784 generic phase: 0
2007/12/25 18:31:28 [debug] 2762#0: *191784 find location for
"/34/mysql-5.0.18-win32.zip"
2007/12/25 18:31:28 [debug] 2762#0: *191784 find location: "/"
2007/12/25 18:31:28 [debug] 2762#0: *191784 find location: "/file1/"
2007/12/25 18:31:28 [debug] 2762#0: *191784 using configuration "/"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http cl:-1 max:16777216
2007/12/25 18:31:28 [debug] 2762#0: *191784 generic phase: 2
2007/12/25 18:31:28 [debug] 2762#0: *191784 post rewrite phase: 3
2007/12/25 18:31:28 [debug] 2762#0: *191784 generic phase: 4
2007/12/25 18:31:28 [debug] 2762#0: *191784 access phase: 5
2007/12/25 18:31:28 [debug] 2762#0: *191784 access phase: 6
2007/12/25 18:31:28 [debug] 2762#0: *191784 post access phase: 7
2007/12/25 18:31:28 [debug] 2762#0: *191784 http init upstream, client
timer: 0
2007/12/25 18:31:28 [debug] 2762#0: *191784 epoll add event: fd:5 op:3
ev:80000005
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script var: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script var: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script var: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http script copy: ""
2007/12/25 18:31:28 [debug] 2762#0: *191784 http proxy header:
"User-Agent: Wget/1.10.2"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http proxy header: "Accept: */*"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http proxy header: "Cookie:
PHPSESSID=822e94871d3899fcda6d8b66d287df22"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http proxy header:
"GET /34/mysql-5.0.18-win32.zip HTTP/1.0
Host: bububu.***
X-URI: /34/mysql-5.0.18-win32.zip
X-Forwarded-For: 80.68.244.35
Connection: close
User-Agent: Wget/1.10.2
Accept: */*
Cookie: PHPSESSID=822e94871d3899fcda6d8b66d287df22
"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http cleanup add: 0938EA4C
2007/12/25 18:31:28 [debug] 2762#0: *191784 get rr peer, try: 1
2007/12/25 18:31:28 [debug] 2762#0: *191784 socket 15
2007/12/25 18:31:28 [debug] 2762#0: *191784 epoll add connection: fd:15
ev:80000005
2007/12/25 18:31:28 [debug] 2762#0: *191784 connect to 127.0.0.1:80,
fd:15 #191785
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream connect: -2
2007/12/25 18:31:28 [debug] 2762#0: *191784 event timer add: 15:
30000:300843110
2007/12/25 18:31:28 [debug] 2762#0: *191784 post event B7CCA894
2007/12/25 18:31:28 [debug] 2762#0: *191784 post event B7CC34CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 delete posted event B7CC34CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream check client,
write event:1, "/34/mysql-5.0.18-win32.zip"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream recv(): -1
(11: Resource temporarily unavailable)
2007/12/25 18:31:28 [debug] 2762#0: *191784 delete posted event B7CCA894
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream send request
handler
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream send request
2007/12/25 18:31:28 [debug] 2762#0: *191784 chain writer buf fl:1 s:250
2007/12/25 18:31:28 [debug] 2762#0: *191784 chain writer in: 0938EA58
2007/12/25 18:31:28 [debug] 2762#0: *191784 writev: 250
2007/12/25 18:31:28 [debug] 2762#0: *191784 chain writer out: 00000000
2007/12/25 18:31:28 [debug] 2762#0: *191784 event timer del: 15: 300843110
2007/12/25 18:31:28 [debug] 2762#0: *191784 event timer add: 15:
120000:300933111
2007/12/25 18:31:28 [debug] 2762#0: *191784 post event B7D944CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 post event B7CC34CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 delete posted event B7CC34CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream check client,
write event:1, "/34/mysql-5.0.18-win32.zip"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream recv(): 0 (11:
Resource temporarily unavailable)
2007/12/25 18:31:28 [debug] 2762#0: *191784 delete posted event B7D944CC
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream check client,
write event:0, "/34/mysql-5.0.18-win32.zip"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http upstream recv(): 0 (11:
Resource temporarily unavailable)
2007/12/25 18:31:28 [info] 2762#0: *191784 client closed prematurely
connection, so upstream connection is closed too while sending requ
est to upstream, client: 80.68.244.35, server: bububu.***, URL:
"/34/mysql-5.0.18-win32.zip", upstream: "http://127.0.0.1:
80/34/mysql-5.0.18-win32.zip", host: "bububu.***"
2007/12/25 18:31:28 [debug] 2762#0: *191784 finalize http upstream
request: 499
2007/12/25 18:31:28 [debug] 2762#0: *191784 finalize http proxy request
2007/12/25 18:31:28 [debug] 2762#0: *191784 free rr peer 1 0
2007/12/25 18:31:28 [debug] 2762#0: *191784 close http upstream
connection: 15
2007/12/25 18:31:28 [debug] 2762#0: *191784 event timer del: 15: 300933111
2007/12/25 18:31:28 [debug] 2762#0: *191784 http finalize request: 499,
"/34/mysql-5.0.18-win32.zip?"
2007/12/25 18:31:28 [debug] 2762#0: *191784 http close request
2007/12/25 18:31:28 [debug] 2762#0: *191784 http log handler
2007/12/25 18:31:28 [debug] 2762#0: *191784 free: 0938E170, unused: 1677
2007/12/25 18:31:28 [debug] 2762#0: *191784 close http connection: 5
2007/12/25 18:31:28 [debug] 2762#0: *191784 free: 0939ACB0
2007/12/25 18:31:28 [debug] 2762#0: *191784 free: 0939AA30
2007/12/25 18:31:28 [debug] 2762#0: *191784 free: 09388450, unused: 64
С уважением.
More information about the nginx-ru
mailing list