zero size buf in output(Bug?)

Andrey Feldman pr1 at pr1.ru
Tue Oct 9 14:51:21 UTC 2012


Hi.
After update from 1.0.14 to 1.2.3, strange alerts starts to appears in
error.log:
2012/10/08 23:44:07 [alert] 25551#0: *79037 zero size buf in output
t:0 r:0 f:0 000000000D31F3F0 000000000D31F3F0-000000000D3273F0
0000000000000000 0-0 while sending to client, client: 91.138.121.71,
server: www.example.ru, request: "HEAD
/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22
HTTP/1.1", upstream:
"http://10.23.23.15:6644/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22",
host: "www.example.ru"

We can't reproduce it in test environment(without real load). It
appears on different servers with different CentOS versions on it.
In most cases error appears after HEAD requests(by google bot, for example).

We uses proxy_cache requests, config:
proxy_cache_key "$request_method|$host|$uri?$args";
proxy_cache_path  /var/nginx/cache/html         levels=1:2
keys_zone=html-cache:18m max_size=5g inactive=60m;
proxy_cache html-cache;
proxy_cache_valid  200 302 301 10m;
proxy_cache_valid  304      10m;
proxy_cache_valid  404      1m;
proxy_cache_use_stale updating timeout error http_502 http_503 http_500;

So, when there's no file in cache path, and we made, for example, a
HEAD request, in some cases it generates an error.
Example with full debug in attachment.

# uname -a
Linux fe1 2.6.18-194.17.1.el5 #1 SMP Wed Sep 29 12:50:31 EDT 2010
x86_64 x86_64 x86_64 GNU/Linux

# nginx -V
nginx version: nginx/1.2.3
TLS SNI support disabled
configure arguments: --prefix=/var/nginx/ --sbin-path=/usr/sbin/nginx
--conf-path=/etc/nginx/nginx.conf
--error-log-path=/var/nginx/logs/error.log
--http-log-path=/var/nginx/logs/access.log
--pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock
--http-client-body-temp-path=/var/nginx/tmp/client_body
--http-proxy-temp-path=/var/nginx/tmp/proxy_temp
--http-fastcgi-temp-path=/var/nginx/tmp/fastcgi_temp
--http-uwsgi-temp-path=/var/nginx/tmp/uwsgi_temp
--http-scgi-temp-path=/var/nginx/tmp/scgi_temp --user=_nginx
--group=_nginx --with-http_ssl_module --with-http_realip_module
--with-http_addition_module --with-http_sub_module
--with-http_dav_module --with-http_flv_module --with-http_mp4_module
--with-http_gzip_static_module --with-http_random_index_module
--with-http_secure_link_module --with-http_stub_status_module
--with-file-aio --with-ipv6 --add-module=nginx_upstream_hash-0.3.1
--with-cc-opt='-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions
-fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic'


-- 
--
Andrey Feldman
-------------- next part --------------
2012/10/08 23:44:07 [debug] 25551#0: *79037 generic phase: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 rewrite phase: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "lwp-request/6.03 libwww-perl/6.03"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script if
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script if: false
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "HEAD"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script if
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script if: false
2012/10/08 23:44:07 [debug] 25551#0: *79037 using configuration "/"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http cl:-1 max:7340032
2012/10/08 23:44:07 [debug] 25551#0: *79037 rewrite phase: 3
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script if
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script if: false
2012/10/08 23:44:07 [debug] 25551#0: *79037 post rewrite phase: 4
2012/10/08 23:44:07 [debug] 25551#0: *79037 generic phase: 5
2012/10/08 23:44:07 [debug] 25551#0: *79037 generic phase: 6
2012/10/08 23:44:07 [debug] 25551#0: *79037 limit_req[0]: 0 0.000
2012/10/08 23:44:07 [debug] 25551#0: *79037 generic phase: 7
2012/10/08 23:44:07 [debug] 25551#0: *79037 limit conn: 9569EE24 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 add cleanup: 000000000D242058
2012/10/08 23:44:07 [debug] 25551#0: *79037 access phase: 8
2012/10/08 23:44:07 [debug] 25551#0: *79037 access phase: 9
2012/10/08 23:44:07 [debug] 25551#0: *79037 post access phase: 10
2012/10/08 23:44:07 [debug] 25551#0: *79037 posix_memalign: 000000000D242390:4096 @16
2012/10/08 23:44:07 [debug] 25551#0: *79037 http init upstream, client timer: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 epoll add event: fd:146 op:1 ev:80000004
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "HEAD"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "|"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "www.example.ru"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "|"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "/images/one/video_player.swf"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "?"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http cache key: "HEAD|www.example.ru|/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 add cleanup: 000000000D242318
2012/10/08 23:44:07 [debug] 25551#0: *79037 http file cache exists: -5 e:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 cache file: "/var/nginx/cache/html/6/63/ebe6688e7cc6dc7ce112182eb764d636"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream cache: -5
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "X-Forwarded-For: "
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "91.138.121.71"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "Host: "
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "www.example.ru"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "X-Real-IP: "
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script var: "91.138.121.71"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "
2012/10/08 23:44:07 [debug] 25551#0: *79037 http script copy: "Connection: close
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "TE: deflate,gzip;q=0.3"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "User-Agent: lwp-request/6.03 libwww-perl/6.03"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header:
2012/10/08 23:44:07 [debug] 25551#0: *79037 http cleanup add: 000000000D242AF0
2012/10/08 23:44:07 [debug] 25551#0: *79037 get rr peer, try: 2
2012/10/08 23:44:07 [debug] 25551#0: *79037 get rr peer, current: 0 -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 socket 147
2012/10/08 23:44:07 [debug] 25551#0: *79037 epoll add connection: fd:147 ev:80000005
2012/10/08 23:44:07 [debug] 25551#0: *79037 connect to 10.23.23.15:6644, fd:147 #79038
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream connect: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 posix_memalign: 000000000D23B560:128 @16
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer add: 147: 200000:1349725647874
2012/10/08 23:44:07 [debug] 25551#0: *79037 http finalize request: -4, "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22" a:1, c:2
2012/10/08 23:44:07 [debug] 25551#0: *79037 http request count:2 blk:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 http run request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream check client, write event:1, "/images/one/video_player.swf"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream recv(): -1 (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream send request handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream send request
2012/10/08 23:44:07 [debug] 25551#0: *79037 chain writer buf fl:1 s:297
2012/10/08 23:44:07 [debug] 25551#0: *79037 chain writer in: 000000000D242B28
2012/10/08 23:44:07 [debug] 25551#0: *79037 writev: 297
2012/10/08 23:44:07 [debug] 25551#0: *79037 chain writer out: 0000000000000000
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer del: 147: 1349725647874
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer add: 147: 300000:1349725747875
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process header
2012/10/08 23:44:07 [debug] 25551#0: *79037 malloc: 000000000D31F3F0:32768
2012/10/08 23:44:07 [debug] 25551#0: *79037 recv: fd:147 4344 of 32591
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy status 200 "200 OK"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Date: Mon, 08 Oct 2012 19:44:07 GMT"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Server: Oracle-Application-Server-11g"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Last-Modified: Tue, 05 Jun 2012 10:52:38 GMT"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "ETag: "2ba8080-21db7-4c1b772eaa980""
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Accept-Ranges: bytes"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Content-Length: 138679"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Cache-Control: max-age=3600"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Expires: Mon, 08 Oct 2012 20:44:07 GMT"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "X-BE-NODE: 1"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Connection: close"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Content-Type: application/x-shockwave-flash"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header: "Content-Language: en"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy header done
2012/10/08 23:44:07 [debug] 25551#0: *79037 HTTP/1.1 200 OK
2012/10/08 23:44:07 [debug] 25551#0: *79037 write new buf t:1 f:0 000000000D243118, pos 000000000D243118, size: 392 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 http write filter: l:1 f:0 s:392
2012/10/08 23:44:07 [debug] 25551#0: *79037 http write filter limit 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 writev: 392
2012/10/08 23:44:07 [debug] 25551#0: *79037 http write filter 0000000000000000
2012/10/08 23:44:07 [debug] 25551#0: *79037 http file cache set header
2012/10/08 23:44:07 [debug] 25551#0: *79037 http cacheable: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 posix_memalign: 000000000D31C3C0:4096 @16
2012/10/08 23:44:07 [debug] 25551#0: *79037 http proxy filter init s:200 h:0 c:0 l:138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe preread: 3951
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:28247
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 1448
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:26799
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 5399 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write busy: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write: out:0000000000000000, f:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 5399 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747877
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 post event 000000000D2B5458
2012/10/08 23:44:07 [debug] 25551#0: *79037 delete posted event 000000000D2B5458
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 post event 000000000D24D448
2012/10/08 23:44:07 [debug] 25551#0: *79037 post event 000000000D2B5458
2012/10/08 23:44:07 [debug] 25551#0: *79037 delete posted event 000000000D2B5458
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 delete posted event 000000000D24D448
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:26799
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 8688
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:18111
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 14087 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write busy: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write: out:0000000000000000, f:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 14087 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747877
2012/10/08 23:44:07 [debug] 25551#0: *79037 post event 000000000D24D448
2012/10/08 23:44:07 [debug] 25551#0: *79037 post event 000000000D2B5458
2012/10/08 23:44:07 [debug] 25551#0: *79037 delete posted event 000000000D2B5458
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 delete posted event 000000000D24D448
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:18111
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 11584
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:6527
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 25671 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write busy: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write: out:0000000000000000, f:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 25671 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 138679
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747878
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:6527
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 6527
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #0
2012/10/08 23:44:07 [debug] 25551#0: *79037 malloc: 000000000D22D330:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 3609
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:4583
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D31F3F0, pos 000000000D31F62A, size: 32198 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 3609 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 106481
2012/10/08 23:44:07 [debug] 25551#0: *79037 add cleanup: 000000000D31C558
2012/10/08 23:44:07 [debug] 25551#0: *79037 hashed path: /var/nginx/tmp/proxy_temp/0000004711
2012/10/08 23:44:07 [debug] 25551#0: *79037 temp fd:162
2012/10/08 23:44:07 [debug] 25551#0: *79037 write: 162, 000000000D31F3F0, 32768, 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write busy: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write: out:000000000D243380, f:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 http output filter "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http copy filter: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 read: 162, 000000000D31C6B8, 1024, 570
2012/10/08 23:44:07 [debug] 25551#0: *79037 http postpone filter "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22" 000000000D31CAB8
2012/10/08 23:44:07 [debug] 25551#0: *79037 http copy filter: -1 "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 3609 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 106481
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747878
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:32768
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 14480
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:22871
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 8192 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 9897 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 98289
2012/10/08 23:44:07 [debug] 25551#0: *79037 write: 162, 000000000D22D330, 8192, 32768
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 9897 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 98289
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747878
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 13032
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 22929 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 98289
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 22929 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 98289
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747878
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 2896
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 25825 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 98289
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 25825 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 98289
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747878
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 15135
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #2
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #3
2012/10/08 23:44:07 [debug] 25551#0: *79037 malloc: 000000000D200270:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 3689
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:4503
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 32768 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 8192 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 3689 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 57329
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 3689 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 57329
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747878
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 3:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 13032
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #4
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 2:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D200270, pos 000000000D200270, size: 8192 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 8529 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 49137
2012/10/08 23:44:07 [debug] 25551#0: *79037 write: 162, 000000000D200270, 8192, 81920
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 8529 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 49137
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747879
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 3:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 18824
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 3:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 27353 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 49137
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 27353 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 49137
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747879
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 3:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 17376
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #5
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #6
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 1:4423
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv() not ready (11: Resource temporarily unavailable)
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: -2
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 32768 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf in   s:1 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 8192 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 3769 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 8177
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 3769 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 8177
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747879
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream downstream error
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream dummy handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream process upstream
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe read upstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 3:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 4408
2012/10/08 23:44:07 [debug] 25551#0: *79037 readv: 3:8192
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe recv chain: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D200270, pos 000000000D200270, size: 8177 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D31F3F0, pos 000000000D31F3F0, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe buf free s:0 t:1 f:0 000000000D22D330, pos 000000000D22D330, size: 0 file: 0, size: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe length: 8177
2012/10/08 23:44:07 [debug] 25551#0: *79037 input buf #7
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D22D330
2012/10/08 23:44:07 [debug] 25551#0: *79037 write: 162, 000000000D200270, 8177, 131072
2012/10/08 23:44:07 [debug] 25551#0: *79037 pipe write downstream: 1
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer: 147, old: 1349725747875, new: 1349725747879
2012/10/08 23:44:07 [debug] 25551#0: *79037 http file cache update
2012/10/08 23:44:07 [debug] 25551#0: *79037 http file cache rename: "/var/nginx/tmp/proxy_temp/0000004711" to "/var/nginx/cache/html/6/63/ebe6688e7cc6dc7ce112182eb764d636"
2012/10/08 23:44:07 [debug] 25551#0: *79037 malloc: 000000000D23B5F0:71
2012/10/08 23:44:07 [debug] 25551#0: *79037 malloc: 000000000D327400:65536
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream exit: 0000000000000000
2012/10/08 23:44:07 [debug] 25551#0: *79037 finalize http upstream request: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 finalize http proxy request
2012/10/08 23:44:07 [debug] 25551#0: *79037 free rr peer 2 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 close http upstream connection: 147
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D23B560, unused: 48
2012/10/08 23:44:07 [debug] 25551#0: *79037 event timer del: 147: 1349725747875
2012/10/08 23:44:07 [debug] 25551#0: *79037 reusable connection: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 http upstream temp fd: 162
2012/10/08 23:44:07 [debug] 25551#0: *79037 http output filter "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http copy filter: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [alert] 25551#0: *79037 zero size buf in output t:0 r:0 f:0 000000000D31F3F0 000000000D31F3F0-000000000D3273F0 0000000000000000 0-0 while sending to client, client: 91.138.121.71, server: www.example.ru, request: "HEAD /images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22 HTTP/1.1", upstream: "http://10.23.23.15:6644/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22", host: "www.example.ru"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http postpone filter "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22" 000000000D31CBE8
2012/10/08 23:44:07 [debug] 25551#0: *79037 http copy filter: -1 "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http finalize request: -1, "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22" a:1, c:1
2012/10/08 23:44:07 [debug] 25551#0: *79037 http terminate request count:1
2012/10/08 23:44:07 [debug] 25551#0: *79037 http terminate cleanup count:1 blk:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 http posted request: "/images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22"
2012/10/08 23:44:07 [debug] 25551#0: *79037 http terminate handler count:1
2012/10/08 23:44:07 [debug] 25551#0: *79037 http request count:1 blk:0
2012/10/08 23:44:07 [debug] 25551#0: *79037 http close request
2012/10/08 23:44:07 [debug] 25551#0: *79037 http log handler
2012/10/08 23:44:07 [debug] 25551#0: *79037 run cleanup: 000000000D31C558
2012/10/08 23:44:07 [debug] 25551#0: *79037 file cleanup: fd:162
2012/10/08 23:44:07 [debug] 25551#0: *79037 run cleanup: 000000000D242318
2012/10/08 23:44:07 [debug] 25551#0: *79037 run cleanup: 000000000D242058
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D200270
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 0000000000000000
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D31F3F0
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D241380, unused: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D242390, unused: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D31C3C0, unused: 1719
2012/10/08 23:44:07 [debug] 25551#0: *79037 close http connection: 146
2012/10/08 23:44:07 [debug] 25551#0: *79037 reusable connection: 0
2012/10/08 23:44:07 [debug] 25551#0: *79037 free: 000000000D215960, unused: 440




More information about the nginx mailing list