Custom headers in nginx: log first, clean afterwards

Question

I need to parse nginx access_log and associate records with user accounts. To do so, I decided to use a custom header:

1. App sends custom header (like x-userid)
2. Nginx stores that value in access_log with custom log format $sent_http_x_userid
3. The header is being cleared and so the client doesn't see it with more_clear_headers 'x-userid'

Logging works just fine, I can see the proper userids in access_log. However, if I turn on the clearing part, the access_log shows '-' instead of actual userid.

Am I doing something wrong? Is it possible to log the header from the app before sending it to the client and then empty it with nginx?

Is there a better way to make this work? The app is PHP7, nginx is 1.10.3

Solution

As $sent_http_x_userid variable name literally means that header was sent to client. When you clean it, nginx will not send it and there will be no variable $sent_http_x_userid.

But what you actually need is to log header that you've received from upstream. For that there is $upstream_http_x_userid variable that you can write to log.

And if you don't want to pass this header to client, there is proxy_hide_header directive.

So all together could look like this

log_format coolname '$remote_addr - $remote_user [$time_local] '
                    '"$request" $status $body_bytes_sent [uid=$upstream_http_x_userid] '
                    '"$http_referer" "$http_user_agent"';

server {
    ...
    access_log /var/log/nginx/cool.log coolname;

    location /whatever {
        proxy_pass http://your-app;
        proxy_hide_header x-userid;
    }
}

Comments

[Gerard H. Pille]

Could you show your custom log format?

[Val Petruchek]

Basically it's default combined log with 1 extra field: log_format coolname '$remote_addr - $remote_user [$time_local] ' '"$request" $status $body_bytes_sent [uid=$sent_http_x_userid] ' '"$http_referer" "$http_user_agent"';

[Alexey Ten]

Try to log $upstream_http_x_user_id

[Val Petruchek]

@AlexeyTen, you should post this as an answer so I can accept - it works!

[Val Petruchek]

Thank you, I've tried @AlexeyTen's answer first because it's an easier one - and it works.

[Val Petruchek]

I'm using more_clear_headers to hide the header from end client.

[Alexey Ten]

@ValPetruchek proxy_hide_header will do the same

[Val Petruchek]

this is rather confusing. I'm not a devops/sysadmin, just a fullstack dev whose stack is apparently becoming too full. As a developer, I believe there's a reason for having 2 different ways of achieving the same goal.