Request time of 60s when denying SSL requests?

[Maxim Dounin]

Hello!

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

> 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!

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