post_action и код возврата 499

Tue Dec 25 19:15:47 MSK 2007

забыл добавить, версия nginx/0.6.16

Matvei Elyutin пишет:
> Не совсем понятно поведение в следующем случае:
>
> 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
>
> С уважением.
>
>