Re: store_proxy не сохраняет файлы

greenh greenh at gmail.com
Mon Nov 10 19:52:01 UTC 2014


Включил дебаг (с пересборкой nginx). Конфиг приобрел следующий вид
server {
listen *:80;
server_name img.mgshare.com  img-a6.site1.com ;
root /home/site1/site1.com;

    location ~* \.(jpg|jpeg|gif|png|ico|css|bmp|swf|js|html|txt)$ {
root /home/site1/site1.com/;
        try_files $uri $uri/ @fallback;
        error_log  /home/site1/logs/site1.com-img-error.log debug ;
    }

    location @fallback
    {
proxy_pass http://db.site1.com;
proxy_store /home/site1/site1.com/$request_uri;
# proxy_store /home/site1/site1.com/111;
proxy_cache_key  $host$uri$query_string;
root /home/site1/site1.com;
proxy_store_access  user:rw  group:rw  all:rw;
        error_log  /home/site1/logs/fallback-error.log debug;
        access_log  /home/site1/logs/fallback-access.log ;
    }

}
А дальше замечено странное: при обращении к jpg файлам запись НЕ
производится, но к урлу добавить что нить, например site1.com/1.jpg?aaaa -
то файл записывается нормально.
Вот логи на 1.jpg:
Куда смотреть дальше?

site1.com-img-error.log:
2014/11/10 22:44:19 [debug] 60244#0: *573 http cl:-1 max:1048576
2014/11/10 22:44:19 [debug] 60244#0: *573 rewrite phase: 2
2014/11/10 22:44:19 [debug] 60244#0: *573 post rewrite phase: 3
2014/11/10 22:44:19 [debug] 60244#0: *573 generic phase: 4
2014/11/10 22:44:19 [debug] 60244#0: *573 generic phase: 5
2014/11/10 22:44:19 [debug] 60244#0: *573 access phase: 6
2014/11/10 22:44:19 [debug] 60244#0: *573 access phase: 7
2014/11/10 22:44:19 [debug] 60244#0: *573 post access phase: 8
2014/11/10 22:44:19 [debug] 60244#0: *573 try files phase: 9
2014/11/10 22:44:19 [debug] 60244#0: *573 http script var: "/1.jpg"
2014/11/10 22:44:19 [debug] 60244#0: *573 trying to use file: "/1.jpg"
"/home/site1/site1.com/1.jpg"
2014/11/10 22:44:19 [debug] 60244#0: *573 http script var: "/1.jpg"
2014/11/10 22:44:19 [debug] 60244#0: *573 trying to use dir: "/1.jpg"
"/home/site1/site1.com/1.jpg"
2014/11/10 22:44:19 [debug] 60244#0: *573 trying to use file: "@fallback"
"/home/site1/site1.com at fallback"
2014/11/10 22:44:19 [debug] 60244#0: *573 test location: "@fallback"
2014/11/10 22:44:19 [debug] 60244#0: *573 using location: @fallback
"/1.jpg?"

fallback-error.log:
2014/11/10 22:44:19 [debug] 60244#0: *573 rewrite phase: 2
2014/11/10 22:44:19 [debug] 60244#0: *573 post rewrite phase: 3
2014/11/10 22:44:19 [debug] 60244#0: *573 generic phase: 4
2014/11/10 22:44:19 [debug] 60244#0: *573 generic phase: 5
2014/11/10 22:44:19 [debug] 60244#0: *573 access phase: 6
2014/11/10 22:44:19 [debug] 60244#0: *573 access phase: 7
2014/11/10 22:44:19 [debug] 60244#0: *573 post access phase: 8
2014/11/10 22:44:19 [debug] 60244#0: *573 try files phase: 9
2014/11/10 22:44:19 [debug] 60244#0: *573 http init upstream, client timer:
0
2014/11/10 22:44:19 [debug] 60244#0: *573 kevent set event: 324: ft:-2
fl:0025
2014/11/10 22:44:19 [debug] 60244#0: *573 http script copy: "Host: "
2014/11/10 22:44:19 [debug] 60244#0: *573 http script var: "db.site1.com"
2014/11/10 22:44:19 [debug] 60244#0: *573 http script copy: "
"
2014/11/10 22:44:19 [debug] 60244#0: *573 http script copy: "Connection:
close
"
2014/11/10 22:44:19 [debug] 60244#0: *573 http script copy: ""
2014/11/10 22:44:19 [debug] 60244#0: *573 http script copy: ""
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"Cache-Control: max-age=0"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "User-Agent:
Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/38.0.2125.111 Safari/537.36"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"Accept-Encoding: gzip,deflate,sdch"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"Accept-Language: ru-RU,ru;q=0.8,en-US;q=0.6,en;q=0.4"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "Cookie:
_ym_visorc_22428427=w; _ga=GA1.2.863053105.1404152211; _gat=1;
_ym_visorc_17454814=b"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"If-None-Match: "545f6fac-8cb2""
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"If-Modified-Since: Sun, 09 Nov 2014 13:44:12 GMT"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"GET /1.jpg HTTP/1.0
Host: db.site1.com
Connection: close
Cache-Control: max-age=0
Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML,
like Gecko) Chrome/38.0.2125.111 Safari/537.36
Accept-Encoding: gzip,deflate,sdch
Accept-Language: ru-RU,ru;q=0.8,en-US;q=0.6,en;q=0.4
Cookie: _ym_visorc_22428427=w; _ga=GA1.2.863053105.1404152211; _gat=1;
_ym_visorc_17454814=b
If-None-Match: "545f6fac-8cb2"
If-Modified-Since: Sun, 09 Nov 2014 13:44:12 GMT

"
2014/11/10 22:44:19 [debug] 60244#0: *573 http cleanup add: 0000000802470FC0
2014/11/10 22:44:19 [debug] 60244#0: *573 get rr peer, try: 1
2014/11/10 22:44:19 [debug] 60244#0: *573 socket 49
2014/11/10 22:44:19 [debug] 60244#0: *573 connect to 91.109.201.5:80, fd:49
#1404
2014/11/10 22:44:19 [debug] 60244#0: *573 kevent set event: 49: ft:-1
fl:0025
2014/11/10 22:44:19 [debug] 60244#0: *573 kevent set event: 49: ft:-2
fl:0025
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream connect: -2
2014/11/10 22:44:19 [debug] 60244#0: *573 posix_memalign:
0000000802422800:128 @16
2014/11/10 22:44:19 [debug] 60244#0: *573 event timer add: 49:
60000:1415648719950
2014/11/10 22:44:19 [debug] 60244#0: *573 http finalize request: -4,
"/1.jpg?" a:1, c:3
2014/11/10 22:44:19 [debug] 60244#0: *573 http request count:3 blk:0
2014/11/10 22:44:19 [debug] 60244#0: *573 http finalize request: -4,
"/1.jpg?" a:1, c:2
2014/11/10 22:44:19 [debug] 60244#0: *573 http request count:2 blk:0
2014/11/10 22:44:19 [debug] 60244#0: *573 post event 000000080257D0A0
2014/11/10 22:44:19 [debug] 60244#0: *573 delete posted event
000000080257D0A0
2014/11/10 22:44:19 [debug] 60244#0: *573 http run request: "/1.jpg?"
2014/11/10 22:44:19 [debug] 60244#0: *573 http request empty handler
2014/11/10 22:44:19 [debug] 60244#0: *573 post event 000000080257E3E0
2014/11/10 22:44:19 [debug] 60244#0: *573 delete posted event
000000080257E3E0
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream request: "/1.jpg?"
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream send request handler
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream send request
2014/11/10 22:44:19 [debug] 60244#0: *573 chain writer buf fl:1 s:563
2014/11/10 22:44:19 [debug] 60244#0: *573 chain writer in: 000000080248A9D0
2014/11/10 22:44:19 [debug] 60244#0: *573 writev: 563 of 563
2014/11/10 22:44:19 [debug] 60244#0: *573 chain writer out: 0000000000000000
2014/11/10 22:44:19 [debug] 60244#0: *573 event timer del: 49: 1415648719950
2014/11/10 22:44:19 [debug] 60244#0: *573 event timer add: 49:
60000:1415648719953
2014/11/10 22:44:19 [debug] 60244#0: *573 post event 000000080257E3E0
2014/11/10 22:44:19 [debug] 60244#0: *573 post event 00000008025623E0
2014/11/10 22:44:19 [debug] 60244#0: *573 delete posted event
00000008025623E0
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream request: "/1.jpg?"
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream process header
2014/11/10 22:44:19 [debug] 60244#0: *573 malloc: 0000000802494000:4096
2014/11/10 22:44:19 [debug] 60244#0: *573 recv: eof:0, avail:175, err:0
2014/11/10 22:44:19 [debug] 60244#0: *573 recv: fd:49 175 of 4096
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy status 304 "304 Not
Modified"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "Server:
nginx/1.6.2"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "Date: Mon, 10
Nov 2014 23:42:59 GMT"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header:
"Last-Modified: Sun, 09 Nov 2014 13:44:12 GMT"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "Connection:
close"
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header: "ETag:
"545f6fac-8cb2""
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy header done
2014/11/10 22:44:19 [debug] 60244#0: *573 HTTP/1.1 304 Not Modified
Server: nginx/1.6.2
Date: Mon, 10 Nov 2014 19:44:19 GMT
Connection: keep-alive
Last-Modified: Sun, 09 Nov 2014 13:44:12 GMT
ETag: "545f6fac-8cb2"

2014/11/10 22:44:19 [debug] 60244#0: *573 write new buf t:1 f:0
000000080248AC80, pos 000000080248AC80, size: 180 file: 0, size: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 http write filter: l:0 f:0 s:180
2014/11/10 22:44:19 [debug] 60244#0: *573 http cacheable: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 http proxy filter init s:304 h:0
c:0 l:-1
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream process upstream
2014/11/10 22:44:19 [debug] 60244#0: *573 pipe read upstream: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 pipe preread: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 pipe buf free s:0 t:1 f:0
0000000802494000, pos 00000008024940AF, size: 0 file: 0, size: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 pipe length: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 pipe write downstream: 1
2014/11/10 22:44:19 [debug] 60244#0: *573 pipe write downstream done
2014/11/10 22:44:19 [debug] 60244#0: *573 event timer: 49, old:
1415648719953, new: 1415648719954
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream exit:
0000000000000000
2014/11/10 22:44:19 [debug] 60244#0: *573 finalize http upstream request: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 finalize http proxy request
2014/11/10 22:44:19 [debug] 60244#0: *573 free rr peer 1 0
2014/11/10 22:44:19 [debug] 60244#0: *573 close http upstream connection: 49
2014/11/10 22:44:19 [debug] 60244#0: *573 free: 0000000802422800, unused: 48
2014/11/10 22:44:19 [debug] 60244#0: *573 event timer del: 49: 1415648719953
2014/11/10 22:44:19 [debug] 60244#0: *573 delete posted event
000000080257E3E0
2014/11/10 22:44:19 [debug] 60244#0: *573 reusable connection: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 http upstream temp fd: -1
2014/11/10 22:44:19 [debug] 60244#0: *573 http output filter "/1.jpg?"
2014/11/10 22:44:19 [debug] 60244#0: *573 http copy filter: "/1.jpg?"
2014/11/10 22:44:19 [debug] 60244#0: *573 http postpone filter "/1.jpg?"
00007FFFFFFFE780
2014/11/10 22:44:19 [debug] 60244#0: *573 write old buf t:1 f:0
000000080248AC80, pos 000000080248AC80, size: 180 file: 0, size: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 write new buf t:0 f:0
0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2014/11/10 22:44:19 [debug] 60244#0: *573 http write filter: l:1 f:0 s:180
2014/11/10 22:44:19 [debug] 60244#0: *573 http write filter limit 0
2014/11/10 22:44:19 [debug] 60244#0: *573 writev: 180 of 180
2014/11/10 22:44:19 [debug] 60244#0: *573 http write filter 0000000000000000
2014/11/10 22:44:19 [debug] 60244#0: *573 http copy filter: 0 "/1.jpg?"
2014/11/10 22:44:19 [debug] 60244#0: *573 http finalize request: 0,
"/1.jpg?" a:1, c:1
2014/11/10 22:44:19 [debug] 60244#0: *573 set http keepalive handler
2014/11/10 22:44:19 [debug] 60244#0: *573 http close request
2014/11/10 22:44:19 [debug] 60244#0: *573 http log handler
2014/11/10 22:44:19 [debug] 60244#0: *573 free: 0000000802494000
2014/11/10 22:44:19 [debug] 60244#0: *573 free: 0000000802470000, unused: 8
2014/11/10 22:44:19 [debug] 60244#0: *573 free: 000000080248A000, unused: 44
2014/11/10 22:44:19 [debug] 60244#0: *573 free: 0000000802406800
2014/11/10 22:44:19 [debug] 60244#0: *573 hc free: 0000000000000000 0
2014/11/10 22:44:19 [debug] 60244#0: *573 hc busy: 0000000000000000 0
2014/11/10 22:44:19 [debug] 60244#0: *573 tcp_nodelay
2014/11/10 22:44:19 [debug] 60244#0: *573 reusable connection: 1
2014/11/10 22:44:19 [debug] 60244#0: *573 event timer add: 324:
65000:1415648724954
2014/11/10 22:44:20 [debug] 60244#0: *573 http empty handler
2014/11/10 22:45:24 [debug] 60244#0: *573 event timer del: 324:
1415648724954
2014/11/10 22:45:24 [debug] 60244#0: *573 http keepalive handler
2014/11/10 22:45:24 [debug] 60244#0: *573 close http connection: 324
2014/11/10 22:45:24 [debug] 60244#0: *573 reusable connection: 0
2014/11/10 22:45:24 [debug] 60244#0: *573 free: 0000000000000000
2014/11/10 22:45:24 [debug] 60244#0: *573 free: 00000008025AC000, unused: 0
2014/11/10 22:45:24 [debug] 60244#0: *573 free: 00000008025AC100, unused:
120



10 ноября 2014 г., 11:15 пользователь Валентин Бартенев <vbart at nginx.com>
написал:

> On Monday 10 November 2014 11:12:52 greenh wrote:
> > поставил error log в  debug. ВОобще пусто
> [..]
>
> Помимо этого nginx должен быть собран с опцией --with-debug.
> Смотрите документацию: http://nginx.org/r/error_log/ru
>
> --
> Валентин Бартенев
> _______________________________________________
> nginx-ru mailing list
> nginx-ru at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx-ru
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-ru/attachments/20141110/befa9a28/attachment-0001.html>


Подробная информация о списке рассылки nginx-ru