try_files is broken with geoip?

Peter Volkov peter.volkov at gmail.com
Mon Mar 30 17:26:13 UTC 2015


Hi!

We experience problem: if inside location we use geoip variable try_files
is not working and only root location is looked up for files.

So problem is reproducible with the following virtual server configuration
(full configuration in attachment):

==================
geo $dontsecure {
    default 0;
    172.16.11.0/24 1;
    127.0.0.0/24 1;
}

server {
    listen 172.16.11.31 default_server;
    listen 127.0.0.1 default_server;

    access_log  /var/log/nginx/production-dvr.access_log main;
    error_log  /var/log/nginx/production-dvr.error_log  debug;

    location ~ /([^/]*?)(_lang_[0-9])?/.*\.ts {


*       if ($dontsecure) {           set $reject_access 0;       }*

         root /tmp/test/;
         try_files /dir1$uri /dir2$uri =404;
    }
}
==================

/tmp/test has follofing files:
/tmp/test/dir2/test/1.ts - file
/tmp/test/dir1/test - directory

Now if we request http://172.16.11.31/test/1.ts nginx returns 404 until I
comment out selected by bold font lines. In debug log (debug-log-nginx.txt
in attachment) it's clear that try_files directive is doing nothing and
only /tmp/test/test/1.ts is looked up.

Now if I comment out this three bold lines in nginx works as expected and
looks up /tmp/test/dir1/test/1.ts or if it not exist
/tmp/test/dir2/test/1.ts file.

nginx version: nginx/1.7.11
TLS SNI support enabled
configure arguments: --prefix=/usr --conf-path=/etc/nginx/nginx.conf
--error-log-path=/var/log/nginx/error_log --pid-path=/run/nginx.pid
--lock-path=/run/lock/nginx.lock --with-cc-opt=-I/usr/include
--with-ld-opt=-L/usr/lib64 --http-log-path=/var/log/nginx/access_log
--http-client-body-temp-path=/var/lib/nginx/tmp/client
--http-proxy-temp-path=/var/lib/nginx/tmp/proxy
--http-fastcgi-temp-path=/var/lib/nginx/tmp/fastcgi
--http-scgi-temp-path=/var/lib/nginx/tmp/scgi
--http-uwsgi-temp-path=/var/lib/nginx/tmp/uwsgi --with-debug --with-ipv6
--with-pcre --with-http_flv_module --with-http_geoip_module
--with-http_mp4_module --with-http_secure_link_module
--with-http_realip_module
--add-module=external_module/nginx-rtmp-module-1.1.7
--add-module=external_module/nginx-push-stream-module-0.4.1
--with-http_ssl_module --without-mail_imap_module
--without-mail_pop3_module --without-mail_smtp_module --user=nginx
--group=nginx


--
Peter.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20150330/8541c363/attachment-0001.html>
-------------- next part --------------
2015/03/30 19:40:27 [debug] 2758#0: *363781 http process request line
2015/03/30 19:40:27 [debug] 2758#0: *363781 http request line: "GET /test/1.ts HTTP/1.1"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http uri: "/test/1.ts"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http args: ""
2015/03/30 19:40:27 [debug] 2758#0: *363781 http exten: "ts"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http process request header line
2015/03/30 19:40:27 [debug] 2758#0: *363781 http header: "Host: 172.16.11.31"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http header: "User-Agent: HTTPie/0.9.2"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http header: "Accept-Encoding: gzip, deflate"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http header: "Accept: */*"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http header: "Connection: keep-alive"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http header done
2015/03/30 19:40:27 [debug] 2758#0: *363781 event timer del: 895: 1427734227110
2015/03/30 19:40:27 [debug] 2758#0: *363781 generic phase: 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 rewrite phase: 1
2015/03/30 19:40:27 [debug] 2758#0: *363781 test location: ~ "/([^/]*?)(_lang_[0-9])?/.*\.ts"
2015/03/30 19:40:27 [debug] 2758#0: *363781 using configuration "/([^/]*?)(_lang_[0-9])?/.*\.ts"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http cl:-1 max:1048576
2015/03/30 19:40:27 [debug] 2758#0: *363781 rewrite phase: 3
2015/03/30 19:40:27 [debug] 2758#0: *363781 posix_memalign: 00007F4406DF7650:4096 @16
2015/03/30 19:40:27 [debug] 2758#0: *363781 http script var
2015/03/30 19:40:27 [debug] 2758#0: *363781 http geo started: 172.16.11.32
2015/03/30 19:40:27 [debug] 2758#0: *363781 http geo: 1
2015/03/30 19:40:27 [debug] 2758#0: *363781 http script var: "1"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http script if
2015/03/30 19:40:27 [debug] 2758#0: *363781 http script value: "0"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http script set $reject_access
2015/03/30 19:40:27 [debug] 2758#0: *363781 post rewrite phase: 4
2015/03/30 19:40:27 [debug] 2758#0: *363781 generic phase: 5
2015/03/30 19:40:27 [debug] 2758#0: *363781 generic phase: 6
2015/03/30 19:40:27 [debug] 2758#0: *363781 generic phase: 7
2015/03/30 19:40:27 [debug] 2758#0: *363781 access phase: 8
2015/03/30 19:40:27 [debug] 2758#0: *363781 access phase: 9
2015/03/30 19:40:27 [debug] 2758#0: *363781 post access phase: 10
2015/03/30 19:40:27 [debug] 2758#0: *363781 try files phase: 11
2015/03/30 19:40:27 [debug] 2758#0: *363781 content phase: 12
2015/03/30 19:40:27 [debug] 2758#0: *363781 content phase: 13
2015/03/30 19:40:27 [debug] 2758#0: *363781 content phase: 14
2015/03/30 19:40:27 [debug] 2758#0: *363781 http filename: "/tmp/test/test/1.ts"
2015/03/30 19:40:27 [debug] 2758#0: *363781 add cleanup: 00007F4406DF7610
2015/03/30 19:40:27 [error] 2758#0: *363781 open() "/tmp/test/test/1.ts" failed (2: No such file or directory), client: 172.16.11.32, server: , request: "GET /test/1.ts HTTP/1.1", host: "172.16.11.31"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http finalize request: 404, "/test/1.ts?" a:1, c:1
2015/03/30 19:40:27 [debug] 2758#0: *363781 http special response: 404, "/test/1.ts?"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http set discard body
2015/03/30 19:40:27 [debug] 2758#0: *363781 HTTP/1.1 404 Not Found
Server: nginx/1.7.11
Date: Mon, 30 Mar 2015 16:40:27 GMT
Content-Type: text/html
Content-Length: 169
Connection: keep-alive
Keep-Alive: timeout=20

2015/03/30 19:40:27 [debug] 2758#0: *363781 write new buf t:1 f:0 00007F4406DF77B8, pos 00007F4406DF77B8, size: 179 file: 0, size: 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 http write filter: l:0 f:0 s:179
2015/03/30 19:40:27 [debug] 2758#0: *363781 http write filter limit 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 writev: 179 of 179
2015/03/30 19:40:27 [debug] 2758#0: *363781 http write filter 0000000000000000
2015/03/30 19:40:27 [debug] 2758#0: *363781 http output filter "/test/1.ts?"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http copy filter: "/test/1.ts?"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http postpone filter "/test/1.ts?" 00007F4406DF7890
2015/03/30 19:40:27 [debug] 2758#0: *363781 write new buf t:0 f:0 0000000000000000, pos 00007F440555A5A0, size: 116 file: 0, size: 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 write new buf t:0 f:0 0000000000000000, pos 00007F440555ACE0, size: 53 file: 0, size: 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 http write filter: l:1 f:0 s:169
2015/03/30 19:40:27 [debug] 2758#0: *363781 http write filter limit 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 writev: 169 of 169
2015/03/30 19:40:27 [debug] 2758#0: *363781 http write filter 0000000000000000
2015/03/30 19:40:27 [debug] 2758#0: *363781 http copy filter: 0 "/test/1.ts?"
2015/03/30 19:40:27 [debug] 2758#0: *363781 http finalize request: 0, "/test/1.ts?" a:1, c:1
2015/03/30 19:40:27 [debug] 2758#0: *363781 set http keepalive handler
2015/03/30 19:40:27 [debug] 2758#0: *363781 http close request
2015/03/30 19:40:27 [debug] 2758#0: *363781 http log handler
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF6640, unused: 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF7650, unused: 3055
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF4640
2015/03/30 19:40:27 [debug] 2758#0: *363781 hc free: 0000000000000000 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 hc busy: 0000000000000000 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 tcp_nodelay
2015/03/30 19:40:27 [debug] 2758#0: *363781 reusable connection: 1
2015/03/30 19:40:27 [debug] 2758#0: *363781 event timer add: 895: 75000:1427733702110
2015/03/30 19:40:27 [debug] 2758#0: *363781 post event 00007F4406CF54F0
2015/03/30 19:40:27 [debug] 2758#0: *363781 delete posted event 00007F4406CF54F0
2015/03/30 19:40:27 [debug] 2758#0: *363781 http keepalive handler
2015/03/30 19:40:27 [debug] 2758#0: *363781 malloc: 00007F4406DF4640:1024
2015/03/30 19:40:27 [debug] 2758#0: *363781 recv: fd:895 -1 of 1024
2015/03/30 19:40:27 [debug] 2758#0: *363781 recv() not ready (11: Resource temporarily unavailable)
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF4640
2015/03/30 19:40:27 [debug] 2758#0: *363781 post event 00007F4406CF54F0
2015/03/30 19:40:27 [debug] 2758#0: *363781 delete posted event 00007F4406CF54F0
2015/03/30 19:40:27 [debug] 2758#0: *363781 http keepalive handler
2015/03/30 19:40:27 [debug] 2758#0: *363781 malloc: 00007F4406DF6EC0:1024
2015/03/30 19:40:27 [debug] 2758#0: *363781 recv: fd:895 0 of 1024
2015/03/30 19:40:27 [info] 2758#0: *363781 client 172.16.11.32 closed keepalive connection
2015/03/30 19:40:27 [debug] 2758#0: *363781 close http connection: 895
2015/03/30 19:40:27 [debug] 2758#0: *363781 event timer del: 895: 1427733702110
2015/03/30 19:40:27 [debug] 2758#0: *363781 reusable connection: 0
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF6EC0
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF4420, unused: 8
2015/03/30 19:40:27 [debug] 2758#0: *363781 free: 00007F4406DF4530, unused: 72



More information about the nginx mailing list