--proxy=X_Forwarded_For is not working

[snap9]

Problem: The IP address logged into the file given by --access-log=<logfile> is recording 127.0.0.1 instead of the real visitor IP address. This happens even if I specify --proxy=X_Forwarded_For.

I have also tried putting my entire Snap app (in Haskell) behind behindProxy X_Forwarded_For $ but that doesn't work either.

This is my nginx setup:

location / {
    proxy_set_header X-Real-IP       $remote_addr;
    proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    proxy_set_header Host            $http_host;
    proxy_set_header X-NginX-Proxy   true;

    proxy_pass http://127.0.0.1:4567/;
    proxy_redirect off;
}

What am I doing wrong?

[mightybyte]

Pinging @gregorycollins

[snap9]

For your information, rqClientAddr in my own Haskell code works perfectly to obtain the correct IP address. (When I run my Snap app with --proxy=X_Forwarded_For.)

It's just the log file that gets the incorrect IP address. Can you guys check the logging code? Maybe that's not using the correct forwarded IP address.

@mightybyte @gregorycollins

[sigrlami]

I can see this running snap app with Docker in Google Cloud, but not on standalone VM. On standalone VM x_forwarded_for is properly set, but rqClientAddr still gives local.

[karls]

I just wanted to comment that I'm seeing the same behaviour as @snap9 in snap-core-0.9.8.0 -- the log file displays 127.0.0.1 no matter what I do, but asking for rqClientAddr in a Handler and printing that yields the correct IP.

[hvr]

What makes this even weirder is that the logging code appears to use rqClientAddr as well: https://github.com/snapframework/snap-server/blob/master/src/Snap/Http/Server.hs#L143

Simple repro code:

{-# LANGUAGE OverloadedStrings #-}
module Main where

import Control.Monad.IO.Class
import           Control.Applicative
import           Snap.Core
import           Snap.Util.FileServe
import           Snap.Http.Server

main :: IO ()
main = quickHttpServe site

site :: Snap ()
site = ifTop $ do writeBS "hello world"
                  rq <- getRequest
                  liftIO $ print (rqClientAddr rq)

Invoking curl -H 'X-Forwarded-For: 1.2.3.4' -v http://localhost:8000/ results in the output:

no port specified, defaulting to port 8000
Listening on http://0.0.0.0:8000
"1.2.3.4"
127.0.0.1 - - [28/May/2017:23:48:50 +0200] "GET / HTTP/1.1" 200 24 - "curl/7.47.0"

[sopvop]

I belive that X_Forwarded_For proxy code is part of handler executed by server, it operates on request as passed to user handler. And logging is part of server code which operates on original request.

httpServe modifies the user handler with proxy and passes it to simpleHttpServe which then setups loggers and the rest.

httpServe :: Config Snap a -> Snap () -> IO ()
httpServe config handler0 = do
    conf <- completeConfig config
    let !handler = chooseProxy conf
    let serve    = compress conf . catch500 conf $ handler
    simpleHttpServe conf serve

And then in httpSession the handler is called with original request, which when modifies request and calls users handler. And at the bottom of same function access log is written with unmodified request.

Fixing this would require to move proxy handling logic up the call chain instead of reusing the behidProxy combinator.

Edit:

Actually you can probably use request modified by user handler (the ignored first field of returned tuple) for logging. But I'm not sure if this can break any other logging context.

[gregorycollins]

Could you please confirm that aa989e3 fixes?