Nginx rewrites $request_method on error

user nginx;
worker_processes 1;

error_log /var/log/nginx/error.log warn;
pid /var/run/nginx.pid;

events {
worker_connections 1024;
}

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

LET’S LOG $request_method

log_format  main  '$request_method $remote_addr - $remote_user

[$time_local] “$request” ’
'$status $body_bytes_sent “$http_referer” ’
‘“$http_user_agent” “$http_x_forwarded_for”’;

#HERE IS WHAT MAKES A BUG#
error_page 405 /error.html;

access_log  /var/log/nginx/access.log  main;

sendfile        on;
#tcp_nopush     on;

keepalive_timeout  65;

#gzip  on;

server {
listen 80;

if ($request_method != GET) {
    return 405;
}

location / {
    root /etc/nginx/www;
}

}

}

What we get:
1)
curl -X POST localhost
log:
GET 127.0.0.1 - - [30/Apr/2014:10:55:03 +0400] “POST / HTTP/1.1” 405 0
“-”
“curl/7.26.0” “-”

curl -X TRACE localhost
log:
GET 127.0.0.1 - - [30/Apr/2014:10:55:10 +0400] “TRACE / HTTP/1.1” 405 0
“-”
“curl/7.26.0” “-”

curl -X PUT localhost
log:
GET 127.0.0.1 - - [30/Apr/2014:10:55:18 +0400] “PUT / HTTP/1.1” 405 0
“-”
“curl/7.26.0” “-”

Let’s disable “if”:

  1. curl -X POST localhost
    GET 127.0.0.1 - - [30/Apr/2014:10:58:48 +0400] “POST / HTTP/1.1” 405 0
    “-”
    “curl/7.26.0” “-”
  2. curl -X TRACE localhost
    GET 127.0.0.1 - - [30/Apr/2014:10:59:12 +0400] “TRACE / HTTP/1.1” 405 0
    “-”
    “curl/7.26.0” “-”
  3. curl -X PUT localhost
    GET 127.0.0.1 - - [30/Apr/2014:10:59:38 +0400] “PUT / HTTP/1.1” 405 0
    “-”
    “curl/7.26.0” “-”

Let’s disable “error_page 405 /error.html;”

  1. curl -X POST localhost
    POST 127.0.0.1 - - [30/Apr/2014:11:00:43 +0400] “POST / HTTP/1.1” 405
    172
    “-” “curl/7.26.0” “-”
  2. curl -X TRACE localhost
    TRACE 127.0.0.1 - - [30/Apr/2014:11:01:02 +0400] “TRACE / HTTP/1.1” 405
    172
    “-” “curl/7.26.0” “-”
  3. curl -X PUT localhost
    PUT 127.0.0.1 - - [30/Apr/2014:11:01:16 +0400] “PUT / HTTP/1.1” 405 172
    “-”
    “curl/7.26.0” “-”

So it seems that error_page 405 /error.html rewrites $request_method

Posted at Nginx Forum:

nginx from official repository:
nginx -V
nginx version: nginx/1.6.0
built by gcc 4.7.2 (Debian 4.7.2-5)
TLS SNI support enabled
configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx
–conf-path=/etc/nginx/nginx.conf
–error-log-path=/var/log/nginx/error.log
–http-log-path=/var/log/nginx/access.log --pid-path=/var/run/nginx.pid
–lock-path=/var/run/nginx.lock
–http-client-body-temp-path=/var/cache/nginx/client_temp
–http-proxy-temp-path=/var/cache/nginx/proxy_temp
–http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp
–http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp
–http-scgi-temp-path=/var/cache/nginx/scgi_temp --user=nginx
–group=nginx
–with-http_ssl_module --with-http_realip_module
–with-http_addition_module
–with-http_sub_module --with-http_dav_module --with-http_flv_module
–with-http_mp4_module --with-http_gunzip_module
–with-http_gzip_static_module --with-http_random_index_module
–with-http_secure_link_module --with-http_stub_status_module
–with-http_auth_request_module --with-mail --with-mail_ssl_module
–with-file-aio --with-http_spdy_module --with-cc-opt=‘-g -O2
-fstack-protector --param=ssp-buffer-size=4 -Wformat
-Werror=format-security
-Wp,-D_FORTIFY_SOURCE=2’ --with-ld-opt=‘-Wl,-z,relro -Wl,–as-needed’
–with-ipv6

Posted at Nginx Forum:

Hello!

On Wed, Apr 30, 2014 at 03:04:11AM -0400, kay wrote:

[…]

So it seems that error_page 405 /error.html rewrites $request_method

Yes, redirection a request to an error page implies changing the
request method to GET (unless it’s HEAD). It’s required to
properly return error page. Much like with URI change, this can
be avoided by using a redirect to a named location instead.


Maxim D.
http://nginx.org/

Hello!

On Tue, May 6, 2014 at 2:58 AM, kay wrote:

Actually I suppose that this is a bug, as it is not possible to make filter
by $request_method

Also some external modules like
GitHub - openresty/memc-nginx-module: An extended version of the standard memcached module that supports set, add, delete, and many more memcached commands. have strange behavior when
client passes TRACE and nginx gets GET.

Will you elaborate your problem and use case? Preferably with a
minimal but still complete example to demonstrate your intention and
problem. As the author of the ngx_memc module, I’d like to have to
look (and find a solution for you) :slight_smile:

Regards,
-agentzh

Actually I suppose that this is a bug, as it is not possible to make
filter
by $request_method

Also some external modules like
GitHub - openresty/memc-nginx-module: An extended version of the standard memcached module that supports set, add, delete, and many more memcached commands. have strange behavior
when
client passes TRACE and nginx gets GET.

Posted at Nginx Forum:

Hello!

On Tue, May 6, 2014 at 11:30 PM, kay wrote:

Sure, you can use nginx.conf from my previous message and this server
config:

I’ve noticed 2 obvious mistakes in your config. See blow.

server {
listen 80;

rewrite_by_lua ’
local res = ngx.location.capture(“/memc?cmd=get&key=test”)
ngx.say(res.body)
';

  1. It is not recommended to use the rewrite_by_lua directive directly
    in the server {} block. Because this rewrite_by_lua directive will
    just get inherited by every location in that server {} block by
    default, including 1) your location /memc, which will create a
    subrequest loop because you initiate a subrequest in your
    rewrite_by_lua code to /memc, and 2) your error pages like
    /error.html. And I’m sure this is not what you want.

  2. If you generate a response in rewrite_by_lua by calls like
    “ngx.say()”, then you should really terminate the current request
    immediately, via “ngx.exit(200)” or something like that, otherwise
    nginx will continue to run later phases like the “content phase”
    (which is supposed to generate a response) and you will face duplicate
    responses for the same request.

Another suggestion is to check out your nginx error logs for hints (if
any). If the existing info is not enough, you can further enable
nginx’s debugging logs: A debugging log

Finally, ensure your version of ngx_lua, ngx_memc, and the nginx core
are recent enough.

Good luck!
-agentzh

Sure, you can use nginx.conf from my previous message and this server
config:

server {
listen 80;

rewrite_by_lua ’
local res = ngx.location.capture(“/memc?cmd=get&key=test”)
ngx.say(res.body)
';

location / {
            root /etc/nginx/www;
}

location /memc {
internal;
access_log /var/log/nginx/memc_log main;
log_subrequest on;
set $memc_key $arg_key;
set $memc_cmd $arg_cmd;
memc_cmds_allowed get;
memc_pass vmembase-2:11211;
}

}

If you enable “error_page 405 /error.html;” nginx will hang on “curl -X
TRACE localhost”
If you disable “error_page 405 /error.html;” - everything will be fine.

Posted at Nginx Forum:

Hello!

On Wed, May 7, 2014 at 8:59 PM, kay wrote:

  1. It is not recommended to use the rewrite_by_lua directive directly

You can do the same with access_by_lua

Please do not cut my original sentence and just pick the first half.
The full sentence is “it is not recommended to use the rewrite_by_lua
directive directly in the server {} block.” and the reason follows
that. The same statement also applies to access_by_lua.

Also, please read the full text of my previous email and correct all
the things I listed there.

Regards,
-agentzh

Yichun Z. (agentzh) Wrote:

The full sentence is "it is not recommended to use the rewrite_by_lua
nginx mailing list
[email protected]
nginx Info Page

This config produces the same nginx hang.

server {
listen 80;
location / {
access_by_lua ’
local res =
ngx.location.capture(“/memc?cmd=get&key=test”)
return
';
root /etc/nginx/www;
}
location /memc {
internal;
access_log /var/log/nginx/memc_log main;
log_subrequest on;
set $memc_key $arg_key;
set $memc_cmd $arg_cmd;
memc_cmds_allowed get;
memc_pass localhost:11211;
}
}

Posted at Nginx Forum:

Hello!

On Tue, May 13, 2014 at 11:52 PM, kay wrote:

}
location /memc {
internal;
access_log /var/log/nginx/memc_log main;
log_subrequest on;
set $memc_key $arg_key;
set $memc_cmd $arg_cmd;
memc_cmds_allowed get;
memc_pass localhost:11211;
}
}

I’ve tried your nginx config snippet on my side with nginx 1.7.0 +
ngx_memc 0.14 + ngx_lua 0.9.7. And I cannot reproduce any hang on my
side. Without further details I’m afraid I cannot really help.

Several suggestions:

  1. check out your nginx error log for any hints regarding your
    configuration issues or memcached backend issues or something.

  2. try to construct a minimal but still complete example that can
    help reproducing the issue you’re seeing in others’ boxes, preferably
    with precise steps.

  3. try to enable the nginx debugging logs for more details for your
    problematic request: A debugging log If
    you do not understand the debugging logs, you can put it somewhere on
    the web (like GitHub Gist) and provide the link here.

Regards,
-agentzh

  1. It is not recommended to use the rewrite_by_lua directive directly

You can do the same with access_by_lua

Finally, ensure your version of ngx_lua, ngx_memc, and the nginx core are
recent enough.

They are recent.

Posted at Nginx Forum:

Here is nginx version:
nginx -V
nginx version: nginx/1.6.0
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
TLS SNI support enabled
configure arguments: --add-module=ngx_devel_kit-0.2.19
–add-module=lua-nginx-module-0.9.7 --add-module=memc-nginx-module-0.14
–user=apache --group=apache --prefix=/usr/share/nginx
–sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf
–error-log-path=/var/log/nginx/error.log
–http-log-path=/var/log/nginx/access.log
–http-client-body-temp-path=/var/lib/nginx/tmp/client_body
–http-proxy-temp-path=/var/lib/nginx/tmp/proxy
–http-fastcgi-temp-path=/var/lib/nginx/tmp/fastcgi
–pid-path=/var/run/nginx.pid --lock-path=/var/lock/subsys/nginx
–with-pcre=pcre-8.35 --with-pcre-jit --with-debug --with-md5-asm
–with-sha1-asm --without-mail_pop3_module --without-mail_imap_module
–without-mail_smtp_module --with-http_ssl_module
–with-http_realip_module
–with-http_gzip_static_module --with-http_stub_status_module
–with-cc-opt=‘-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions
-fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic’

Here is minimal config:
worker_processes 1;

error_log /var/log/nginx/error.log debug;
pid /var/run/nginx.pid;

events {
worker_connections 1024;
}

http {
error_page 405 /error.html;
error_page 400 /error.html;
error_page 403 /error.html;

    server {
            listen 8080;
                    location / {
                            access_by_lua '
                                    local res =

ngx.location.capture(“/memc?cmd=get&key=test”)
return
';
root /etc/nginx/www;
}
location /memc {
internal;
set $memc_key $arg_key;
set $memc_cmd $arg_cmd;
memc_pass localhost:11211;
}
}
}

/etc/nginx/www content:
ls /etc/nginx/www
error.html

curl -X GET localhost works fine (processes 403)
curl -X POST localhost works fine (processes 403)

Here is debug log on curl -X TRACE localhost or curl -X anythinghere
localhost:
2014/05/15 09:59:17 [debug] 15900#0: epoll: fd:6 ev:0001
d:00007FC4FBE03010
2014/05/15 09:59:17 [debug] 15900#0: accept on 0.0.0.0:80, ready: 0
2014/05/15 09:59:17 [debug] 15900#0: posix_memalign:
0000000000D4AD30:256
@16
2014/05/15 09:59:17 [debug] 15900#0: *3 accept: 127.0.0.1 fd:3
2014/05/15 09:59:17 [debug] 15900#0: posix_memalign:
0000000000D4AE90:256
@16
2014/05/15 09:59:17 [debug] 15900#0: *3 event timer add: 3:
60000:1400133617621
2014/05/15 09:59:17 [debug] 15900#0: *3 reusable connection: 1
2014/05/15 09:59:17 [debug] 15900#0: *3 epoll add event: fd:3 op:1
ev:80002001
2014/05/15 09:59:17 [debug] 15900#0: timer delta: 6573
2014/05/15 09:59:17 [debug] 15900#0: posted events 0000000000000000
2014/05/15 09:59:17 [debug] 15900#0: worker cycle
2014/05/15 09:59:17 [debug] 15900#0: epoll timer: 60000
2014/05/15 09:59:17 [debug] 15900#0: epoll: fd:3 ev:0001
d:00007FC4FBE031C1
2014/05/15 09:59:17 [debug] 15900#0: *3 http wait request handler
2014/05/15 09:59:17 [debug] 15900#0: *3 malloc: 0000000000D653D0:1024
2014/05/15 09:59:17 [debug] 15900#0: *3 recv: fd:3 78 of 1024
2014/05/15 09:59:17 [debug] 15900#0: *3 reusable connection: 0
2014/05/15 09:59:17 [debug] 15900#0: *3 posix_memalign:
0000000000D571B0:4096 @16
2014/05/15 09:59:17 [debug] 15900#0: *3 http process request line
2014/05/15 09:59:17 [debug] 15900#0: *3 http request line: “TRACE /
HTTP/1.1”
2014/05/15 09:59:17 [debug] 15900#0: *3 http uri: “/”
2014/05/15 09:59:17 [debug] 15900#0: *3 http args: “”
2014/05/15 09:59:17 [debug] 15900#0: *3 http exten: “”
2014/05/15 09:59:17 [debug] 15900#0: *3 http process request header line
2014/05/15 09:59:17 [debug] 15900#0: *3 http header: “User-Agent:
curl/7.26.0”
2014/05/15 09:59:17 [debug] 15900#0: *3 http header: “Host: localhost”
2014/05/15 09:59:17 [debug] 15900#0: *3 http header: “Accept: /
2014/05/15 09:59:17 [debug] 15900#0: *3 http header done
2014/05/15 09:59:17 [info] 15900#0: *3 client sent TRACE method while
reading client request headers, client: 127.0.0.1, server: , request:
“TRACE
/ HTTP/1.1”, host: “localhost”
2014/05/15 09:59:17 [debug] 15900#0: *3 http finalize request: 405, “/?”
a:1, c:1
2014/05/15 09:59:17 [debug] 15900#0: *3 event timer del: 3:
1400133617621
2014/05/15 09:59:17 [debug] 15900#0: *3 http special response: 405, “/?”
2014/05/15 09:59:17 [debug] 15900#0: *3 internal redirect:
“/error.html?”
2014/05/15 09:59:17 [debug] 15900#0: *3 rewrite phase: 1
2014/05/15 09:59:17 [debug] 15900#0: *3 test location: “/”
2014/05/15 09:59:17 [debug] 15900#0: *3 test location: “memc”
2014/05/15 09:59:17 [debug] 15900#0: *3 using configuration “/”
2014/05/15 09:59:17 [debug] 15900#0: *3 http cl:-1 max:1048576
2014/05/15 09:59:17 [debug] 15900#0: *3 rewrite phase: 3
2014/05/15 09:59:17 [debug] 15900#0: *3 post rewrite phase: 4
2014/05/15 09:59:17 [debug] 15900#0: *3 generic phase: 5
2014/05/15 09:59:17 [debug] 15900#0: *3 generic phase: 6
2014/05/15 09:59:17 [debug] 15900#0: *3 generic phase: 7
2014/05/15 09:59:17 [debug] 15900#0: *3 access phase: 8
2014/05/15 09:59:17 [debug] 15900#0: *3 access phase: 9
2014/05/15 09:59:17 [debug] 15900#0: *3 access phase: 10
2014/05/15 09:59:17 [debug] 15900#0: *3 lua access handler,
uri:“/error.html” c:2
2014/05/15 09:59:17 [debug] 15900#0: *3 posix_memalign:
0000000000D4F2B0:4096 @16
2014/05/15 09:59:17 [debug] 15900#0: *3 lua creating new thread
2014/05/15 09:59:17 [debug] 15900#0: *3 lua reset ctx
2014/05/15 09:59:17 [debug] 15900#0: *3 http cleanup add:
0000000000D58118
2014/05/15 09:59:17 [debug] 15900#0: *3 lua run thread, top:0 c:2
2014/05/15 09:59:17 [debug] 15900#0: *3 lua location capture,
uri:“/error.html” c:2
2014/05/15 09:59:17 [debug] 15900#0: *3 http subrequest
“/memc?cmd=get&key=test”
2014/05/15 09:59:17 [debug] 15900#0: *3 posix_memalign:
0000000000D502C0:4096 @16
2014/05/15 09:59:17 [debug] 15900#0: *3 lua resume returned 1
2014/05/15 09:59:17 [debug] 15900#0: *3 lua thread yielded
2014/05/15 09:59:17 [debug] 15900#0: *3 http finalize request: -4,
“/error.html?” a:1, c:3
2014/05/15 09:59:17 [debug] 15900#0: *3 http request count:3 blk:0
2014/05/15 09:59:17 [debug] 15900#0: timer delta: 0
2014/05/15 09:59:17 [debug] 15900#0: posted events 0000000000000000
2014/05/15 09:59:17 [debug] 15900#0: worker cycle
2014/05/15 09:59:17 [debug] 15900#0: epoll timer: -1 <<<< Here nginx
hangs
on

Posted at Nginx Forum:

Hello!

On Wed, May 14, 2014 at 11:19 PM, kay wrote:

http {
error_page 405 /error.html;
error_page 400 /error.html;
error_page 403 /error.html;

Okay, I can reproduce your request hang on my side now and I see what
is going on here.

Basically the 405 error is thrown so early in the processing flow of
your TRACE request within the nginx core that you cannot do
complicated processing like initiating a subrequest in your error page
target (because the request state has not been fully initialized).

Several suggestions:

  1. prevent complicated logic (like subrequests and etc) in your error
    page target location,

  2. avoid using error_page directives in big scope as server {} or even
    http {} because every location will inherit your error_page
    configurations, including your location /memc for subrequests, which
    can create an access dead loop.

Regards,
-agentzh

I mean that I know how to avoid these errors, but I think that a better
way
to fix the issue is to fix it in low level.

Posted at Nginx Forum:

Hello!

On Thu, May 15, 2014 at 11:56 PM, kay wrote:

Don’t you think this is a bug?

I think the NGINX core should prevent bad things from happen when

  1. the user configures complicated things in his error_page targets, and
  2. the error page is initiated by nginx too early in the request
    processing lifetime (like when processing the request header).

Because it should be done in the nginx core, and I can do very little
on my 3rd-party modules side about this.

Maxim D.: what is your opinion on this?

Best regards,
-agentzh

Don’t you think this is a bug?

Posted at Nginx Forum:

Hello!

On Fri, May 16, 2014 at 01:25:57PM -0700, Yichun Z. (agentzh) wrote:

processing lifetime (like when processing the request header).

Because it should be done in the nginx core, and I can do very little
on my 3rd-party modules side about this.

Maxim D.: what is your opinion on this?

First of all, I think that people should think before specifying
error processing, especially complex error processing.

It is known that using subrequest for errors generated early may
cause request hang (and FengGu tried to provide a patch
a while ago on nginx-devel@), and it will be eventually fixed.
This is relatively low priority though, see above.


Maxim D.
http://nginx.org/

Hello!

On Mon, May 19, 2014 at 4:33 AM, Maxim D. wrote:

First of all, I think that people should think before specifying
error processing, especially complex error processing.

Unfortunately we cannot control what the users think :slight_smile: Many users
just try things away according to their intuition. I’d expect that
we’ll have to waste more time to explain to other users trying to do
this in the near future (before it gets fixed). I already cannot
remember exactly how many times my modules’ users have reported such
things in the past :wink:

IMHO, if nginx cannot handle a particular case, it should complain
about it rather than hang forever. It is about usability :slight_smile:

It is known that using subrequest for errors generated early may
cause request hang (and FengGu tried to provide a patch
a while ago on nginx-devel@), and it will be eventually fixed.

That’s cool. Looking forward to that.

Regards,
-agentzh