Nginx X-Forwarded-Protocol and X-Forwarded-For

I have a client that had multiples apache web servers sit behind the Nginx web load balancer. Currently both http and https requests are terminated on Nginx and the requests will then be proxied to the backend apache web servers at port 80 (i.e. http).

From backend web servers perspective, all traffic coming in are sort of masqueraded by the Nginx , web server could only see the requests are made by Nginx and the protocol was http. So my client would interest to know which protocol the original request was, whether it is http or the ssl-encrypted https.

Nginx do allow customization on proxy header via proxy_set_header attributes. So I added below parameter to the location block so that extra header will be passed to the backend web server.


Here is the reverse proxy configuration
    upstream backend_web_server_pool {
       server 1.2.3.4:80;
       server 1.2.3.5:80;
    }

Here is the http site configuration

server {
    listen       80;  # The http server
    ....     
   location / {
       proxy_pass http://backend_web_server_pool;
       proxy_set_header X-Forwarded-Protocol "http" ;
       proxy_set_header X-Forwarded-For $remote_addr;
    }
}




Here is the https site configuration
server {
    listen       443;  # The https server
    ssl                  on;
    ....

    location / {
       proxy_pass http://backend_web_server_pool;
       proxy_set_header X-Forwarded-Protocol "https" ;
       proxy_set_header X-Forwarded-For $remote_addr;
    }
}


So the line proxy_set_header X-Forwarded-Protocol "http" will pass a header named "X-Forwarded-Protocol" and its value "http" to the backend web server. You can replace this header value to any arbitrary value, e.g. "xyz123". After all it is just a placeholder or symbol to let you know where the request came from. The same logic applies to the HTTPS block however you may want to replace the value from "http" to "https" to avoid confusion. The line proxy_set_header X-Forwarded-For $remote_addr pass the variable remote_addr (i.e. the remote client IP address) to the backend web server.

Once the above configuration applied, restart nginx and then we can head to reconfigure the log format configuration on apache web server. We will now modify the combined log format to capture the X-Forwarded-For and X-Forwarded-Protocol.

#LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
LogFormat "%h %{X-Forwarded-For}i %{X-Forwarded-Protocol}i %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined

I added the %{X-Forwarded-For}i and %{X-Forwarded-Protocol}i to the combined log format followed by apache restart and now apache log could capture the client IP address and the original protocol.

Using gawk (GNU awk) to monitor /var/log/messages

I have a requirement to periodically scan through /var/log/messages to catch specific error message. The error itself is very time-sensitive and I want to be informed as soon as the message is shown on the log, ideally in a minute interval.

Usually people would suggest to periodically run grep against the log which is the simplest way to facilitate the need but it doesn't work for my scenario. The problem to simply run grep is that it may also capture unnecessary information. For example, I have below logs on my /var/log/messages.

Aug 3 12:40:06 test-box kernel: [1645652.295156] CPU0: Temperature/speed normal
Aug 3 15:05:28 test-box kernel: [1645673.980296] CPU1: Temperature/speed normal

If I simply use grep to catch above log entry in a minute interval, I will probably be informed at 12:40.06 and then all the way till the end of the day (i.e. when the /var/log/messages be rotated and cleaned up). Not to mention starting from 15:05:28, the grep script will catch 2 errors from the log, the lines being recorded at 12:40:05 and 15:05:28. However, the fact is that I actually need the one on 15:05:28.

After some research, it looks like gawk (GNU awk) would be the perfect tool to solve the problem. Eventually I come up with below gawk script to read /var/log/messages.


$ cat gawk-script
BEGIN {
    # Declare field seperator.
    FS="[- :.]";

    
    # Generate the timestamp
    NOW=systime();
    
    # The time interval that I want this script to read from
    # As long as I will run this script with cron in every minutes
    # I set the time interval to 1sec*60
    # So, for example when the script is run at 12:05, only log entries between 12:04 ~ 12:05 will be read.
    PAST=NOW-(60);

    
    # /var/log/messages start with the line in format of "Month date" (e.g Mar 23)
    # Ideally we can convert it to something like 23/3 but I want to be lazy, 
    # so I simply make use of the system time library and 
    # picked %Y %m to represent the Year and Month attributes.
    format="%Y %m";
    # LOGMTH will be something like "2012 10" (Oct 2012)
    # This will be used later to generate the timestamp of the log entry.
    LOGMTH=strftime(format, THEN)
}
{
    # Read the line of the log and convert it to a timestamp
    LOGTIME=mktime(LOGMTH " " $2 " " $3 " " $4 " " $5);
    # Below 3 lines can be commented out to debug with the value being read.
    #{print $2, $3, $4, $5};
    #{print LOGMTH};
    #{print LOGTIME};
    
    # print the log if the timestamp of the line is between PAST <> NOW.
    if(PAST<LOGTIME){print}
}

So here is a demo of the script.

$ cat /var/log/messages  ### totally 4 lines here
Aug 3 12:40:06 test-box kernel: [1645652.295156] CPU0: Temperature/speed normal
Aug 3 15:05:28 test-box kernel: [1645673.980296] CPU1: Temperature/speed normal Aug 3 18:03:31 test-box kernel: [1640277.321612] usb 2-2: new high speed USB device using ehci_hcd and address 28
Aug 3 18:03:32 test-box kernel: [1640277.474483] usb 2-2: configuration #1 chosen from 4 choices

$ date  #Lets check the current time
Wed Oct 3 18:04:24 HKT 2012

$ gawk -f gawk-script /var/log/messages
Oct 3 18:03:31 test-box kernel: [1640277.321612] usb 2-2: new high speed USB device using ehci_hcd and address 28
Oct 3 18:03:32 test-box kernel: [1640277.474483] usb 2-2: configuration #1 chosen from 4 choices

So, the script now only print everything captured within last minute. You can then use the script together with grep utility to catch the string you are interested.