Forum: NGINX Request time of 60s when denying SSL requests?

I purposely use the following rule to deny both http and https requests 
made to the root or our nginx server:
location = / { access_log  /logs/nginx/forbidden.log main; deny all; }
If you enter http://whatever.domaina234.com into a browser then nginx 
immediately returns the 403 page to the browser, as expected.  This 
shows up in the log as this:
"[10/Jan/2013:12:57:30 -0500]" "-" "400" "0" "80" "-" "-" "0.000" "-" 
"-" "-"
where 0.000 is the $request_time.
However, if you make the request using https, like this 
https://whatever.domaina234.com then nginx immediately displays a 408 
page in the browser (why this instead of 403?). And the most troubling 
part is that nothing shows up in the logs until about 60 seconds later, 
and then shows like this:
"[10/Jan/2013:12:59:20 -0500]" "-" "408" "0" "443" "-" "-" "59.999" "-" 
"-" "-"
Sometimes the request_time is 59.999, sometimes it is 60.000. But it is 
always 60 seconds.
This is troubling because it seems nginx is in a wait state of some sort 
for 60 seconds before finishing up with the request. I am concerned this 
is tying up resources of some kind. I am using nginx to front-end 
Tomcat, but my understanding is that with the "deny all" the processing 
should end there? And even if it was passing this on to Jetty, it would 
get a valid response back within a few ms.
I am certain the above "location" rule is being triggered, because if I 
change "deny all" to "return 507;" (just to pick an arbitrary number) 
then the browser shows "507" as the error code.
This seems odd to me. I don't know why nginx is following the rule I set 
up to deny the request, yet still seems to be "in process" in some way 
to account for the 60 seconds.  And this only happens for HTTPS. So it 
looks like nginx handles it from the client perspective immediately, but 
then expects something else to happen during that 60 seconds. I don't 
think nginx is really doing any work on this during the 60 seconds. It 
doesn't show in top and the cpu is at 0% (doing this on a testing box). 
I tried forcing keep alive off in these situations but the results is 
still the 60 second "request time". Nginx is being used to front end a 
web service and in no case should someone make a request to the root 
like this. Therefore my goal is to immediately terminate any such 
request and minimize the amount of cpu resources being used to service 
such requests.
Any ideas? Thank you so much in advance for any help you can provide!

Hello!

On Thu, Jan 10, 2013 at 11:59:06AM -0800, JB Hobbs wrote:

> This seems odd to me. I don't know why nginx is following the rule I set up to 
deny the request, yet still seems to be "in process" in some way to account for 
the 60 seconds.  And this only happens for HTTPS. So it looks like nginx handles 
it from the client perspective immediately, but then expects something else to 
happen during that 60 seconds. I don't think nginx is really doing any work on 
this during the 60 seconds. It doesn't show in top and the cpu is at 0% (doing 
this on a testing box). I tried forcing keep alive off in these situations but the 
results is still the 60 second "request time". Nginx is being used to front end a 
web service and in no case should someone make a request to the root like this. 
Therefore my goal is to immediately terminate any such request and minimize the 
amount of cpu resources being used to service such requests.
> Any ideas? Thank you so much in advance for any help you can provide!

I would suggest that what you see in logs is actually empty
connection (without any request sent) opened by your browser in
addition to one which actually did a request.  These are expected
to show up as 400 if client closes connection, but 408 if it's
closed by nginx, and the exact code might depend on browser
behaviour.

The odd thing is that 408 page is displayed in the browser.  Could
you please double check and provide full sample configuration to
reproduce?

I've just checked with the following config:

    daemon off;

    error_log /dev/stderr notice;

    events {
    }

    http {
        server {
            listen 8443 ssl;

            ssl_certificate test-ssl.crt;
            ssl_certificate_key test-ssl-nopasswd.key;

            access_log /dev/stderr combined;

            location / {
                deny all;
            }
        }
    }

and it returns 403 Forbidden as expected.


--
Maxim Dounin
http://nginx.com/support.html

Thank you Maxim. I have a few follow up points and questions please:

1. I should have mentioned that I was doing this on Nginx 0.6.x. I just 
tried the same test on Nginx 1.2.6. With 1.2.6 it does return the 403 to 
the browser as expected.

The following applies to my testing on Nginx 1.2.6:

2. I understand (and verfied by closing the browser sooner) from your 
response that the browser (Chrome in this case) is keeping the 
connection open with Nginx for 60 seconds when it is HTTPS (and about 10 
seconds with http). However, if a browser makes a request to the root, I 
want to tell Nginx to force the connection closed immediately after 
retuning the 403. This is a high volume web service and I do not want 
browsers keeping requests open.

Is there some sort of directive or option I can set within my location=/ 
block to tell nginx to drop the connection immediately upon returning 
the 403? This is highly desirable so I hope there is a way to do it.


3. On a related note - as I mentioned nginx is serving as a front-end to 
Jetty. The way our web service makes, a browser should only make a 
single request for one html page and never make another request until 24 
hours later, when the cache period expires. With this in mind, even for 
the legitimate requests, I am wondering if it would be more efficient 
for the server if I turned off keep-alive because there will just be 
this single request. What do you think? Are there any other 
optimizations I can make to this or other settings to use considering 
nginx will be serving just one single request per 24 hour per unique 
browser?

4. I have a access_log directive that points to main.log outside of the 
"location" blocks so it serves as the default location for where Nginx 
should log requests to. Inside my "location=/" block I have another 
access_log directive that points to forbidden.log. When the above http 
and https request are made to "/", I do get a log entry in the 
forbidden.log as desired. However I also get this log entry in my 
main.log file as well. What do I need to do so that nginx only logs this 
to the forbidden.log, without (hopefully) removing the main.log entry 
defined outside of the location blocks (since I use this as a default 
from many other location blocks).

Thank you so much for the excellent support!! :)


============================================

I would suggest that what you see in logs is actually empty
connection (without any request sent) opened by your browser in
addition to one which actually did a request. These are expected
to show up as 400 if client closes connection, but 408 if it's
closed by nginx, and the exact code might depend on browser
behaviour.

The odd thing is that 408 page is displayed in the browser. Could
you please double check and provide full sample configuration to
reproduce?

I've just checked with the following config:

  daemon off;

  error_log /dev/stderr notice;

  events {
  }

  http {
    server {
      listen 8443 ssl;

      ssl_certificate test-ssl.crt;
      ssl_certificate_key test-ssl-nopasswd.key;

      access_log /dev/stderr combined;

      location / {
        deny all;
      }
    }
  }

and it returns 403 Forbidden as expected.


--
Maxim Dounin
http://nginx.com/support.html

Hello!

On Fri, Jan 11, 2013 at 07:37:04AM -0800, JB Hobbs wrote:

> Thank you Maxim. I have a few follow up points and questions
> please:
>
> 1. I should have mentioned that I was doing this on Nginx 0.6.x.
> I just tried the same test on Nginx 1.2.6. With 1.2.6 it does
> return the 403 to the browser as expected.

Well, ancient versions may do strange things.  :)

>
> Is there some sort of directive or option I can set within my
> location=/ block to tell nginx to drop the connection
> immediately upon returning the 403? This is highly desirable so
> I hope there is a way to do it.

You may disable keepalive by configuring keepalive_timeout to 0,
see http://nginx.org/r/keepalive_timeout.

It may be configured on a per-location basis, and hence you may
configure nginx to don't use keepalive after 403 by configuring
something like

    error_page 403 /403.html;

    location = /403.html {
        keepalive_timeout 0;
    }

Note well: 400 and 408 in your previous message aren't after 403.
They are logged for connections without any single request got by
nginx, and keepalive_timeout do not apply here.  To limit the time
nginx will wait for a request you may tune client_header_timeout,
see http://nginx.org/r/client_header_timeout.

> browser?
I think you are right, disabling keepalive completely may be
beneficial in such case.  (Well, nginx itself doesn't care much,
but it should be less painfull for your OS.)

> default from many other location blocks).
I believe you misunderstood what you actually get.  Defining
access_log inside the location overrides all access_log's difined
on previous levels, so you'll only get requests logged to
fobidden.log.  What you see in your main.log is other connections
opened by the browser.

--
Maxim Dounin
http://nginx.com/support.html

> You may disable keepalive by configuring keepalive_timeout to 0,

> see http://nginx.org/r/keepalive_timeout.


>  error_page 403 /403.html;
>  location = /403.html {
>   keepalive_timeout 0; }

Would that approach be any different than me just putting 
"keepalive_timeout 0;" directly into my "location = /" block? Or doing 
that would not work because of the 403 page itself acts like a new 
request that then needs to have the keep alive suppressed there?

> Note well: 400 and 408 in your previous message aren't after 403.
>They are logged for connections without any single request got by
>nginx, and keepalive_timeout do not apply here. To limit the time
>nginx will wait for a request you may tune client_header_timeout,
>see http://nginx.org/r/client_header_timeout.

The way our web service works, our users fetch a tiny file from us 
(front-ended by Nginx). They do this by making a simple GET request. I 
can't imagine the headers transmitted to us are more than 1Kb or so - 
just the user agent string and whatever default headers browsers send. 
There would not be any cookies and so forth. With this in mind, what do 
you think would be a reasonable timeout to use? For someone on a dial up 
connection in a far away land with high latency I couldn't imagine it 
taking more than 10 seconds? I want to tune it tight, but not overly 
aggressive.

At any rate, I tried putting a client_header_timeout setting inside of 
my "location = /" block, but Nginx returned an error message in the logs 
stating that the directive is not allowed in there.

Basically what I would like to do is use a VERY aggressive 
client_header_timeout, even 0 if that is allowed, but specifically just 
for requests made to the root (location = /). I can do this because such 
requests made to our service are invalid and just "stray" requests 
coming in over the net. Therefore I want to dispose of any system 
resources ASAP for such requests, even if the browser doesn't like it. 
Is there a way I can set this client_header_timeout differently based on 
the location block like what I tried? If not, is there an alternative 
approach?

> I think you are right, disabling keepalive completely may be
>beneficial in such case. (Well, nginx itself doesn't care much,
>but it should be less painfull for your OS.)

Is there a command I can run like netstat or something that shows me 
what extent keepalive is taking up resources on my server? I would like 
to get a feel for what impact, if any, having it on is making to the 
system so that I can compare that to how things look after turning 
keepalive off.

> I believe you misunderstood what you actually get. Defining
>access_log inside the location overrides all access_log's difined
>on previous levels, so you'll only get requests logged to
>fobidden.log. What you see in your main.log is other connections
>opened by the browser.


Yes. I am seeing in forbidden.log the requests made to / as expected. 
Then about 10 seconds later for http, and 60 seconds later for https, I 
get the 400 or 408 log entry in main.log. I guess this is nginx's way of 
logging that it (408) or the browser (400) closed the connection. So 
then my question is how would I tell nginx to make this log entry 
somewhere else other than in main.log. As an example this is what it 
looks like in forbidden.log:


 "[11/Jan/2013:13:36:08 -0500]" "GET / HTTP/1.1" "403" "570" "443" "-" 
"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like 
Gecko) Chrome/24.0.1312.52 Safari/537.17" "0.070" "-" "-" "-"
 (appears instantly upon making the request)

and this is what it looks like in main.log
 "[11/Jan/2013:13:37:08 -0500]" "-" "408" "0" "443" "-" "-" "60.006" "-" 
"-" "-"
 (appears 60 seconds after the initial request - how do I get Nginx to 
log this somewhere else?)

Thank you once again for your very timely and detailed help. It is very 
much appreciated!

Hello!

On Fri, Jan 11, 2013 at 11:18:27AM -0800, JB Hobbs wrote:

> Would that approach be any different than me just putting
> "keepalive_timeout 0;" directly into my "location = /" block? Or
> doing that would not work because of the 403 page itself acts
> like a new request that then needs to have the keep alive
> suppressed there?

As long as all requests in "location /" are rejected, and there is
no error_page 403 define, just "keepalive_timout 0" would be
enough.  Separate 403 location is needed to distinguish between
allowed and not allowed requests.

> headers browsers send. There would not be any cookies and so
> forth. With this in mind, what do you think would be a
> reasonable timeout to use? For someone on a dial up connection
> in a far away land with high latency I couldn't imagine it
> taking more than 10 seconds? I want to tune it tight, but not
> overly aggressive.

Minimal time one should allow IMO is slightly more than 3s to
tolerate one retransmit without RTT known.  With 10s up to two
retransmits in a row will be allowed (3s + 6s), and it's ok for
most use cases.

> Therefore I want to dispose of any system resources ASAP for
> such requests, even if the browser doesn't like it. Is there a
> way I can set this client_header_timeout differently based on
> the location block like what I tried? If not, is there an
> alternative approach?

Request URI isn't known in advance, and therefore it's not
possible to set different header timeouts for different locations.
Moreover, please note it only works for _default_ server on the
listen socket in question (as virtual host isn't known as well).

Once request headers are got from client and you know the request
isn't legitimate, you may just close the connection by using

    return 444;

See http://nginx.org/r/return.

> > I think you are right, disabling keepalive completely may be
> >beneficial in such case. (Well, nginx itself doesn't care
> >much, but it should be less painfull for your OS.)
>
> Is there a command I can run like netstat or something that
> shows me what extent keepalive is taking up resources on my
> server? I would like to get a feel for what impact, if any,
> having it on is making to the system so that I can compare that
> to how things look after turning keepalive off.

This depends on the OS you are using.  E.g. on FreeBSD "vmstat -z"
will show something like this:

...
socket:                   412,    25605,      149,     1804, 43516452, 
0
unpcb:                    172,    25622,       96,      686, 14762777, 
0
ipq:                       32,      904,        0,      226,    22503, 
0
udp_inpcb:                220,    25614,       10,      134,  6521351, 
0
udpcb:                      8,    25781,       10,      193,  6521351, 
0
tcp_inpcb:                220,    25614,       43,     6311, 22232147, 
0
tcpcb:                    632,    25602,       34,     1148, 22232147, 
0
tcptw:                     52,     5184,        9,     5175,  9010766, 
114029
syncache:                 112,    15365,        0,      175, 14160824, 
0
hostcache:                 76,    15400,      139,      261,   441570, 
0
tcpreass:                  20,     1690,        0,      338,   497191, 
0
...

Each established TCP connection uses at least socket + tcp_inpcb +
tcpcb structures, i.e. about 1.5k.  Additionally, each connection
sits in TCB hash and slows down lookups if there are lots of
connections.  This isn't a problem if you have properly tuned
system and enough memory, but if you are trying to keep lots of
connections alive - you may want to start counting.

> guess this is nginx's way of logging that it (408) or the
> browser (400) closed the connection.

Not exactly - it's about "closed the connection without sending
any complete request in it".  400 here means "client opened the
connection presumably to send a request, but closed the connection
before it was able to send a request", and 408 "... but failed to
send a request before timeout expired".

>So then my question is how would I tell nginx to make this log
> entry somewhere else other than in main.log. As an example this
> is what it looks like in forbidden.log:

If you want nginx to log 400 and 408 errors separately you have to
configure error_page to handle these errors, and configure
access_log there.  E.g.:

    error_page 408 /408.html;

    location = /408.html {
        access_log /path/to/408.log combined;
    }

[...]

--
Maxim Dounin
http://nginx.com/support.html

> Request URI isn't known in advance, and therefore it's not

>possible to set different header timeouts for different locations.
>Moreover, please note it only works for _default_ server on the
>listen socket in question (as virtual host isn't
 known as well).

>Once request headers are got from client and you know the request
> isn't legitimate, you may just close the connection by using

> return 444;

Thanks. I tested this. I think in some ways it is worse. In one way it 
seems better because with 444 I do not get a 408 from Nginx 60 seconds 
later.

However, sending the 444 causes Chrome to try multiple times in a row. 
For instance just entering https://mydomain/ one time in the browser and 
not refreshing the page at all gives this:

"[12/Jan/2013:15:10:33 -0500]" "GET / HTTP/1.1" "444" "0" "443" "-" 
"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like 
Gecko) Chrome/24.0.1312.52 Safari/537.17" "0.055" "-" "-" "-"
"[12/Jan/2013:15:10:35 -0500]" "GET / HTTP/1.1" "444" "0" "443" "-" 
"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like 
Gecko) Chrome/24.0.1312.52 Safari/537.17" "1.683" "-" "-" "-"
"[12/Jan/2013:15:10:35 -0500]" "GET / HTTP/1.1" "444" "0" "443" "-" 
"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like 
Gecko) Chrome/24.0.1312.52 Safari/537.17" "0.029" "-" "-" "-"
"[12/Jan/2013:15:10:35 -0500]" "GET / HTTP/1.1" "444" "0" "443" "-" 
"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like 
Gecko) Chrome/24.0.1312.52 Safari/537.17" "0.020" "-" "-" "-"

So it seems that returning the 444 makes Chrome want to try 4 more times 
before giving up. That's got to be worse than with the 403 and it trying 
once but keeping the connection, you think?

I am wondering if I am concerning myself too much with this 60 second 
delay before nginx closes the connection. I can probably use 
client_header_timeout at 15s and still have that be safe and so the 
connection doesn't stay more than 15 seconds before Nginx closes it out. 
But I still wonder if having this connection stick around is wasting 
resources?
> This depends on the OS you are using. E.g. on FreeBSD "vmstat -z"
> will show something like this:

> This isn't a problem if you have properly tuned
> system and enough memory, but if you are trying to keep lots of
> connections alive - you may want to start counting.

Sorry I should have specified I am on Fedora Core 17. It has a vmstat 
but no -z option? Anyway, in looking at the output, how can one 
determine whether the amount of sockets and such being held is nearing 
the OS limits?


Thanks again!

Hello!

On Sat, Jan 12, 2013 at 12:19:15PM -0800, JB Hobbs wrote:

> > return 444;
>
> Thanks. I tested this. I think in some ways it is worse. In one
> way it seems better because with 444 I do not get a 408 from
> Nginx 60 seconds later.
>
> However, sending the 444 causes Chrome to try multiple times in
> a row. For instance just entering https://mydomain/ one time in
> the browser and not refreshing the page at all gives this:

Yes, for https hosts most browsers retry with various workarounds
if connection is closed, and use of "return 444" with https is
probably not a good idea.

[...]

> I am wondering if I am concerning myself too much with this 60
> second delay before nginx closes the connection. I can probably
> use client_header_timeout at 15s and still have that be safe and
> so the connection doesn't stay more than 15 seconds before Nginx
> closes it out. But I still wonder if having this connection
> stick around is wasting resources?

It is, but a) most likely you wouldn't even notice, and b) you
anyway can't avoid it completely.

> held is nearing the OS limits?
Sorry, I'm not familiar with Linux and can't help.  Google returns
about 1 mln results on "linux tuning c10k" query though.


--
Maxim Dounin
http://nginx.com/support.html