странное поведение при отдаче файла при использовании proxy_cache
Vasiliy Tolstov
v.tolstov на selfip.ru
Пт Янв 27 00:06:07 UTC 2017
Всем доброй ночи.
Заметил странную вещь, nginx 1.9.10-1~bpo8+4 (пакет nginx-extras, знаю
сейчас будут лететь тухлые яйца, что надо пробовать чистый nginx).
Nginx используется как кеширующий фронтент для swift. При первом запросе
видео файла он берется с бекенда и отдается с Content-Type: video/mp4, но
как только он попадает в кеш, периодически он отдается с Content-Type:
text/plain. При этом его длина верная и на диске файл лежит в нормальном
виде (как видео).
Настройки для прокси:
proxy_connect_timeout 30s;
proxy_cache d0;
proxy_cache_valid 200 201 204 24h;
proxy_cache_valid 301 302 304 24h;
proxy_cache_valid 404 30m;
proxy_cache_valid 401
403 5m;
proxy_cache_valid any 5m;
proxy_cache_key $uri$is_args$args;
proxy_cache_methods GET;
proxy_cache_bypass $http_x_direct;
proxy_no_cache $http_x_auth_token;
proxy_ignore_headers "Cache-Control" "Expires" "Set-Cookie";
proxy_ignore_client_abort on;
proxy_pass http://backend;
debug log:
2017/01/27 02:59:42 [debug] 5034#5034: *307298342 event timer del: 103:
1485475257937
2017/01/27 02:59:42 [debug] 5034#5034: *307298342 reusable connection: 0
2017/01/27 02:59:42 [debug] 5034#5034: *307298342 free: 00007F4FD4C01FD0,
unused: 2704
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http header: "Host:
st.interneturok.com"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http header: "User-Agent:
curl/7.51.0"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http header: "Accept: */*"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http header done
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 event timer del: 84:
1485475243753
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 generic phase: 0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 rewrite phase: 1
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 posix_memalign:
00007F4FDAE14E90:4096 @16
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script value:
"CLODO_bef7b28b3d918e432ae6a6e45fc84b06"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script set $cs_acct
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 test location: "/"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 test location: ~
"\.(mp4|m4v|m4a)$"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 using configuration
"\.(mp4|m4v|m4a)$"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http cl:-1 max:5368709120
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 rewrite phase: 3
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 rewrite phase: 4
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script regex:
"^(.*)$"
2017/01/27 02:59:43 [notice] 5049#5049: *307298554 "^(.*)$" matches
"/video/geografy/8_klass/0004111.270.mp4", client: 92.255.100.1, server:
st.interneturok.com, request: "HEAD /video/geografy/8_klass/0004111.270.mp4
HTTP/1.1", host: "st.interneturok.com"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script copy:
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script capture:
"/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script regex end
2017/01/27 02:59:43 [notice] 5049#5049: *307298554 rewritten data:
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4",
args: "", client: 92.255.100.1, server: st.interneturok.com, request: "HEAD
/video/geografy/8_klass/0004111.270.mp4 HTTP/1.1", host: "
st.interneturok.com"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 rewrite phase: 5
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 headers more rewrite
handler, uri
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 post rewrite phase: 6
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 generic phase: 7
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 generic phase: 8
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 generic phase: 9
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 access phase: 10
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 access phase: 11
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 access phase: 12
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 access phase: 13
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 post access phase: 14
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 try files phase: 15
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http script var:
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 trying to use file:
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
"/srv/d1/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 try file uri:
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http set discard body
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http mp4 filename:
"/srv/d1/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 add cleanup:
00007F4FDAE151A0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 lua header filter for
user lua code, uri
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4"
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 uploadprogress
error-tracker error: 0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 xslt filter header
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 HTTP/1.1 200 OK
Server: nginx
Date: Thu, 26 Jan 2017 23:59:43 GMT
Content-Type: text/plain
Content-Length: 16876286
Last-Modified: Tue, 19 Feb 2013 15:17:34 GMT
Connection: keep-alive
ETag: "5123978e-10182fe"
Accept-Ranges: bytes
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 write new buf t:1 f:0
00007F4FDAE15378, pos 00007F4FDAE15378, size: 241 file: 0, size: 0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http write filter: l:1
f:0 s:241
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http write filter limit 0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 writev: 241 of 241
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http write filter
0000000000000000
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http finalize request: 0,
"/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4?"
a:1, c:1
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 set http keepalive handler
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http close request
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http log handler
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 run cleanup:
00007F4FDAE151A0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 file cleanup: fd:87
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 free: 00007F4FDB64E2F0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 free: 00007F4FD1AD83D0,
unused: 0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 free: 00007F4FDAE14E90,
unused: 2183
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 hc free: 0000000000000000
0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 hc busy: 0000000000000000
0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 tcp_nodelay
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 reusable connection: 1
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 event timer add: 84:
75000:1485475258753
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 post event
00007F4FCE6EC7F0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 delete posted event
00007F4FCE6EC7F0
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http keepalive handler
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 recv: fd:84 -1 of 1024
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 recv() not ready (11:
Resource temporarily unavailable)
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 http keepalive handler
2017/01/27 02:59:43 [debug] 5049#5049: *307298554 recv: fd:84 0 of 1024
2017/01/27 02:59:43 [info] 5049#5049: *307298554 client 92.255.100.1 closed
keepalive connection
При этом файл:
stat
/srv/d1/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4
File:
‘/srv/d1/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4’
Size: 16876286 Blocks: 33000 IO Block: 4096 regular file
Device: 6810h/26640d Inode: 383 Links: 1
Access: (0600/-rw-------) Uid: ( 33/www-data) Gid: ( 33/www-data)
Access: 2017-01-27 02:45:18.000000000 +0300
Modify: 2013-02-19 19:17:34.000000000 +0400
Change: 2017-01-27 02:45:17.000000000 +0300
Birth: -
file
/srv/d1/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4
/srv/d1/v1/CLODO_bef7b28b3d918e432ae6a6e45fc84b06/public/video/geografy/8_klass/0004111.270.mp4:
ISO Media, MP4 Base Media v1 [IS0 14496-12:2003]
--
Vasiliy Tolstov,
e-mail: v.tolstov at selfip.ru
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-ru/attachments/20170127/33aae241/attachment.html>
Подробная информация о списке рассылки nginx-ru