Does Nginx honor DNS TTLs for proxy upstreams?

[luislavena]

I have a short question on Nginx’s proxy module. In our setup we reverse
proxy specific requests to the server of an external partner via
proxy_pass. Over the weekend the partner updated DNS but Nginx wasn’t
catching up the change and still sent traffic to the old server despite
the fact the TTL of the record was little enough.

An additional obstacle might be that in our case we have for example

proxy_pass http://foo.example.com;

where foo.example.com is a CNAME to bar.example.com (TTL of 1 hour)
which is a A record (TTL of 60 seconds).

Does Nginx honor DNS changes for upstream proxies or are lookups only
done once on startup? If not, will the TTL being honor even if it has to
traverse a list of CNAME records until it hits an A record?

Both configuration directives, resolver and resolver_timeout are not
set, therefore the default of 30 seconds should apply (if that is
relevant here).

$ nginx -V
nginx: nginx version: nginx/1.0.3
nginx: configure arguments: --prefix=/usr/share/nginx
–conf-path=/etc/nginx/nginx.conf --sbin-path=/usr/sbin/nginx
–http-log-path=/var/log/nginx/access.log
–error-log-path=/var/log/nginx/error.log --pid-path=/var/run/nginx.pid
–user=nginx --group=nginx --with-http_geoip_module
–with-http_gzip_static_module --with-http_realip_module
–with-http_secure_link_module --with-http_stub_status_module
–add-module=…/agentzh-echo-nginx-module-1c4e116
–add-module=…/ngx-fancyindex-0.3.1
–add-module=…/agentzh-headers-more-nginx-module-2cbbc15

Thanks in advance!

Posted at Nginx Forum:

Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Hello!

On Mon, Sep 26, 2011 at 04:42:07AM -0400, csg wrote:

where foo.example.com is a CNAME to bar.example.com (TTL of 1 hour)
which is a A record (TTL of 60 seconds).

Does Nginx honor DNS changes for upstream proxies or are lookups only
done once on startup? If not, will the TTL being honor even if it has to
traverse a list of CNAME records until it hits an A record?

No, domain names statically configured in config are only looked
up once on startup (or configuration reload).

Both configuration directives, resolver and resolver_timeout are not
set, therefore the default of 30 seconds should apply (if that is
relevant here).

These are not relevant for “proxy_pass http://foo.example.com;”.
Resolver is only used for proxy_pass with variables, i.e.
something like

resolver 127.0.0.1;
set $backend "foo.example.com";
proxy_pass http://$backend;

In such setup ip address of “foo.example.com” will be looked up
dynamically and result will be cached for 5 minutes.

Maxim D.

[csg]

Maxim D. Wrote:

dynamically and result will be cached for 5
minutes.

Thanks Maxim, that would be great but is it really supposed to work (in
the stable branch)? The 1.0.3 which was deployed up to now gave me

no host in upstream “”

errors, with 1.0.6 I am getting

invalid URL prefix in “http://”

errors. If it helps I can try to setup a simplified test case, because
posting the full configuration would certainly exceed some acceptable
message limit of this list/forum.

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Maxim D. Wrote:

Errors suggest you don’t have $backend set, and
resulting
proxy_pass tries to go to “http://” which is
invalid.

Yup, I am just curious how to accomplish that if you want to perform
some rewriting before, for example to strip off some leading parts of
the URL path. I came up with following test case:

worker_processes 3;

events {
worker_connections 1024;
}

http {
server_tokens off;

include                             nginx.mime.types;
default_type                        application/octet-stream;

sendfile                            on;
keepalive_timeout                   15;

server {
    listen                          0.0.0.0:90;
    server_name                     _;

    location                        / {
        root                        html;
        index                       index.html;
    }
}

server {
    listen                          0.0.0.0:91;
    server_name                     _;

    location                        / {
        rewrite                     ^/foo/(.*)$  /$1  break;

        proxy_pass                  http://localhost:90;
        proxy_redirect              off;
    }
}

server {
    listen                          0.0.0.0:92;
    server_name                     _;

    location                        / {
        rewrite                     ^/foo/(.*)$  /$1  break;

        resolver                    127.0.0.1;

        set                         $backend  "localhost:90";
        proxy_pass                  http://$backend;
        proxy_redirect              off;
    }

    error_log                       /var/log/nginx/error.log

debug;
}
}

The port 91 server is a reverse proxy to the port 90 server with static
upstream (DNS lookup only on startup/reload). I delivers happily the
index.html of the port 90 server, regardless if I request
http://localhost:91/ of http://localhost:91/foo/.

Bringing the resolver into play doesn’t seem to be that straight forward
if you look at the port 92 reverse proxy. It works when no rewriting has
to be performed, i.e., http://localhost:92/ works. But if I want to
strip off the leading /foo/ URL path segment of the request
http://localhost:92/foo/.

2011/09/28 17:55:51 [notice] 1490#0: 2 "^/foo/(.)$" matches “/foo/”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/28 17:55:51 [notice] 1490#0: *2 rewritten data: “/”, args: “”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/28 17:55:51 [warn] 1490#0: *2 using uninitialized “backend”
variable, client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”,
host: “localhost:92”
2011/09/28 17:55:51 [error] 1490#0: *2 invalid URL prefix in “http://”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”

Any hints how to solve this the easiest way? Basically me requirement is
to reverse proxy http://proxy.example.com/foo/bar/quux to
http://upstream.example.com/bar/quux (so strip off “foo/”) while the IP
of upstream.example.com can change over time without prior announcement.

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Hello!

On Mon, Sep 26, 2011 at 09:40:53AM -0400, csg wrote:

In such setup ip address of “foo.example.com” will

invalid URL prefix in “http://”

errors. If it helps I can try to setup a simplified test case, because
posting the full configuration would certainly exceed some acceptable
message limit of this list/forum.

Errors suggest you don’t have $backend set, and resulting
proxy_pass tries to go to “http://” which is invalid.

Maxim D.

[csg]

Hello!

On Wed, Sep 28, 2011 at 12:05:07PM -0400, csg wrote:

Maxim D. Wrote:

Errors suggest you don’t have $backend set, and
resulting
proxy_pass tries to go to “http://” which is
invalid.

Yup, I am just curious how to accomplish that if you want to perform
some rewriting before, for example to strip off some leading parts of
the URL path. I came up with following test case:

[…]

    location                        / {
        rewrite                     ^/foo/(.*)$  /$1  break;

The “break” here will stop execution of rewrite module directives
(including “set” below) on match.

        resolver                    127.0.0.1;

        set                         $backend  "localhost:90";

This “set” won’t be executed due to break above…

        proxy_pass                  http://$backend;

… and $backend won’t be set as a result. Moving “set” before
“rewrite … break” will do the trick.

Maxim D.

[csg]

Maxim D. Wrote:

Hello again!

… and $backend won’t be set as a result.
Moving “set” before
“rewrite … break” will do the trick.

Right, in this case the $backend applies to proxy_pass and the request
gets proxied but unfortunatelly in this case the rewrite rule does not
have effect anymore. It still gets applied according to the error logs,
but instead of the rewritten URL path to original one gets proxied. To
make it more clear I changed the example configuration I posted above by
having each virtual host its own access and error log.

When I run following test …

$ curl -s -o - -D - http://localhost:92/foo/
HTTP/1.1 404 Not Found
Server: nginx
Date: Wed, 28 Sep 2011 19:26:04 GMT
Content-Type: text/html
Connection: keep-alive
Content-Length: 162

404 Not Found

404 Not Found

---

nginx

I will get this in the error logs

tail -F /var/log/nginx/{access,error}9[012].log

==> /var/log/nginx/access90.log <==
127.0.0.1 - - [28/Sep/2011:21:26:04 +0200] “GET /foo/ HTTP/1.0” 404 162
“-” “curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”

==> /var/log/nginx/access92.log <==
127.0.0.1 - - [28/Sep/2011:21:26:04 +0200] “GET /foo/ HTTP/1.1” 404 162
“-” “curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”

==> /var/log/nginx/error90.log <==
2011/09/28 21:26:04 [error] 3078#0: *15
“/usr/share/nginx/html/foo/index.html” is not found (2: No such file or
directory), client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.0”,
host: “localhost:90”

==> /var/log/nginx/error92.log <==
2011/09/28 21:26:04 [notice] 3078#0: 13 "^/foo/(.)$" matches “/foo/”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/28 21:26:04 [notice] 3078#0: *13 rewritten data: “/”, args: “”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/28 21:26:04 [notice] 3078#0: 13 "^/foo/(.)$" does not match
“/”, client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/28 21:26:04 [info] 3078#0: *13 client 127.0.0.1 closed keepalive
connection

If this in not what you would expect, I can rebuild Nginx with
–with-debug tomorrow and repeat the test.

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Ah sorry, just saw your patch … will give that a try! Many thanks

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Hello!

On Wed, Sep 28, 2011 at 03:35:50PM -0400, csg wrote:

have effect anymore. It still gets applied according to the error logs,
but instead of the rewritten URL path to original one gets proxied. To
make it more clear I changed the example configuration I posted above by
having each virtual host its own access and error log.

This looks like a bug (or at least misfeature). Please try the
attached patch.

Maxim D.

[csg]

I can confirm that the patch fixes the issue on my test setup Will
add it to my Nginx package and deploy it on production.

Many thanks Maxim for your fantastic support on this issue (and all the
work you do on this amazing and very helpful list)!

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Here as a follow up the debug output plus additional information:

nginx -V

nginx: nginx version: nginx/1.0.6
nginx: configure arguments: --with-debug --prefix=/usr/share/nginx
–conf-path=/etc/nginx/nginx.conf --sbin-path=/usr/sbin/nginx
–http-log-path=/var/log/nginx/access.log
–error-log-path=/var/log/nginx/error.log --pid-path=/var/run/nginx.pid
–user=nginx --group=nginx --with-http_geoip_module
–with-http_gzip_static_module --with-http_realip_module
–with-http_secure_link_module --with-http_stub_status_module
–add-module=…/chaoslawful-drizzle-nginx-module-1fc3af0
–add-module=…/agentzh-echo-nginx-module-13dd12f
–add-module=…/ngx-fancyindex-0.3.1
–add-module=…/agentzh-headers-more-nginx-module-137855d
–add-module=…/ngx_http_upstream_keepalive-2ee28064a04a
–add-module=…/agentzh-memc-nginx-module-4f1952c
–add-module=…/simpl-ngx_devel_kit-bc97eea
–add-module=…/chaoslawful-lua-nginx-module-dd0d4d0
–add-module=…/agentzh-rds-csv-nginx-module-eb697d1
–add-module=…/agentzh-rds-json-nginx-module-376db1f

cat /etc/nginx/nginx.conf

/etc/nginx/nginx.conf

worker_processes 3;

events {
worker_connections 1024;
}

http {
server_tokens off;

include                             nginx.mime.types;
default_type                        application/octet-stream;

sendfile                            on;
keepalive_timeout                   15;

server {
    listen                          0.0.0.0:90;
    server_name                     _;

    location                        / {
        root                        html;
        index                       index.html;
    }

    access_log                      /var/log/nginx/access90.log;
    error_log                       /var/log/nginx/error90.log

debug;
}

server {
    listen                          0.0.0.0:91;
    server_name                     _;

    location                        / {
        rewrite                     ^/foo/(.*)$  /$1  break;

        proxy_pass                  http://localhost:90;
        proxy_redirect              off;
    }

    access_log                      /var/log/nginx/access91.log;
    error_log                       /var/log/nginx/error91.log

debug;
}

server {
    listen                          0.0.0.0:92;
    server_name                     _;

    location                        / {
        set                         $backend  "localhost:90";

        rewrite                     ^/foo/(.*)$  /$1  break;

        resolver                    127.0.0.1;

        proxy_pass                  http://$backend;
        proxy_redirect              off;
    }

    access_log                      /var/log/nginx/access92.log;
    error_log                       /var/log/nginx/error92.log

debug;
}
}

$ curl -s -o - -D - http://localhost:92/foo/
HTTP/1.1 404 Not Found
Server: nginx
Date: Thu, 29 Sep 2011 07:21:07 GMT
Content-Type: text/html
Connection: keep-alive
Content-Length: 162

404 Not Found

404 Not Found

---

nginx

cat access92.log

127.0.0.1 - - [29/Sep/2011:09:21:07 +0200] “GET /foo/ HTTP/1.1” 404 162
“-” “curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”

cat access90.log

127.0.0.1 - - [29/Sep/2011:09:21:07 +0200] “GET /foo/ HTTP/1.0” 404 162
“-” “curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”

cat error92.log

2011/09/29 09:21:05 [debug] 3565#0: epoll add event: fd:13 op:1
ev:00000001
2011/09/29 09:21:07 [debug] 3565#0: post event 0A15AC50
2011/09/29 09:21:07 [debug] 3565#0: delete posted event 0A15AC50
2011/09/29 09:21:07 [debug] 3565#0: accept on 0.0.0.0:92, ready: 0
2011/09/29 09:21:07 [debug] 3565#0: posix_memalign: 0A11BC80:256 @16
2011/09/29 09:21:07 [debug] 3565#0: *1 accept: 127.0.0.1 fd:17
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer add: 17:
60000:3020934938
2011/09/29 09:21:07 [debug] 3565#0: *1 epoll add event: fd:17 op:1
ev:80000001
2011/09/29 09:21:07 [debug] 3565#0: *1 post event 0A15ACB8
2011/09/29 09:21:07 [debug] 3565#0: *1 delete posted event 0A15ACB8
2011/09/29 09:21:07 [debug] 3565#0: *1 malloc: 0A124890:664
2011/09/29 09:21:07 [debug] 3565#0: *1 malloc: 0A124B30:1024
2011/09/29 09:21:07 [debug] 3565#0: *1 posix_memalign: 0A121C90:4096
@16
2011/09/29 09:21:07 [debug] 3565#0: *1 http process request line
2011/09/29 09:21:07 [debug] 3565#0: *1 recv: fd:17 158 of 1024
2011/09/29 09:21:07 [debug] 3565#0: *1 http request line: “GET /foo/
HTTP/1.1”
2011/09/29 09:21:07 [debug] 3565#0: *1 http uri: “/foo/”
2011/09/29 09:21:07 [debug] 3565#0: *1 http args: “”
2011/09/29 09:21:07 [debug] 3565#0: *1 http exten: “”
2011/09/29 09:21:07 [debug] 3565#0: *1 http process request header line
2011/09/29 09:21:07 [debug] 3565#0: *1 http header: “User-Agent:
curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”
2011/09/29 09:21:07 [debug] 3565#0: *1 http header: “Host:
localhost:92”
2011/09/29 09:21:07 [debug] 3565#0: *1 http header: “Accept: /”
2011/09/29 09:21:07 [debug] 3565#0: *1 http header done
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer del: 17: 3020934938
2011/09/29 09:21:07 [debug] 3565#0: *1 generic phase: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 rewrite phase: 1
2011/09/29 09:21:07 [debug] 3565#0: *1 test location: “/”
2011/09/29 09:21:07 [debug] 3565#0: *1 using configuration “/”
2011/09/29 09:21:07 [debug] 3565#0: *1 http cl:-1 max:1048576
2011/09/29 09:21:07 [debug] 3565#0: *1 rewrite phase: 3
2011/09/29 09:21:07 [debug] 3565#0: *1 http script value:
“localhost:90”
2011/09/29 09:21:07 [debug] 3565#0: *1 http script set $backend
2011/09/29 09:21:07 [debug] 3565#0: 1 http script regex: "^/foo/(.)$"
2011/09/29 09:21:07 [notice] 3565#0: 1 "^/foo/(.)$" matches “/foo/”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/29 09:21:07 [debug] 3565#0: *1 http script copy: “/”
2011/09/29 09:21:07 [debug] 3565#0: *1 http script capture: “”
2011/09/29 09:21:07 [debug] 3565#0: *1 http script regex end
2011/09/29 09:21:07 [notice] 3565#0: *1 rewritten data: “/”, args: “”,
client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.1”, host:
“localhost:92”
2011/09/29 09:21:07 [debug] 3565#0: *1 post rewrite phase: 4
2011/09/29 09:21:07 [debug] 3565#0: *1 generic phase: 5
2011/09/29 09:21:07 [debug] 3565#0: *1 generic phase: 6
2011/09/29 09:21:07 [debug] 3565#0: *1 generic phase: 7
2011/09/29 09:21:07 [debug] 3565#0: *1 access phase: 8
2011/09/29 09:21:07 [debug] 3565#0: *1 access phase: 9
2011/09/29 09:21:07 [debug] 3565#0: *1 post access phase: 10
2011/09/29 09:21:07 [debug] 3565#0: *1 http script copy: “http://”
2011/09/29 09:21:07 [debug] 3565#0: *1 http script var: “localhost:90”
2011/09/29 09:21:07 [debug] 3565#0: *1 http init upstream, client timer:
0
2011/09/29 09:21:07 [debug] 3565#0: *1 epoll add event: fd:17 op:3
ev:80000005
2011/09/29 09:21:07 [debug] 3565#0: *1 http script copy: "Host: "
2011/09/29 09:21:07 [debug] 3565#0: *1 http script var: “localhost:90”
2011/09/29 09:21:07 [debug] 3565#0: *1 http script copy: "
"
2011/09/29 09:21:07 [debug] 3565#0: *1 http script copy: "Connection:
close
"
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header: “User-Agent:
curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header: “Accept: /”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header:
"GET /foo/ HTTP/1.0
Host: localhost:90
Connection: close
User-Agent: curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5
OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5
Accept: /

"
2011/09/29 09:21:07 [debug] 3565#0: *1 http cleanup add: 0A122630
2011/09/29 09:21:07 [debug] 3565#0: *1 get rr peer, try: 1
2011/09/29 09:21:07 [debug] 3565#0: *1 socket 18
2011/09/29 09:21:07 [debug] 3565#0: *1 epoll add connection: fd:18
ev:80000005
2011/09/29 09:21:07 [debug] 3565#0: *1 connect to 127.0.0.1:90, fd:18
#2
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream connect: -2
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer add: 18:
60000:3020934939
2011/09/29 09:21:07 [debug] 3565#0: *1 http finalize request: -4, “/?”
a:1, c:2
2011/09/29 09:21:07 [debug] 3565#0: *1 http request count:2 blk:0
2011/09/29 09:21:07 [debug] 3565#0: *1 post event 0A167CF4
2011/09/29 09:21:07 [debug] 3565#0: *1 post event 0A167CC0
2011/09/29 09:21:07 [debug] 3565#0: *1 delete posted event 0A167CC0
2011/09/29 09:21:07 [debug] 3565#0: *1 http run request: “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream check client, write
event:1, “/”
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream recv(): -1 (11:
Resource temporarily unavailable)
2011/09/29 09:21:07 [debug] 3565#0: *1 delete posted event 0A167CF4
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream request: “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream send request
handler
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream send request
2011/09/29 09:21:07 [debug] 3565#0: *1 chain writer buf fl:1 s:177
2011/09/29 09:21:07 [debug] 3565#0: *1 chain writer in: 0A12264C
2011/09/29 09:21:07 [debug] 3565#0: *1 writev: 177
2011/09/29 09:21:07 [debug] 3565#0: *1 chain writer out: 00000000
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer del: 18: 3020934939
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer add: 18:
60000:3020934939
2011/09/29 09:21:07 [debug] 3565#0: *1 post event 0A15ACEC
2011/09/29 09:21:07 [debug] 3565#0: *1 post event 0A167CF4
2011/09/29 09:21:07 [debug] 3565#0: *1 delete posted event 0A167CF4
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream request: “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream dummy handler
2011/09/29 09:21:07 [debug] 3565#0: *1 delete posted event 0A15ACEC
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream request: “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream process header
2011/09/29 09:21:07 [debug] 3565#0: *1 malloc: 0A174BF8:4096
2011/09/29 09:21:07 [debug] 3565#0: *1 recv: fd:18 305 of 4096
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy status 404 “404 Not
Found”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header: “Server:
nginx”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header: “Date: Thu, 29
Sep 2011 07:21:07 GMT”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header: “Content-Type:
text/html”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header:
“Content-Length: 162”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header: “Connection:
close”
2011/09/29 09:21:07 [debug] 3565#0: *1 http proxy header done
2011/09/29 09:21:07 [debug] 3565#0: *1 lua capture header filter, uri
“/”
2011/09/29 09:21:07 [debug] 3565#0: *1 HTTP/1.1 404 Not Found
Server: nginx
Date: Thu, 29 Sep 2011 07:21:07 GMT
Content-Type: text/html
Connection: keep-alive
Content-Length: 162

2011/09/29 09:21:07 [debug] 3565#0: *1 write new buf t:1 f:0 0A1227F8,
pos 0A1227F8, size: 148 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 http write filter: l:0 f:0 s:148
2011/09/29 09:21:07 [debug] 3565#0: *1 http cacheable: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream process upstream
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe read upstream: 1
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe preread: 162
2011/09/29 09:21:07 [debug] 3565#0: *1 readv: 1:3791
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe recv chain: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe buf free s:0 t:1 f:0
0A174BF8, pos 0A174C87, size: 162 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 input buf #0
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe write downstream: 1
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe write downstream flush in
2011/09/29 09:21:07 [debug] 3565#0: *1 http output filter “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http copy filter: “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 lua capture body filter, uri “/”
2011/09/29 09:21:07 [debug] 3565#0: *1 http postpone filter “/?”
0A122970
2011/09/29 09:21:07 [debug] 3565#0: *1 write old buf t:1 f:0 0A1227F8,
pos 0A1227F8, size: 148 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 write new buf t:1 f:0 0A174BF8,
pos 0A174C87, size: 162 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 http write filter: l:0 f:0 s:310
2011/09/29 09:21:07 [debug] 3565#0: *1 http copy filter: 0 “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 pipe write downstream done
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer: 18, old: 3020934939,
new: 3020934939
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream exit: 00000000
2011/09/29 09:21:07 [debug] 3565#0: *1 finalize http upstream request:
0
2011/09/29 09:21:07 [debug] 3565#0: *1 finalize http proxy request
2011/09/29 09:21:07 [debug] 3565#0: *1 free rr peer 1 0
2011/09/29 09:21:07 [debug] 3565#0: *1 close http upstream connection:
18
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer del: 18: 3020934939
2011/09/29 09:21:07 [debug] 3565#0: *1 reusable connection: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 http upstream temp fd: -1
2011/09/29 09:21:07 [debug] 3565#0: *1 http output filter “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http copy filter: “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 lua capture body filter, uri “/”
2011/09/29 09:21:07 [debug] 3565#0: *1 http postpone filter “/?”
BF8FAFD8
2011/09/29 09:21:07 [debug] 3565#0: *1 write old buf t:1 f:0 0A1227F8,
pos 0A1227F8, size: 148 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 write old buf t:1 f:0 0A174BF8,
pos 0A174C87, size: 162 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 write new buf t:0 f:0 00000000,
pos 00000000, size: 0 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 http write filter: l:1 f:0 s:310
2011/09/29 09:21:07 [debug] 3565#0: *1 http write filter limit 0
2011/09/29 09:21:07 [debug] 3565#0: *1 writev: 310
2011/09/29 09:21:07 [debug] 3565#0: *1 http write filter 00000000
2011/09/29 09:21:07 [debug] 3565#0: *1 http copy filter: 0 “/?”
2011/09/29 09:21:07 [debug] 3565#0: *1 http finalize request: 0, “/?”
a:1, c:1
2011/09/29 09:21:07 [debug] 3565#0: *1 set http keepalive handler
2011/09/29 09:21:07 [debug] 3565#0: *1 http close request
2011/09/29 09:21:07 [debug] 3565#0: *1 http log handler
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 0A174BF8
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 0A121C90, unused: 483
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer add: 17:
15000:3020889939
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 0A124890
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 0A124B30
2011/09/29 09:21:07 [debug] 3565#0: *1 hc free: 00000000 0
2011/09/29 09:21:07 [debug] 3565#0: *1 hc busy: 00000000 0
2011/09/29 09:21:07 [debug] 3565#0: *1 tcp_nodelay
2011/09/29 09:21:07 [debug] 3565#0: *1 reusable connection: 1
2011/09/29 09:21:07 [debug] 3565#0: *1 post event 0A15ACB8
2011/09/29 09:21:07 [debug] 3565#0: *1 delete posted event 0A15ACB8
2011/09/29 09:21:07 [debug] 3565#0: *1 http keepalive handler
2011/09/29 09:21:07 [debug] 3565#0: *1 malloc: 0A124890:1024
2011/09/29 09:21:07 [debug] 3565#0: *1 recv: fd:17 0 of 1024
2011/09/29 09:21:07 [info] 3565#0: *1 client 127.0.0.1 closed keepalive
connection
2011/09/29 09:21:07 [debug] 3565#0: *1 close http connection: 17
2011/09/29 09:21:07 [debug] 3565#0: *1 event timer del: 17: 3020889939
2011/09/29 09:21:07 [debug] 3565#0: *1 reusable connection: 0
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 0A124890
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 00000000
2011/09/29 09:21:07 [debug] 3565#0: *1 free: 0A11BC80, unused: 56

cat error90.log

2011/09/29 09:21:05 [debug] 3565#0: epoll add event: fd:11 op:1
ev:00000001
2011/09/29 09:21:07 [debug] 3565#0: post event 0A15ABE8
2011/09/29 09:21:07 [debug] 3565#0: delete posted event 0A15ABE8
2011/09/29 09:21:07 [debug] 3565#0: accept on 0.0.0.0:90, ready: 0
2011/09/29 09:21:07 [debug] 3565#0: posix_memalign: 0A11BE10:256 @16
2011/09/29 09:21:07 [debug] 3565#0: *3 accept: 127.0.0.1 fd:19
2011/09/29 09:21:07 [debug] 3565#0: *3 event timer add: 19:
60000:3020934939
2011/09/29 09:21:07 [debug] 3565#0: *3 epoll add event: fd:19 op:1
ev:80000001
2011/09/29 09:21:07 [debug] 3565#0: *3 post event 0A15AD20
2011/09/29 09:21:07 [debug] 3565#0: *3 delete posted event 0A15AD20
2011/09/29 09:21:07 [debug] 3565#0: *3 malloc: 0A124F38:664
2011/09/29 09:21:07 [debug] 3565#0: *3 malloc: 0A122CA8:1024
2011/09/29 09:21:07 [debug] 3565#0: *3 posix_memalign: 0A1230B0:4096
@16
2011/09/29 09:21:07 [debug] 3565#0: *3 http process request line
2011/09/29 09:21:07 [debug] 3565#0: *3 recv: fd:19 177 of 1024
2011/09/29 09:21:07 [debug] 3565#0: *3 http request line: “GET /foo/
HTTP/1.0”
2011/09/29 09:21:07 [debug] 3565#0: *3 http uri: “/foo/”
2011/09/29 09:21:07 [debug] 3565#0: *3 http args: “”
2011/09/29 09:21:07 [debug] 3565#0: *3 http exten: “”
2011/09/29 09:21:07 [debug] 3565#0: *3 http process request header line
2011/09/29 09:21:07 [debug] 3565#0: *3 http header: “Host:
localhost:90”
2011/09/29 09:21:07 [debug] 3565#0: *3 http header: “Connection: close”
2011/09/29 09:21:07 [debug] 3565#0: *3 http header: “User-Agent:
curl/7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
zlib/1.2.3 libidn/0.6.5”
2011/09/29 09:21:07 [debug] 3565#0: *3 http header: “Accept: /”
2011/09/29 09:21:07 [debug] 3565#0: *3 http header done
2011/09/29 09:21:07 [debug] 3565#0: *3 event timer del: 19: 3020934939
2011/09/29 09:21:07 [debug] 3565#0: *3 generic phase: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 rewrite phase: 1
2011/09/29 09:21:07 [debug] 3565#0: *3 test location: “/”
2011/09/29 09:21:07 [debug] 3565#0: *3 using configuration “/”
2011/09/29 09:21:07 [debug] 3565#0: *3 http cl:-1 max:1048576
2011/09/29 09:21:07 [debug] 3565#0: *3 rewrite phase: 3
2011/09/29 09:21:07 [debug] 3565#0: *3 post rewrite phase: 4
2011/09/29 09:21:07 [debug] 3565#0: *3 generic phase: 5
2011/09/29 09:21:07 [debug] 3565#0: *3 generic phase: 6
2011/09/29 09:21:07 [debug] 3565#0: *3 generic phase: 7
2011/09/29 09:21:07 [debug] 3565#0: *3 access phase: 8
2011/09/29 09:21:07 [debug] 3565#0: *3 access phase: 9
2011/09/29 09:21:07 [debug] 3565#0: *3 post access phase: 10
2011/09/29 09:21:07 [debug] 3565#0: *3 content phase: 11
2011/09/29 09:21:07 [debug] 3565#0: *3 open index
“/usr/share/nginx/html/foo/index.html”
2011/09/29 09:21:07 [debug] 3565#0: *3 stat()
“/usr/share/nginx/html/foo/index.html” failed (2: No such file or
directory)
2011/09/29 09:21:07 [debug] 3565#0: *3 http index check dir:
“/usr/share/nginx/html/foo”
2011/09/29 09:21:07 [error] 3565#0: *3
“/usr/share/nginx/html/foo/index.html” is not found (2: No such file or
directory), client: 127.0.0.1, server: _, request: “GET /foo/ HTTP/1.0”,
host: “localhost:90”
2011/09/29 09:21:07 [debug] 3565#0: *3 http finalize request: 404,
“/foo/?” a:1, c:1
2011/09/29 09:21:07 [debug] 3565#0: *3 http special response: 404,
“/foo/?”
2011/09/29 09:21:07 [debug] 3565#0: *3 http set discard body
2011/09/29 09:21:07 [debug] 3565#0: *3 lua capture header filter, uri
“/foo/”
2011/09/29 09:21:07 [debug] 3565#0: *3 HTTP/1.1 404 Not Found
Server: nginx
Date: Thu, 29 Sep 2011 07:21:07 GMT
Content-Type: text/html
Content-Length: 162
Connection: close

2011/09/29 09:21:07 [debug] 3565#0: *3 write new buf t:1 f:0 0A12362C,
pos 0A12362C, size: 143 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 http write filter: l:0 f:0 s:143
2011/09/29 09:21:07 [debug] 3565#0: *3 http output filter “/foo/?”
2011/09/29 09:21:07 [debug] 3565#0: *3 http copy filter: “/foo/?”
2011/09/29 09:21:07 [debug] 3565#0: *3 lua capture body filter, uri
“/foo/”
2011/09/29 09:21:07 [debug] 3565#0: *3 http postpone filter “/foo/?”
0A123778
2011/09/29 09:21:07 [debug] 3565#0: *3 write old buf t:1 f:0 0A12362C,
pos 0A12362C, size: 143 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 write new buf t:0 f:0 00000000,
pos 08116EE0, size: 116 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 write new buf t:0 f:0 00000000,
pos 08116920, size: 46 file: 0, size: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 http write filter: l:1 f:0 s:305
2011/09/29 09:21:07 [debug] 3565#0: *3 http write filter limit 0
2011/09/29 09:21:07 [debug] 3565#0: *3 writev: 305
2011/09/29 09:21:07 [debug] 3565#0: *3 http write filter 00000000
2011/09/29 09:21:07 [debug] 3565#0: *3 http copy filter: 0 “/foo/?”
2011/09/29 09:21:07 [debug] 3565#0: *3 http finalize request: 0,
“/foo/?” a:1, c:1
2011/09/29 09:21:07 [debug] 3565#0: *3 event timer add: 19:
5000:3020879939
2011/09/29 09:21:07 [debug] 3565#0: *3 http lingering close handler
2011/09/29 09:21:07 [debug] 3565#0: *3 recv: fd:19 -1 of 4096
2011/09/29 09:21:07 [debug] 3565#0: *3 recv() not ready (11: Resource
temporarily unavailable)
2011/09/29 09:21:07 [debug] 3565#0: *3 lingering read: -2
2011/09/29 09:21:07 [debug] 3565#0: *3 event timer: 19, old: 3020879939,
new: 3020879939
2011/09/29 09:21:07 [debug] 3565#0: *3 post event 0A15AD20
2011/09/29 09:21:07 [debug] 3565#0: *3 delete posted event 0A15AD20
2011/09/29 09:21:07 [debug] 3565#0: *3 http lingering close handler
2011/09/29 09:21:07 [debug] 3565#0: *3 recv: fd:19 0 of 4096
2011/09/29 09:21:07 [debug] 3565#0: *3 lingering read: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 http request count:1 blk:0
2011/09/29 09:21:07 [debug] 3565#0: *3 http close request
2011/09/29 09:21:07 [debug] 3565#0: *3 http log handler
2011/09/29 09:21:07 [debug] 3565#0: *3 free: 0A1230B0, unused: 2143
2011/09/29 09:21:07 [debug] 3565#0: *3 close http connection: 19
2011/09/29 09:21:07 [debug] 3565#0: *3 event timer del: 19: 3020879939
2011/09/29 09:21:07 [debug] 3565#0: *3 reusable connection: 0
2011/09/29 09:21:07 [debug] 3565#0: *3 free: 0A122CA8
2011/09/29 09:21:07 [debug] 3565#0: *3 free: 0A124F38
2011/09/29 09:21:07 [debug] 3565#0: *3 free: 0A11BE10, unused: 56

Any advice how to get rid of the 'foo/" in the proxied request would be
highly welcome.

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?

[csg]

Hi Maxim and Igor!

in the meantime we served around 15 million requests successfully
without any issue on production. As a long term fix would it be possible
for get Maxims’ patch merged into to the official code base. As this is
a change in behavior I would understand if it doesn’t get merged into
the stable branch, but merging this into the development branch would be
excellent.

HG changeset patch

User Maxim D. [email protected]

Date 1317281138 -14400

Node ID d6a0787307868c06073d92bb39eb2f73acf19d7c

Parent 29d417d419d946dce33023c71cce0e586ef3547b

Proxy: made proxy_pass with variables more consitent.

If proxy_pass were used with variables and there were no URI component,
nginx always used unparsed URI. This isn’t consistent with “no
variables”
case, where e.g. rewrites are applied even if there are no URI
component.

Fix is to use same logic in both cases, i.e. only use unparsed URI if
it’s valid and request is main one.

diff --git a/src/http/modules/ngx_http_proxy_module.c
b/src/http/modules/ngx_http_proxy_module.c
— a/src/http/modules/ngx_http_proxy_module.c
+++ b/src/http/modules/ngx_http_proxy_module.c
@@ -738,9 +738,6 @@ ngx_http_proxy_eval(ngx_http_request_t *
url.uri.len++;
url.uri.data = p - 1;
}

• } else {

•    url.uri = r->unparsed_uri;
  

  }

  ctx->vars.key_start = u->schema;
  @@ -808,7 +805,7 @@ ngx_http_proxy_create_key(ngx_http_reque
  return NGX_ERROR;
  }

• if (plcf->proxy_lengths) {

• if (plcf->proxy_lengths && ctx->vars.uri.len) {

  *key = ctx->vars.uri;
  u->uri = ctx->vars.uri;
  

@@ -918,7 +915,7 @@ ngx_http_proxy_create_request(ngx_http_r
loc_len = 0;
unparsed_uri = 0;

• if (plcf->proxy_lengths) {

• if (plcf->proxy_lengths && ctx->vars.uri.len) {
  uri_len = ctx->vars.uri.len;

  } else if (ctx->vars.uri.len == 0 && r->valid_unparsed_uri && r ==
  r->main)
  @@ -1024,7 +1021,7 @@ ngx_http_proxy_create_request(ngx_http_r

  u->uri.data = b->last;

• if (plcf->proxy_lengths) {

• if (plcf->proxy_lengths && ctx->vars.uri.len) {
  b->last = ngx_copy(b->last, ctx->vars.uri.data,
  ctx->vars.uri.len);

  } else if (unparsed_uri) {

Many thanks!

Posted at Nginx Forum:

Re: Does Nginx honor DNS TTLs for proxy upstreams?