username/user_id keys in production_json.log is null
Summary
The username
and user_id
keys in production_json.log
are null
in GitLab 13.0.6
. In GitLab 12.10.11
, these keys were populated.
Steps to reproduce
The way we reproduced this was by cloning a project via HTTP on both a 13.0.6
instance and a 12.10.11
instance, and then looking at the log requests in the production_json.log
. On 12.10.11
, the user_id
and username
values are present, but on 13.0.6
, the values are null
. See JSON output in Relevant logs and/or screenshots.
Example Project
N/A
What is the current bug behavior?
Log entries in production_json.log
have null
values for user_id
and username
keys.
What is the expected correct behavior?
Log entries in production_json.log
should have the authenticated user values for the user_id
and username
keys.
Relevant logs and/or screenshots
production_json.log
on 12.10.11-ee
:
{
"method":"POST",
"path":"/root/project.git/git-upload-pack",
"format":null,
"controller":"Repositories::GitHttpController",
"action":"git_upload_pack",
"status":200,
"time":"2020-06-18T03:08:45.369Z",
"params":[
{
"key":"namespace_id",
"value":"root"
},
{
"key":"repository_id",
"value":"project.git"
}
],
"remote_ip":"x.x.x.x",
"user_id":1,
"username":"root",
"ua":"git/2.26.2",
"queue_duration_s":null,
"redis_calls":3,
"redis_duration_s":0.0,
"correlation_id":"c8afb078-e21a-4b66-a055-89c2b18cba82",
"cpu_s":0.09,
"db_duration_s":0.01,
"view_duration_s":0.0,
"duration_s":0.09
}
production_json.log
on 13.0.6-ee
:
{
"method":"POST",
"path":"/root/project.git/git-upload-pack",
"format":null,
"controller":"Repositories::GitHttpController",
"action":"git_upload_pack",
"status":200,
"time":"2020-06-18T01:47:59.956Z",
"params":[
{
"key":"namespace_id",
"value":"root"
},
{
"key":"repository_id",
"value":"project.git"
}
],
"remote_ip":"x.x.x.x",
"user_id":null,
"username":null,
"ua":"git/2.26.2",
"queue_duration_s":null,
"correlation_id":"eaac78b9-74ed-4a16-bb93-bb0f15ea8c6c",
"meta.project":"root/project",
"meta.root_namespace":"group",
"meta.caller_id":"Repositories::GitHttpController#git_upload_pack",
"redis_calls":1,
"redis_duration_s":0.000253,
"cpu_s":0.05,
"db_duration_s":0.00945,
"view_duration_s":0.00032,
"duration_s":0.03768
}
Output of checks
(If you are reporting a bug on GitLab.com, write: This bug happens on GitLab.com)
Results of GitLab environment info
Expand for output related to GitLab environment info
(For installations with omnibus-gitlab package run and paste the output of: `sudo gitlab-rake gitlab:env:info`) (For installations from source run and paste the output of: `sudo -u git -H bundle exec rake gitlab:env:info RAILS_ENV=production`)
Results of GitLab application Check
Expand for output related to the GitLab application check
(For installations with omnibus-gitlab package run and paste the output of:
sudo gitlab-rake gitlab:check SANITIZE=true
)(For installations from source run and paste the output of:
sudo -u git -H bundle exec rake gitlab:check RAILS_ENV=production SANITIZE=true
)(we will only investigate if the tests are passing)
Possible fixes
It looks like the log entries are set here https://gitlab.com/gitlab-org/gitlab/-/blob/master/app/controllers/application_controller.rb#L158-159
This file has been changed several times over the last month but this commit seems to be related to logging 05b7fccd and I wonder if this broke anything? cc @reprazent since you were the author of this commit, just a heads up.