Skip to content

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.

Edited by Anton Smith