Conflict between more_set_input_headers and map

[dioni21]

Hi,

I found a nasty bug in our setup! Better explain by example.

Suppose this configuration:

http {
...
    map $http_x_forwarded_proto $forwarded_proto_final {
      default $scheme;
      "~." $http_x_forwarded_proto;
    }
  error_page 400 403 404     /errordocument/404.html;
  error_page 500 502 503 504 /errordocument/500.html;
...
  server {
    ...
    location ~ ^/errordocument/(.*)$ {
        alias /data/htdocs/errordocument/$1;
    }
    more_set_input_headers 'X-FP: $forwarded_proto_final';
    more_set_headers       'X-FP: $forwarded_proto_final';
    # Forced errors...
    location /404/ {
      return 404;
    }
    location /500/ {
      return 500;
    }
    ...
  }
}

Now, let's do a request:

$ curl -svo /dev/null http://my.host.com/500/test
...
< HTTP/1.1 500 Internal Server Error
...

Perfect! Buf, if instead:

$ curl -svo /dev/null http://my.host.com/500/test -H 'X-Forwarded-Proto: https'
...
< HTTP/1.1 301 Moved Permanently
...
< Location: http://my.host.com/errordocument/500.html/
...

[dioni21]

Note that while debugging, we found a workaround.

Apparently, if the map is resolved BEFORE calling more_set_input_headers (and thus, cached), this does not happen!

Just change

    more_set_input_headers 'X-FP: $forwarded_proto_final';

to

    set $xxx $forwarded_proto_final;
    more_set_input_headers 'X-FP: $forwarded_proto_final';

And everything is ok again...

[dioni21]

Not sure if this helps, but we traced the ending / problem

In error situation, debug log shows something like this:

2020/01/28 18:00:29 [debug] 831#831: *10 using configuration "^/errordocument/(.*)$"
2020/01/28 18:00:29 [debug] 831#831: *10 http cl:-1 max:20971520
2020/01/28 18:00:29 [debug] 831#831: *10 rewrite phase: 4
2020/01/28 18:00:29 [debug] 831#831: *10 rewrite phase: 5
2020/01/28 18:00:29 [debug] 831#831: *10 rewrite phase: 6
2020/01/28 18:00:29 [debug] 831#831: *10 headers more rewrite handler, uri "/errordocument/500.html"
2020/01/28 18:00:29 [debug] 831#831: *10 http map started
2020/01/28 18:00:29 [debug] 831#831: *10 http script var: "https"
2020/01/28 18:00:29 [debug] 831#831: *10 http script var: "https"
2020/01/28 18:00:29 [debug] 831#831: *10 http map: "https" "https"
2020/01/28 18:00:29 [debug] 831#831: *10 http script var: "https"
...
2020/01/28 18:00:29 [debug] 831#831: *10 content phase: 22
2020/01/28 18:00:29 [debug] 831#831: *10 content phase: 23
2020/01/28 18:00:29 [debug] 831#831: *10 content phase: 24
2020/01/28 18:00:29 [debug] 831#831: *10 http script copy: "/data/htdocs/errordocument/"
2020/01/28 18:00:29 [debug] 831#831: *10 http script capture: ""
2020/01/28 18:00:29 [debug] 831#831: *10 http filename: "/data/htdocs/errordocument/"
2020/01/28 18:00:29 [debug] 831#831: *10 add cleanup: 0000558A0153E098

And when everything is as it should be:

2020/01/28 18:06:45 [debug] 1399#1399: *11 generic phase: 0
2020/01/28 18:06:45 [debug] 1399#1399: *11 generic phase: 1
2020/01/28 18:06:45 [debug] 1399#1399: *11 rewrite phase: 2
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script complex value
2020/01/28 18:06:45 [debug] 1399#1399: *11 http map started
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script var: "https"
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script var: "https"
2020/01/28 18:06:45 [debug] 1399#1399: *11 http map: "https" "https"
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script var: "https"
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script set $xxx
...
2020/01/28 18:06:45 [debug] 1399#1399: *11 content phase: 22
2020/01/28 18:06:45 [debug] 1399#1399: *11 content phase: 23
2020/01/28 18:06:45 [debug] 1399#1399: *11 content phase: 24
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script copy: "/data/htdocs/errordocument/"
2020/01/28 18:06:45 [debug] 1399#1399: *11 http script capture: "500.html"
2020/01/28 18:06:45 [debug] 1399#1399: *11 http filename: "/data/htdocs/errordocument/500.html"
2020/01/28 18:06:45 [debug] 1399#1399: *11 add cleanup: 0000558A01532720

So, if the destination is a directory, another internal redirect occur, causing the 301

Why? Sorry, my nginx debug knowledge ends here...

[agentzh]

Nginx's map directive is known to be evil. I even wrote an article to demonstrate it. In essence, it delays evaluation of the variable to the point of the first reading (and then caches the value, as you have already noticed).

[dioni21]

Delay the evaluation was our primary intention, mostly to avoid if (if is evil).

After reading you answer and analysing the problem a bit more, I found another workaround. This that may indicate the bug is not within headers_more, but in reentrancy control (is there any?) of regex operations:

Just change the errordocument location to:

    location ~ ^/errordocument/(.*)$ {
        rewrite ^/errordocument/(.*)$ /errordocument/$1;
        alias /data/htdocs/errordocument/$1;
    }

Probably the header changes, and thus the map evaluation, thus the regex "~." from the map, are evaluated after the location selection, and this clears the capture buffer that would be used in the alias directive.

From this I can see these options to fix the problem, in order of cleanliness:

1. Make regex processing fully reentrant.
2. Fixing map processing to avoid capture buffer destruction
3. Changing phase where more_set_input_headers runs, at least for "global" configurations, running the string processing before location search
4. Keep using the workaround... :-(

Maybe @igorsysoev, @mdounin or somebody else involved in core nginx development could take a look in options 1 or 2?

[agentzh]

@dioni21 Thanks for digging this up and sharing the root cause. I think it's already outside the scope of this module. You need to contact the nginx team for a fix.

BTW, changing the running phase of this module is not an option, more like a hack to me and it would break backward-compatibility for existing users.

[dioni21]

Just to finish and leave another reference: I found a 6 year old 😭 reference in nginx bugtrack: https://trac.nginx.org/nginx/ticket/564