Requests coming from Internal network is logged as 127.0.0.1 on `production.log` since 11.6
Summary
Starting from 11.6, If GitLab is running on a private network, and is accessed from within the private network, the production.log
is logging 127.0.0.1 instead of the correct private IP address.
This is only observed on the production.log
. Corresponding logs on production_json.log
& nginx/gitlab_access.log
is logging the correct private IP address of the server performing the request.
api_json.log
is logging multiple IP addresses starting from 11.6 and in it logs both the private IP of the server performing request & 127.0.0.1
The same behavior above is still observed in 11.8. No additional configuration is added on GitLab server.
There is no issue when the server is accessed from outside the internet. As in production.log
logging the correct IP. The api_json.log
is logging the correct IP twice.
The same behavior is not observed on 11.5. production.log
. production_json.log
, api_json.log
, & nginx/gitlab_access.log
are logging the correct private IP
Steps to reproduce
- Install GitLab omnibus on a private network
- Log in as root, create a project open to public
- Setup another server within the same private network
- Curl endpoints to generate logs:
curl "http://gitlab.private.server/root/test"
curl "http://gitlab.private.server/api/v4/projects" -> to generate api_json.log
Note: This is tested on AWS instances, having the server on the same VPC & the same region.
What is the current bug behavior?
127.0.0.1
is logged on production.log
What is the expected correct behavior?
the correct private IP address is logged on production.log
Relevant logs and/or screenshots
Logs from 11.6
Ngnix log:
172.31.11.80 - - [12/Mar/2019:09:49:38 +0000] "GET /root/test HTTP/1.1" 200 36982 "" "curl/7.58.0"
172.31.11.80 - - [12/Mar/2019:09:49:45 +0000] "GET /api/v4/projects HTTP/1.1" 200 679 "" "curl/7.58.0"
production.log: ##### NOTE THE 127.0.0.1 addresses
Started GET "/root/test" for 127.0.0.1 at 2019-03-12 09:49:37 +0000
Processing by ProjectsController#show as */*
Parameters: {"namespace_id"=>"root", "id"=>"test"}
Completed 200 OK in 1413ms (Views: 1284.3ms | ActiveRecord: 49.7ms | Elasticsearch: 0.0ms)
Started GET "/api/v4/projects" for 127.0.0.1 at 2019-03-12 09:49:45 +0000
Processing by Gitlab::RequestForgeryProtection::Controller#index as */*
Completed 200 OK in 1ms (ActiveRecord: 0.0ms | Elasticsearch: 0.0ms)
production_json.log:
{"method":"GET","path":"/root/test","format":"*/*","controller":"ProjectsController","action":"show","status":200,"duration":1414.23,"view":1284.31,"db":49.68,"time":"2019-03-12T09:49:37.334Z","params":[{"key":"namespace_id","value":"root"},{"key":"id","value":"test"}],"remote_ip":"172.31.11.80","user_id":null,"username":null,"ua":"curl/7.58.0","gitaly_calls":9,"correlation_id":"kjPlMh480oa"}
{"method":"GET","path":"/api/v4/projects","format":"*/*","controller":"Gitlab::RequestForgeryProtection::Controller","action":"index","status":200,"duration":1.63,"view":0.0,"db":0.0,"time":"2019-03-12T09:49:45.615Z","params":[],"remote_ip":null,"user_id":null,"username":null,"ua":null,"correlation_id":"Fezao79gJa3"}
api_json.log: ##### NOTE the private IP and 127.0.0.1
{"time":"2019-03-12T09:49:45.793Z","severity":"INFO","duration":189.68,"db":18.69,"view":170.99,"status":200,"method":"GET","path":"/api/v4/projects","params":[],"host":"awinata-116.winzy.io","ip":"172.31.11.80, 127.0.0.1","ua":"curl/7.58.0","route":"/api/:version/projects","queue_duration":22.24,"gitaly_calls":0,"correlation_id":"Fezao79gJa3"}
Logs from 11.5 -> No issue
Ngnix log:
172.31.1.234 - - [12/Mar/2019:09:47:33 +0000] "GET /root/test HTTP/1.1" 200 35237 "" "curl/7.58.0"
172.31.1.234 - - [12/Mar/2019:09:47:34 +0000] "GET /api/v4/projects HTTP/1.1" 200 655 "" "curl/7.58.0"
production.log:
Started GET "/root/test" for 172.31.1.234 at 2019-03-12 09:47:30 +0000
Processing by ProjectsController#show as */*
Parameters: {"namespace_id"=>"root", "id"=>"test"}
Completed 200 OK in 2070ms (Views: 1877.7ms | ActiveRecord: 45.6ms | Elasticsearch: 0.0ms)
Started GET "/api/v4/projects" for 172.31.1.234 at 2019-03-12 09:47:34 +0000
Processing by Gitlab::RequestForgeryProtection::Controller#index as */*
Completed 200 OK in 0ms (ActiveRecord: 0.0ms | Elasticsearch: 0.0ms)
production_json.log:
{"method":"GET","path":"/root/test","format":"*/*","controller":"ProjectsController","action":"show","status":200,"duration":2071.43,"view":1877.67,"db":45.56,"time":"2019-03-12T09:47:31.059Z","params":[{"key":"namespace_id","value":"root"},{"key":"id","value":"test"}],"remote_ip":"172.31.1.234","user_id":null,"username":null,"ua":"curl/7.58.0","gitaly_calls":9}
{"method":"GET","path":"/api/v4/projects","format":"*/*","controller":"Gitlab::RequestForgeryProtection::Controller","action":"index","status":200,"duration":1.27,"view":0.0,"db":0.0,"time":"2019-03-12T09:47:34.843Z","params":[],"remote_ip":null,"user_id":null,"username":null,"ua":null}
api_json.log:
{"time":"2019-03-12T09:47:34.951Z","severity":"INFO","duration":122.78,"db":8.04,"view":114.74000000000001,"status":200,"method":"GET","path":"/api/v4/projects","params":[],"host":"awinata-115.winzy.io","ip":"172.31.1.234","ua":"curl/7.58.0","route":"/api/:version/projects","queue_duration":23.71,"gitaly_calls":3}
Logs from 11.6 -> access from the internet, no issue:
xxx.xxx.xxx.xxx = normal IP address on the internet
Ngnix log:
xxx.xxx.xxx.xxx - - [12/Mar/2019:09:50:08 +0000] "GET /root/test HTTP/1.1" 200 36982 "" "curl/7.54.0"
xxx.xxx.xxx.xxx - - [12/Mar/2019:09:50:12 +0000] "GET /api/v4/projects HTTP/1.1" 200 679 "" "curl/7.54.0"
production.log:
Started GET "/root/test" for xxx.xxx.xxx.xxx at 2019-03-12 09:50:06 +0000
Processing by ProjectsController#show as */*
Parameters: {"namespace_id"=>"root", "id"=>"test"}
Completed 200 OK in 1465ms (Views: 1329.2ms | ActiveRecord: 46.3ms | Elasticsearch: 0.0ms)
Scheduling removal of build artifacts
Started GET "/api/v4/projects" for xxx.xxx.xxx.xxx at 2019-03-12 09:50:12 +0000
Processing by Gitlab::RequestForgeryProtection::Controller#index as */*
Completed 200 OK in 0ms (ActiveRecord: 0.0ms | Elasticsearch: 0.0ms)
production_json.log:
{"method":"GET","path":"/root/test","format":"*/*","controller":"ProjectsController","action":"show","status":200,"duration":1471.22,"view":1329.18,"db":46.26,"time":"2019-03-12T09:50:06.779Z","params":[{"key":"namespace_id","value":"root"},{"key":"id","value":"test"}],"remote_ip":"xxx.xxx.xxx.xxx","user_id":null,"username":null,"ua":"curl/7.54.0","gitaly_calls":9,"correlation_id":"osEseVwDJo6"}
{"method":"GET","path":"/api/v4/projects","format":"*/*","controller":"Gitlab::RequestForgeryProtection::Controller","action":"index","status":200,"duration":1.57,"view":0.0,"db":0.0,"time":"2019-03-12T09:50:12.227Z","params":[],"remote_ip":null,"user_id":null,"username":null,"ua":null,"correlation_id":"3cCpIpIDWw5"}
api_json.log #### Note IP is repeated
{"time":"2019-03-12T09:50:12.260Z","severity":"INFO","duration":34.86,"db":5.74,"view":29.119999999999997,"status":200,"method":"GET","path":"/api/v4/projects","params":[],"host":"awinata-116.winzy.io","ip":"xxx.xxx.xxx.xxx, xxx.xxx.xxx.xxx","ua":"curl/7.54.0","route":"/api/:version/projects","queue_duration":43.4,"gitaly_calls":0,"correlation_id":"3cCpIpIDWw5"}
Possible fixes
This might be related to whitelisting issue: https://gitlab.com/gitlab-org/gitlab-ce/issues/58573
Internal only ticket from current user in ZD: https://gitlab.zendesk.com/agent/tickets/113249