Commit a4c89270 authored by Paco Guzman's avatar Paco Guzman

Instrument GitLab Shell and log metrics data to a file

parent b30d957f
v3.6.5 v3.6.5
- Test against ruby 2.3 - Test against ruby 2.3
- Instrument GitLab Shell and log metrics data to a file
v3.6.4 v3.6.4
- Fix rsync with ionice command building - Fix rsync with ionice command building
......
...@@ -6,13 +6,16 @@ ...@@ -6,13 +6,16 @@
require_relative '../lib/gitlab_init' require_relative '../lib/gitlab_init'
require File.join(ROOT_PATH, 'lib', 'gitlab_projects') require File.join(ROOT_PATH, 'lib', 'gitlab_projects')
require File.join(ROOT_PATH, 'lib', 'gitlab_metrics')
repository_storage_paths = ARGV repository_storage_paths = ARGV
repository_storage_paths.each do |repo_path| repository_storage_paths.each do |repo_path|
Dir["#{repo_path.chomp('/')}/*/*.git"].each do |repo| Dir["#{repo_path.chomp('/')}/*/*.git"].each do |repo|
begin begin
GitlabMetrics.measure('command-create-hooks') do
GitlabProjects.create_hooks(repo) GitlabProjects.create_hooks(repo)
end
rescue Errno::ENOENT rescue Errno::ENOENT
# The user must have deleted their repository. Ignore. # The user must have deleted their repository. Ignore.
end end
......
...@@ -54,4 +54,8 @@ class GitlabConfig ...@@ -54,4 +54,8 @@ class GitlabConfig
def git_trace_log_file def git_trace_log_file
@config['git_trace_log_file'] @config['git_trace_log_file']
end end
def metrics_log_file
@config['metrics_log_file'] ||= File.join(ROOT_PATH, 'gitlab-shell-metrics.log')
end
end end
...@@ -2,6 +2,7 @@ require 'timeout' ...@@ -2,6 +2,7 @@ require 'timeout'
require_relative 'gitlab_config' require_relative 'gitlab_config'
require_relative 'gitlab_logger' require_relative 'gitlab_logger'
require_relative 'gitlab_metrics'
class GitlabKeys class GitlabKeys
class KeyError < StandardError ; end class KeyError < StandardError ; end
...@@ -28,19 +29,27 @@ class GitlabKeys ...@@ -28,19 +29,27 @@ class GitlabKeys
end end
def exec def exec
GitlabMetrics.measure("command-#{@command}") do
case @command case @command
when 'add-key'; add_key when 'add-key';
when 'batch-add-keys'; batch_add_keys add_key
when 'rm-key'; rm_key when 'batch-add-keys';
when 'list-keys'; puts list_keys batch_add_keys
when 'clear'; clear when 'rm-key';
when 'check-permissions'; check_permissions rm_key
when 'list-keys';
list_keys
when 'clear';
clear
when 'check-permissions';
check_permissions
else else
$logger.warn "Attempt to execute invalid gitlab-keys command #{@command.inspect}." $logger.warn "Attempt to execute invalid gitlab-keys command #{@command.inspect}."
puts 'not allowed' puts 'not allowed'
false false
end end
end end
end
protected protected
......
require 'logger'
require_relative 'gitlab_config'
module GitlabMetrics
module System
# THREAD_CPUTIME is not supported on OS X
if Process.const_defined?(:CLOCK_THREAD_CPUTIME_ID)
def self.cpu_time
Process.
clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :millisecond)
end
else
def self.cpu_time
Process.
clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond)
end
end
# Returns the current monotonic clock time in a given precision.
#
# Returns the time as a Fixnum.
def self.monotonic_time
Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond)
end
end
def self.logger
@logger ||= Logger.new(GitlabConfig.new.metrics_log_file)
end
# Measures the execution time of a block.
#
# Example:
#
# GitlabMetrics.measure(:find_by_username_duration) do
# User.find_by_username(some_username)
# end
#
# name - The name of the field to store the execution time in.
#
# Returns the value yielded by the supplied block.
def self.measure(name)
start_real = System.monotonic_time
start_cpu = System.cpu_time
retval = yield
real_time = System.monotonic_time - start_real
cpu_time = System.cpu_time - start_cpu
logger.debug { "name=#{name.inspect} wall_time=#{real_time.inspect} cpu_time=#{cpu_time.inspect}" }
retval
end
end
...@@ -4,6 +4,7 @@ require 'open3' ...@@ -4,6 +4,7 @@ require 'open3'
require_relative 'gitlab_config' require_relative 'gitlab_config'
require_relative 'gitlab_logger' require_relative 'gitlab_logger'
require_relative 'gitlab_metrics'
require_relative 'gitlab_reference_counter' require_relative 'gitlab_reference_counter'
class GitlabProjects class GitlabProjects
...@@ -50,26 +51,41 @@ class GitlabProjects ...@@ -50,26 +51,41 @@ class GitlabProjects
end end
def exec def exec
GitlabMetrics.measure("command-#{@command}") do
case @command case @command
when 'create-tag'; create_tag when 'create-tag';
when 'add-project'; add_project create_tag
when 'list-projects'; puts list_projects when 'add-project';
when 'rm-project'; rm_project add_project
when 'mv-project'; mv_project when 'list-projects';
when 'mv-storage'; mv_storage puts list_projects
when 'import-project'; import_project when 'rm-project';
when 'fork-project'; fork_project rm_project
when 'fetch-remote'; fetch_remote when 'mv-project';
when 'push-branches'; push_branches mv_project
when 'delete-remote-branches'; delete_remote_branches when 'mv-storage';
when 'list-remote-tags'; list_remote_tags mv_storage
when 'gc'; gc when 'import-project';
import_project
when 'fork-project';
fork_project
when 'fetch-remote';
fetch_remote
when 'push-branches';
push_branches
when 'delete-remote-branches';
delete_remote_branches
when 'list-remote-tags';
list_remote_tags
when 'gc';
gc
else else
$logger.warn "Attempt to execute invalid gitlab-projects command #{@command.inspect}." $logger.warn "Attempt to execute invalid gitlab-projects command #{@command.inspect}."
puts 'not allowed' puts 'not allowed'
false false
end end
end end
end
protected protected
......
...@@ -2,6 +2,7 @@ require 'shellwords' ...@@ -2,6 +2,7 @@ require 'shellwords'
require 'pathname' require 'pathname'
require_relative 'gitlab_net' require_relative 'gitlab_net'
require_relative 'gitlab_metrics'
class GitlabShell class GitlabShell
class AccessDeniedError < StandardError; end class AccessDeniedError < StandardError; end
...@@ -32,7 +33,9 @@ class GitlabShell ...@@ -32,7 +33,9 @@ class GitlabShell
args = Shellwords.shellwords(origin_cmd) args = Shellwords.shellwords(origin_cmd)
parse_cmd(args) parse_cmd(args)
verify_access if GIT_COMMANDS.include?(args.first) if GIT_COMMANDS.include?(args.first)
GitlabMetrics.measure('verify-access') { verify_access }
end
process_cmd(args) process_cmd(args)
...@@ -118,11 +121,11 @@ class GitlabShell ...@@ -118,11 +121,11 @@ class GitlabShell
$logger.info "gitlab-shell: executing git-annex command <#{parsed_args.join(' ')}> for #{log_username}." $logger.info "gitlab-shell: executing git-annex command <#{parsed_args.join(' ')}> for #{log_username}."
exec_cmd(*parsed_args) exec_cmd(*parsed_args)
elsif @command == 'git-lfs-authenticate' elsif @command == 'git-lfs-authenticate'
GitlabMetrics.measure('lfs-authenticate') do
$logger.info "gitlab-shell: Processing LFS authentication for #{log_username}." $logger.info "gitlab-shell: Processing LFS authentication for #{log_username}."
lfs_authenticate lfs_authenticate
end
else else
$logger.info "gitlab-shell: executing git command <#{@command} #{repo_path}> for #{log_username}." $logger.info "gitlab-shell: executing git command <#{@command} #{repo_path}> for #{log_username}."
exec_cmd(@command, repo_path) exec_cmd(@command, repo_path)
......
...@@ -53,7 +53,7 @@ describe GitlabKeys do ...@@ -53,7 +53,7 @@ describe GitlabKeys do
end end
context "without file writing" do context "without file writing" do
before { gitlab_keys.stub(:open) } before { allow(gitlab_keys).to receive(:open) }
before { create_authorized_keys_fixture } before { create_authorized_keys_fixture }
it "should log an add-key event" do it "should log an add-key event" do
...@@ -106,7 +106,7 @@ describe GitlabKeys do ...@@ -106,7 +106,7 @@ describe GitlabKeys do
context "without file writing" do context "without file writing" do
before do before do
gitlab_keys.should_receive(:open).and_yield(mock(:file, puts: nil, chmod: nil)) gitlab_keys.should_receive(:open).and_yield(double(:file, puts: nil, chmod: nil))
end end
it "should log an add-key event" do it "should log an add-key event" do
......
require_relative 'spec_helper'
require_relative '../lib/gitlab_metrics'
describe GitlabMetrics do
describe '::measure' do
it 'returns the return value of the block' do
val = described_class.measure('foo') { 10 }
expect(val).to eq(10)
end
it 'write in a file metrics data' do
result = nil
expect(described_class.logger).to receive(:debug) do |&b|
result = b.call
end
described_class.measure('foo') { 10 }
expect(result).to match(/name=\"foo\" wall_time=\d+ cpu_time=\d+/)
end
it 'calls proper measure methods' do
expect(described_class::System).to receive(:monotonic_time).twice.and_call_original
expect(described_class::System).to receive(:cpu_time).twice.and_call_original
described_class.measure('foo') { 10 }
end
end
end
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment