Merge pull request #56 from smashwilson/36-logger

Logger

6 files changed, 110 insertions, 17 deletions

diff --git a/lib/gitlab_config.rb b/lib/gitlab_config.rb
index ede554d..9dc5c66 100644
--- a/lib/gitlab_config.rb
+++ b/lib/gitlab_config.rb
@@ -31,6 +31,18 @@ class GitlabConfig
     redis['namespace'] || 'resque:gitlab'
   end
 
+  def log_file
+    @config['log_file'] ||= File.join(ROOT_PATH, 'gitlab-shell.log')
+  end
+
+  def log_level
+    @config['log_level'] ||= 'INFO'
+  end
+
+  def audit_usernames
+    @config['audit_usernames'] ||= false
+  end
+
   # Build redis command to write update event in gitlab queue
   def redis_command
     if redis.empty?
diff --git a/lib/gitlab_keys.rb b/lib/gitlab_keys.rb
index 7e6362a..03026ed 100644
--- a/lib/gitlab_keys.rb
+++ b/lib/gitlab_keys.rb
@@ -1,6 +1,7 @@
 require 'open3'
 
 require_relative 'gitlab_config'
+require_relative 'gitlab_logger'
 
 class GitlabKeys
   attr_accessor :auth_file, :key
@@ -17,6 +18,7 @@ class GitlabKeys
     when 'add-key'; add_key
     when 'rm-key';  rm_key
     else
+      $logger.warn "Attempt to execute invalid gitlab-keys command #{@command.inspect}."
       puts 'not allowed'
       false
     end
@@ -25,12 +27,14 @@ class GitlabKeys
   protected
 
   def add_key
+    $logger.info "Adding key #{@key_id} => #{@key.inspect}"
     cmd = "command=\"#{ROOT_PATH}/bin/gitlab-shell #{@key_id}\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty #{@key}"
     cmd = "echo \'#{cmd}\' >> #{auth_file}"
     system(cmd)
   end
 
   def rm_key
+    $logger.info "Removing key #{@key_id}"
     cmd = "sed -i '/shell #{@key_id}\"/d' #{auth_file}"
     system(cmd)
   end
diff --git a/lib/gitlab_logger.rb b/lib/gitlab_logger.rb
new file mode 100644
index 0000000..4b87e27
--- /dev/null
+++ b/lib/gitlab_logger.rb
@@ -0,0 +1,16 @@
+require 'logger'
+
+require_relative 'gitlab_config'
+
+def convert_log_level log_level
+  Logger.const_get(log_level.upcase)
+rescue NameError
+  $stderr.puts "WARNING: Unrecognized log level #{log_level.inspect}."
+  $stderr.puts "WARNING: Falling back to INFO."
+  Logger::INFO
+end
+
+config = GitlabConfig.new
+
+$logger = Logger.new(config.log_file)
+$logger.level = convert_log_level(config.log_level)
diff --git a/lib/gitlab_net.rb b/lib/gitlab_net.rb
index 3f0b58b..99d0044 100644
--- a/lib/gitlab_net.rb
+++ b/lib/gitlab_net.rb
@@ -3,6 +3,7 @@ require 'openssl'
 require 'json'
 
 require_relative 'gitlab_config'
+require_relative 'gitlab_logger'
 
 class GitlabNet
   def allowed?(cmd, repo, key, ref)
@@ -13,7 +14,6 @@ class GitlabNet
     key_id = key.gsub("key-", "")
 
     url = "#{host}/allowed?key_id=#{key_id}&action=#{cmd}&ref=#{ref}&project=#{project_name}"
-
     resp = get(url)
 
     !!(resp.code == '200' && resp.body == 'true')
@@ -40,6 +40,8 @@ class GitlabNet
   end
 
   def get(url)
+    $logger.debug "Performing GET #{url}"
+
     url = URI.parse(url)
     http = Net::HTTP.new(url.host, url.port)
 
@@ -57,7 +59,13 @@ class GitlabNet
       request.basic_auth config.http_settings['user'], config.http_settings['password']
     end
 
-    http.start {|http| http.request(request) }
+    http.start {|http| http.request(request) }.tap do |resp|
+      if resp.code == "200"
+        $logger.debug { "Received response #{resp.code} => <#{resp.body}>." }
+      else
+        $logger.error { "API call <GET #{url}> failed: #{resp.code} => <#{resp.body}>." }
+      end
+    end
   end
 
   def cert_store
diff --git a/lib/gitlab_projects.rb b/lib/gitlab_projects.rb
index 0b9bb8c..e60438e 100644
--- a/lib/gitlab_projects.rb
+++ b/lib/gitlab_projects.rb
@@ -2,6 +2,7 @@ require 'open3'
 require 'fileutils'
 
 require_relative 'gitlab_config'
+require_relative 'gitlab_logger'
 
 class GitlabProjects
   # Project name is a directory name for repository with .git at the end
@@ -31,6 +32,7 @@ class GitlabProjects
     when 'import-project'; import_project
     when 'fork-project'; fork_project
     else
+      $logger.warn "Attempt to execute invalid gitlab-projects command #{@command.inspect}."
       puts 'not allowed'
       false
     end
@@ -39,6 +41,7 @@ class GitlabProjects
   protected
 
   def add_project
+    $logger.info "Adding project #{@project_name} at <#{full_path}>."
     FileUtils.mkdir_p(full_path, mode: 0770)
     cmd = "cd #{full_path} && git init --bare && #{create_hooks_cmd}"
     system(cmd)
@@ -49,6 +52,7 @@ class GitlabProjects
   end
 
   def rm_project
+    $logger.info "Removing project #{@project_name} from <#{full_path}>."
     FileUtils.rm_rf(full_path)
   end
 
@@ -56,6 +60,7 @@ class GitlabProjects
   # URL must be publicly clonable
   def import_project
     @source = ARGV.shift
+    $logger.info "Importing project #{@project_name} from <#{@source}> to <#{full_path}>."
     cmd = "cd #{repos_path} && git clone --bare #{@source} #{project_name} && #{create_hooks_cmd}"
     system(cmd)
   end
@@ -71,15 +76,26 @@ class GitlabProjects
   def mv_project
     new_path = ARGV.shift
 
-    return false unless new_path
+    unless new_path
+      $logger.error "mv-project failed: no destination path provided."
+      return false
+    end
 
     new_full_path = File.join(repos_path, new_path)
 
-    # check if source repo exists
-    # and target repo does not exist
-    return false unless File.exists?(full_path)
-    return false if File.exists?(new_full_path)
+    # verify that the source repo exists
+    unless File.exists?(full_path)
+      $logger.error "mv-project failed: source path <#{full_path}> does not exist."
+      return false
+    end
+
+    # ...and that the target repo does not exist
+    if File.exists?(new_full_path)
+      $logger.error "mv-project failed: destination path <#{new_full_path}> already exists."
+      return false
+    end
 
+    $logger.info "Moving project #{@project_name} from <#{full_path}> to <#{new_full_path}>."
     FileUtils.mv(full_path, new_full_path)
   end
 
@@ -87,16 +103,26 @@ class GitlabProjects
     new_namespace = ARGV.shift
 
     # destination namespace must be provided
-    return false unless new_namespace
+    unless new_namespace
+      $logger.error "fork-project failed: no destination namespace provided."
+      return false
+    end
 
-    #destination namespace must exist
+    # destination namespace must exist
     namespaced_path = File.join(repos_path, new_namespace)
-    return false unless File.exists?(namespaced_path)
+    unless File.exists?(namespaced_path)
+      $logger.error "fork-project failed: destination namespace <#{namespaced_path}> does not exist."
+      return false
+    end
 
-    #a project of the same name cannot already be within the destination namespace
+    # a project of the same name cannot already be within the destination namespace
     full_destination_path = File.join(namespaced_path, project_name.split('/')[-1])
-    return false if File.exists?(full_destination_path)
+    if File.exists?(full_destination_path)
+      $logger.error "fork-project failed: destination repository <#{full_destination_path}> already exists."
+      return false
+    end
 
+    $logger.info "Forking project from <#{full_path}> to <#{full_destination_path}>."
     cmd = "cd #{namespaced_path} && git clone --bare #{full_path} && #{create_hooks_to(full_destination_path)}"
     system(cmd)
   end
@@ -108,7 +134,6 @@ class GitlabProjects
     up_hook_path = File.join(ROOT_PATH, 'hooks', 'update')
 
     "ln -s #{pr_hook_path} #{dest_path}/hooks/post-receive && ln -s #{up_hook_path} #{dest_path}/hooks/update"
-
   end
 
 end
diff --git a/lib/gitlab_shell.rb b/lib/gitlab_shell.rb
index 7a9e3df..01ef4a1 100644
--- a/lib/gitlab_shell.rb
+++ b/lib/gitlab_shell.rb
@@ -8,7 +8,9 @@ class GitlabShell
   def initialize
     @key_id = /key-[0-9]+/.match(ARGV.join).to_s
     @origin_cmd = ENV['SSH_ORIGINAL_COMMAND']
-    @repos_path = GitlabConfig.new.repos_path
+    @config = GitlabConfig.new
+    @repos_path = @config.repos_path
+    @user_tried = false
   end
 
   def exec
@@ -20,13 +22,18 @@ class GitlabShell
 
         if validate_access
           process_cmd
+        else
+          message = "gitlab-shell: Access denied for git command <#{@origin_cmd}> by #{log_username}."
+          $logger.warn message
+          $stderr.puts "Access denied."
         end
       else
+        message = "gitlab-shell: Attempt to execute disallowed command <#{@origin_cmd}> by #{log_username}."
+        $logger.warn message
         puts 'Not allowed command'
       end
     else
-      user = api.discover(@key_id)
-      puts "Welcome to GitLab, #{user && user['name'] || 'Anonymous'}!"
+      puts "Welcome to GitLab, #{username}!"
     end
   end
 
@@ -44,7 +51,9 @@ class GitlabShell
 
   def process_cmd
     repo_full_path = File.join(repos_path, repo_name)
-    exec_cmd "#{@git_cmd} #{repo_full_path}"
+    cmd = "#{@git_cmd} #{repo_full_path}"
+    $logger.info "gitlab-shell: executing git command <#{cmd}> for #{log_username}."
+    exec_cmd(cmd)
   end
 
   def validate_access
@@ -58,4 +67,23 @@ class GitlabShell
   def api
     GitlabNet.new
   end
+
+  def user
+    # Can't use "@user ||=" because that will keep hitting the API when @user is really nil!
+    if @user_tried
+      @user
+    else
+      @user_tried = true
+      @user = api.discover(@key_id)
+    end
+  end
+
+  def username
+    user && user['name'] || 'Anonymous'
+  end
+
+  # User identifier to be used in log messages.
+  def log_username
+    @config.audit_usernames ? username : "user with key #{@key_id}"
+  end
 end