title: How to log real client ip in rails log when behind proxy like nginx
body: <h3>Problem</h3>
  
  <p>I have a rails 3.2.15 with rack 1.4.5 setup on two servers. First server is a nginx proxy serving static assets. Second server is a unicorn serving the rails app.</p>
  
  <p>In Rails <code>production.log</code> I always see the nginx IP address (10.0.10.150) and not my client IP address (10.0.10.62):</p>
  
  <pre><code>Started GET "/" for 10.0.10.150 at 2013-11-21 13:51:05 +0000
  </code></pre>
  
  <p>I want to have the real client IP in logs.</p>
  
  <h3>Our Setup</h3>
  
  <p>The HTTP headers <code>X-Forwarded-For</code> and <code>X-Real-IP</code> are setup correctly in nginx and I have defined <code>10.0.10.62</code> as not being a trusted proxy address by setting <code>config.action_dispatch.trusted_proxies = /^127\.0\.0\.1$/</code> in <code>config/environments/production.rb</code>, thanks to another <a href="https://stackoverflow.com/a/19904490/177665">answer</a>. I can check it is working because I log them in the application controller:</p>
  
  <p>in <code>app/controllers/application_controller.rb</code>:</p>
  
  <pre><code>class ApplicationController &lt; ActionController::Base
      before_filter :log_ips
  
      def log_ips
          logger.info("request.ip = #{request.ip} and request.remote_ip = #{request.remote_ip}")
      end
  end
  </code></pre>
  
  <p>in <code>production.log</code>:</p>
  
  <pre><code>request.ip = 10.0.10.150 and request.remote_ip = 10.0.10.62
  </code></pre>
  
  <h3>Investigation</h3>
  
  <p>When investigating, I saw that <a href="https://github.com/rails/rails/blob/v3.2.15/railties/lib/rails/rack/logger.rb" rel="noreferrer"><code>Rails::Rack::Logger</code></a> is responsible for logging the IP address:</p>
  
  <pre><code>def started_request_message(request)
    'Started %s "%s" for %s at %s' % [
      request.request_method,
      request.filtered_path,
      request.ip,
      Time.now.to_default_s ]
  end
  </code></pre>
  
  <p><code>request</code> is an instance of <a href="https://github.com/rails/rails/blob/v3.2.15/actionpack/lib/action_dispatch/http/request.rb" rel="noreferrer"><code>ActionDispatch::Request</code></a>. It inherits <a href="https://github.com/rack/rack/blob/1.4.5/lib/rack/request.rb" rel="noreferrer"><code>Rack::Request</code></a> which defines how the IP address is computed:</p>
  
  <pre><code>def trusted_proxy?(ip)
    ip =~ /^127\.0\.0\.1$|^(10|172\.(1[6-9]|2[0-9]|30|31)|192\.168)\.|^::1$|^fd[0-9a-f]{2}:.+|^localhost$/i
  end
  
  def ip
    remote_addrs = @env['REMOTE_ADDR'] ? @env['REMOTE_ADDR'].split(/[,\s]+/) : []
    remote_addrs.reject! { |addr| trusted_proxy?(addr) }
  
    return remote_addrs.first if remote_addrs.any?
  
    forwarded_ips = @env['HTTP_X_FORWARDED_FOR'] ? @env['HTTP_X_FORWARDED_FOR'].strip.split(/[,\s]+/) : []
  
    if client_ip = @env['HTTP_CLIENT_IP']
      # If forwarded_ips doesn't include the client_ip, it might be an
      # ip spoofing attempt, so we ignore HTTP_CLIENT_IP
      return client_ip if forwarded_ips.include?(client_ip)
    end
  
    return forwarded_ips.reject { |ip| trusted_proxy?(ip) }.last || @env["REMOTE_ADDR"]
  end
  </code></pre>
  
  <p>The forwarded IP address are filtered with <code>trusted_proxy?</code>. Because our nginx server is using a public IP address and not a private IP address, <code>Rack::Request#ip</code> thinks it is not a proxy but the real client ip that tries to do some IP spoofing. That's why I see nginx IP address in my logs.</p>
  
  <p>In log excerpts, client and servers have IP address 10.0.10.x because I am using virtual machines to reproduce our production environment.</p>
  
  <h3>Our current solution</h3>
  
  <p>To circumvent this behavior, I wrote a little Rack middleware located in app/middleware/remote_ip_logger.rb:</p>
  
  <pre><code>class RemoteIpLogger
    def initialize(app)
      @app = app
    end
  
    def call(env)
      remote_ip = env["action_dispatch.remote_ip"]
      Rails.logger.info "Remote IP: #{remote_ip}" if remote_ip
      @app.call(env)
    end
  end
  </code></pre>
  
  <p>And I insert it just after the <code>ActionDispatch::RemoteIp</code> middleware</p>
  
  <pre><code>config.middleware.insert_after ActionDispatch::RemoteIp, "RemoteIpLogger"
  </code></pre>
  
  <p>This way I can see the real client IP in logs:</p>
  
  <pre><code>Started GET "/" for 10.0.10.150 at 2013-11-21 13:59:06 +0000
  Remote IP: 10.0.10.62
  </code></pre>
  
  <p>I feel a little uncomfortable with this solution. nginx+unicorn is a common setup for rails application. If I have to log the client IP myself, it means I have missed something. Is it because the Nginx server is using a public IP address when communicating with the rails server? Is there a way to customize the <code>trusted_proxy?</code> method of <code>Rack::Request</code>?</p>
  
  <p><strong>EDITED</strong>: add nginx configuration and a HTTP request capture</p>
  
  <p><code>/etc/nginx/sites-enabled/site.example.com.conf</code>:</p>
  
  <pre><code>server {
      server_name    site.example.com;
      listen         80;
  
  
      location ^~ /assets/ {
         root /home/deployer/site/shared;
         expires 30d;
      }
  
      location / {
        root /home/deployer/site/current/public;
        try_files $uri @proxy;
      }
  
      location @proxy {
        access_log  /var/log/nginx/site.access.log combined_proxy;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto $scheme;
        proxy_set_header Host $http_host;
        proxy_redirect off;
        proxy_read_timeout 300;
  
        proxy_pass http://rails.example.com:8080;
      }
  }
  </code></pre>
  
  <p>Nginx server is <code>10.0.10.150</code>. Rails server is <code>10.0.10.190</code>. My machine is <code>10.0.10.62</code> When doing <code>curl http://10.0.10.150/</code> from my machine, a <code>tcpdump port 8080 -i eth0 -Aq -s 0</code> on rails server show theses request HTTP headers:</p>
  
  <pre><code>GET / HTTP/1.0
  X-Forwarded-For: 10.0.10.62
  X-Forwarded-Proto: http
  Host: 10.0.10.150
  Connection: close
  User-Agent: curl/7.29.0
  Accept: */*
  </code></pre>
  
  <p>And the rails log <code>/home/deployer/site/current/log/production.log</code> (<em>Remote IP</em> and <em>request.ip</em> lines being added by custom code):</p>
  
  <pre><code>Started GET "/" for 10.0.10.150 at 2013-11-22 08:01:17 +0000
  Remote IP: 10.0.10.62
  Processing by Devise::RegistrationsController#new as */*
  request.ip = 10.0.10.150 and request.remote_ip = 10.0.10.62
    Rendered devise/shared/_links.erb (0.1ms)
    Rendered devise/registrations/new.html.erb within layouts/application (2.3ms)
    Rendered layouts/_landing.html.erb (1.5ms)
  Completed 200 OK in 8.9ms (Views: 7.5ms | ActiveRecord: 0.0ms)
  </code></pre>