$request_body overwritten (MINOR)

[gsahbi]

Nginx $request_body is being overwritten with “token=…” when I try to inspect it in the logs.

Any workaround?

[gary-archer]

Could you provide a bit more info please, so that we have the best chance of resolving your issue quickly. It seems you're calling an API and receiving an unexpected response:

• Does the issue occur on every request or intermittently?
• Could you give us an idea of NGINX configuration, the request / response details and any relevant log entries?
• Does it only happen under certain conditions, eg large messages, POST requests, when the token expires?
• Have you only recently started using this plugin or have you been using it for quite a while?
• Did your API calls work previously and have they only recently stopped working?
• If it is new behavior, has anything changed recently, such as an upgrade to NGINX or the plugin?
• What versions of NGINX and the plugin are you using - and which NGINX docker image?

[gsahbi]

The issue is not related to the function of the plugin itself. I’m getting the correct request body forwarded by nginx to the API server.

The issue is seen only when I try to access the value $request_body from within location directive for example for logging

So to reproduce :

1. add req_body="$request_body" to the log_format directive
2. cat /var/log/nginx/access.log will contain

req_body="token=_0XBPWQQ_642208b4-44f6-4e1a-ae1f-180a80c4d359"

[gsahbi]

I think somehow nginx is confusing the original request body with the introspection request

ngx_snprintf(introspect_body_data, request->headers_in.authorization->value.len, "token=%s", bearer_token_pos);

[gary-archer]

Ah - I understand your issue now. The module does write its own request body in order to send the introspection request. So this could be a case of needing to set a variable to capture the original request body, before this happens. I will run it by people internally, then take a closer look a little later, to see if we can find you a workaround.

[gary-archer]

I reproduced this, with the following Docker based configuration. If the module does not run its introspection subrequest then a POST request body is logged correctly. Yet when the introspection subrequest is run, nginx seems to update the $request_body variable as you say.

worker_processes 1;
error_log /dev/stdout info;

daemon on;
load_module modules/ngx_curity_http_phantom_token_module.so;
events { worker_connections 1024; }

http {
    sendfile on;
    proxy_cache_path cache levels=1:2 keys_zone=api_cache:10m max_size=10g inactive=60m use_temp_path=off;
    log_format postdata $request_body;

    server {
        listen 8080;

        location / {
            root   /usr/share/nginx/html;
            index  index.html index.htm;
        }
 
        location /api {
            access_log /dev/stdout postdata;
            resolver 127.0.0.11;
            phantom_token on;
            phantom_token_client_credential test-nginx secret2;
            phantom_token_introspection_endpoint curity;
            proxy_pass "http://mockbin.com/request";
        }

        location curity {
            resolver 127.0.0.11;
            proxy_pass http://identityserver:8443/oauth/v2/oauth-introspect;
            proxy_cache_methods POST;
            proxy_cache api_cache;
            proxy_cache_key $request_body;
            proxy_ignore_headers Set-Cookie;
        }
    }
}

Log entries for successful API calls in the /api block then look like this, whereas error responses that do not undergo introspection show the original request body.

req_body="token=_0XBPWQQ_642208b4-44f6-4e1a-ae1f-180a80c4d359"

When cache configuration is removed, or the below entry is removed, the logging works as expected. Yet this is not an acceptable solution since the cache key then no longer works correctly and multiple access tokens return the same cached JWT.

proxy_cache_key $request_body;

So perhaps, after the subrequest completes, the parent request context needs to be restored in order for logging of request bodies to work. A couple of related posts below but a solution would require care. Also, we do not recommend logging of request bodies in production so perhaps this is a developer only requirement.

• post 1
• post 2

In the meantime I see you have found a LUA based workaround so we will put this on hold.

[gsahbi]

as a workaround I used Lua to save request body

access_by_lua '

    ngx.req.read_body()
    ngx.var.req_body = ngx.req.get_body_data()

';