Add ip address of ssh client and io statistics to log outputs
Problem to solve
Currently we can collect some statistics about git usage with parsing gitlab-shell log file and gitaly log file. There is records that can provide information about usernames, repositories etc. But there is no information about source client ip address. For http it can be solved by adding X-Forwarded-For header, for ssh currently it is impossible to see. Also there is no statistics about io operations with stdin/stdout by ssh commands in gitaly logs. Stdin/stdout in gitaly ssh can directly effect performance of gitlab, so we need to have some logs about this.
Example of current gitlab-shell log record:
level=info msg="executing git command" command="gitaly-receive-pack unix:/var/opt/gitlab/gitaly/gitaly.socket {\"repository\":{\"storage_name\":\"default\",\"relative_path\":\"root/repo.git\",\"git_object_directory\":\"\",\"git_alternate_object_directories\":[],\"gl_repository\":\"project-001\"},\"gl_repository\":\"project-001\",\"gl_id\":\"user-001\",\"gl_username\":\"testuser\"}" pid=10000 user="user with id user-001"
Example of current gitaly log record:
2018-05-05_01:04:33.97276 time="2018-05-05T01:04:33Z" level=info msg="spawn complete" args="[/opt/gitlab/embedded/bin/git --git-dir /var/opt/gitlab/git-data/repositories/martyn/linux.git rev-parse refs/heads/vme-testing]" command.exitCode=0 command.inblock=0 command.maxrss=25384 command.oublock=0 command.real_time_ms=54992.834446 command.system_time_ms=0 command.user_time_ms=0 grpc.meta.call_site=commit_languages grpc.meta.client_name=gitlab-web grpc.method=CommitLanguages grpc.request.glRepository=project-24 grpc.request.repoPath=martyn/linux.git grpc.request.repoStorage=default grpc.request.topLevelGroup=martyn grpc.service=gitaly.CommitService path=/opt/gitlab/embedded/bin/git peer.address=@ pid=3007 span.kind=server system=grpc
Proposal
Adding extra field to gitlab-shell log output sshclientaddress
for ssh-protocol operations.
Add extra fields to gitaly debug log output: command.stdin
and command.stdout
with amount of bytes received to spawned command.
What does success look like, and how can we measure that?
New log output for gitlab-shell should be:
level=info msg="executing git command" command="gitaly-upload-pack unix:/var/opt/gitlab/gitaly/gitaly.socket {\"repository\":{\"storage_name\":\"default\",\"relative_path\":\"root/test.git\",\"git_object_directory\":\"\",\"git_alternate_object_directories\":[],\"gl_repository\":\"project-1\"},\"sshclientaddress\":\"172.17.0.1\",\"gl_repository\":\"project-1\",\"gl_id\":\"key-1\",\"gl_username\":\"root\"}" pid=2128 user="user with key key-1"
New log output for gitaly should be:
level=debug msg="spawn complete" args="[/opt/gitlab/embedded/bin/git upload-pack /var/opt/gitlab/git-data/repositories/root/test.git]" command.exitCode=0 command.inblock=2120 command.maxrss=19204 command.oublock=0 command.real_time_ms=20.645899999999997 command.stdin=4 command.stdout=4 command.system_time_ms=0 command.user_time_ms=0 grpc.method=SSHUploadPack grpc.request.glRepository=project-1 grpc.request.repoPath=root/test.git grpc.request.repoStorage=default grpc.request.sshClientAddress=172.17.0.1 grpc.request.topLevelGroup=root grpc.service=gitaly.SSHService path=/opt/gitlab/embedded/bin/git peer.address=@ pid=2385 span.kind=server system=grpc