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:

App sends custom header (like x-userid)
Nginx stores that value in access_log with custom log format $sent_http_x_userid
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

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"';` — Val Petruchek, Apr 13 '20 at 16:17
@AlexeyTen, you should post this as an answer so I can accept - it works! — Val Petruchek, Apr 17 '20 at 13:43

score 6 · Accepted Answer · answered Apr 17 '20 at 14:56

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;
    }
}

I'm using `more_clear_headers` to hide the header from end client. — Val Petruchek, Apr 17 '20 at 19:12
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. — Val Petruchek, Apr 17 '20 at 23:08

score 0 · Answer 2 · answered Apr 14 '20 at 11:39

I thought this would be simple, just store the header's contents in a variable (using "set"), and use that variable in your log_format, disregarding the cleared header. But that failed miserably: the set command is executed before calling the backend (when the upstream headers have yet to be set).

But using LUA was succesful:

            set $saved_uid "X";
            header_filter_by_lua_block {
              ngx.var.saved_uid = ngx.var.upstream_http_x_userid;
            }
            more_clear_headers 'x-userid';

and use the variable in log_format:

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

Thank you, I've tried @AlexeyTen's answer first because it's an easier one - and it works. — Val Petruchek, Apr 17 '20 at 13:43

Custom headers in nginx: log first, clean afterwards

2 Answers2