Quite hacky, but works.file-access-logger

5 files changed, 74 insertions, 44 deletions

diff --git a/config/initializers/0_file_access_logger.rb b/config/initializers/0_file_access_logger.rb
index a750ba5f844..d3f6163a224 100644
--- a/config/initializers/0_file_access_logger.rb
+++ b/config/initializers/0_file_access_logger.rb
@@ -1,20 +1,17 @@
-# FileUtils = Gitlab::Audit::MethodLogger.new('FileUtils', FileUtils, Gitlab::FileAccessJsonLogger)
-# #IO = Gitlab::Audit::MethodLogger.new('IO', IO, Gitlab::FileAccessJsonLogger)
-# File = Gitlab::Audit::MethodLogger.new('File', File, Gitlab::FileAccessJsonLogger)
-
-# Gitlab::Audit::LogMethodCalls.stub(
-#   FileUtils,
-#   Gitlab::FileAccessJsonLogger
-# )
-
-Gitlab::Audit::MethodLogger.stub!(FileUtils, Gitlab::FileAccessJsonLogger,
+Gitlab::Audit::MethodLogger.stub!(
+  FileUtils,
+  Gitlab::FileAccessJsonLogger,
+  unique_key: 'file_access_logger',
   base_object: Module)
 
-# Gitlab::Audit::MethodLogger.stub!(IO, Gitlab::FileAccessJsonLogger,
-#   except_singleton_methods: [],
-#   instance_methods: nil)
-  
-# Gitlab::Audit::MethodLogger.stub!(File, Gitlab::FileAccessJsonLogger,
-#   except_singleton_methods: %i[new expand_path basename join dirname extname exist? file? readable? writable? realpath directory? mtime stat absolute_path],
-#   instance_methods: [])
+Gitlab::Audit::MethodLogger.stub!(File, Gitlab::FileAccessJsonLogger,
+  unique_key: 'file_access_logger',
+  base_object: Object,
+  singleton_methods: %i[new open chmod chown delete lchmod lchown link readlink rename size truncate unlink utime],
+  instance_methods: %i[])
 
+Gitlab::Audit::MethodLogger.stub!(IO, Gitlab::FileAccessJsonLogger,
+  unique_key: 'file_access_logger',
+  base_object: Object,
+  singleton_methods: %i[open binread binwrite copy_stream for_fd foreach popen read readlines sysopen write],
+  instance_methods: %i[])
diff --git a/lib/gitlab/audit/method_logger.rb b/lib/gitlab/audit/method_logger.rb
index bfd625244bb..8cd042ca5a6 100644
--- a/lib/gitlab/audit/method_logger.rb
+++ b/lib/gitlab/audit/method_logger.rb
@@ -1,25 +1,29 @@
 module Gitlab
   module Audit
     class MethodLogger
-      attr_reader :object, :object_name, :logger, :singleton_methods, :instance_methods
+      attr_reader :object, :name, :unique_key, :logger, :singleton_methods, :instance_methods
 
       def self.stub!(object, logger, base_object: Object,
+          unique_key: nil,
           singleton_methods: nil, except_singleton_methods: [],
           instance_methods: nil, except_instance_methods: [])
 
         singleton_methods ||= object.singleton_methods(false) - base_object.singleton_methods(false)
         instance_methods ||= object.methods(false) - base_object.methods(false)
+        unique_key ||= object.to_s
 
         new(
           object, logger,
+          unique_key: unique_key,
           singleton_methods: singleton_methods - except_singleton_methods,
           instance_methods: instance_methods - except_instance_methods,
-        ).stub!
+        ).tap(&:stub!)
       end
 
-      def initialize(object, logger, singleton_methods:, instance_methods:)
+      def initialize(object, logger, unique_key:, singleton_methods:, instance_methods:)
         @object = object
-        @object_name = object.to_s
+        @name = object.to_s
+        @unique_key = unique_key
         @logger = logger
         @singleton_methods = singleton_methods
         @instance_methods = instance_methods
@@ -35,36 +39,54 @@ module Gitlab
         end
       end
 
+      private
+
       def stub_method!(method_type, method)
-        old_method = object.send(method_type, method)
-        method_logger = self
+        log_method = method(:log)
+
+        old_method = find_method!(object, method_type, method)
+        unbound_method = old_method.unbind
+        bound_method = unbound_method.bind(object)
 
         object.send("define_" + method_type, method) do |*args, &block|
-          nested = method_logger.object_value_add(1)
+          log_method.call(method_type, method, args) do
+            bound_method.call(*args, &block)
+          end
+        end
+      end
 
-          begin
-            if nested == 1
-              method_logger.logger.info(
-                class: method_logger.object.to_s,
-                method_type: method_type,
-                method: method,
-                args: args.map(&:to_s))
-            end
+      def find_method!(object, method_type, method)
+        object.send(method_type, method)
+      rescue NameError
+        find_method!(object.superclass, method_type, method)
+      end
 
-            old_method.call(*args, &block)
-          ensure
-            method_logger.object_value_add(-1)
+      def log(method_type, method, args, &blk)
+        in_lock do |first|
+          if first
+            @logger.info(
+              class: name,
+              method_type: method_type,
+              method: method,
+              args: args.map(&:to_s))
           end
+
+          yield
         end
       end
 
-      def object_value_add(value)
-        Thread.current["#{object_key}"] ||= 0
-        Thread.current["#{object_key}"] += value
+      def in_lock(&blk)
+        Thread.current[key] ||= 0
+        Thread.current[key] += 1
+        begin
+          yield(Thread.current[key] == 1)
+        ensure
+          Thread.current[key] -= 1
+        end
       end
 
-      def object_key
-        "method_logger:#{object_name}"
+      def key
+        "method_logger:#{unique_key}"
       end
     end
   end
diff --git a/lib/gitlab/file_access_json_logger.rb b/lib/gitlab/file_access_json_logger.rb
index a92a2b41260..84b0fa5c65e 100644
--- a/lib/gitlab/file_access_json_logger.rb
+++ b/lib/gitlab/file_access_json_logger.rb
@@ -5,5 +5,10 @@ module Gitlab
     def self.file_name_noext
       'file_access_json'
     end
+
+    def additional_message_data
+      super.merge(
+        cwd: Dir.pwd)
+    end
   end
 end
diff --git a/lib/gitlab/json_logger.rb b/lib/gitlab/json_logger.rb
index 91cc7821df1..466a4e80daf 100644
--- a/lib/gitlab/json_logger.rb
+++ b/lib/gitlab/json_logger.rb
@@ -21,6 +21,10 @@ module Gitlab
       Thread.current[:correlation_id]&.last
     end
 
+    def additional_message_data
+      {}
+    end
+
     def format_message(severity, timestamp, progname, message)
       data = {}
       data[:severity] = severity
@@ -34,6 +38,8 @@ module Gitlab
         data.merge!(message)
       end
 
+      data.merge!(additional_message_data)
+
       data.to_json + "\n"
     end
   end
diff --git a/lib/gitlab/middleware/correlation_id.rb b/lib/gitlab/middleware/correlation_id.rb
index 51e2a51ac1b..2020aa75a7d 100644
--- a/lib/gitlab/middleware/correlation_id.rb
+++ b/lib/gitlab/middleware/correlation_id.rb
@@ -5,22 +5,22 @@ module Gitlab
     class CorrelationId
       include ActionView::Helpers::TagHelper
 
-      CORRELATION_HEADER = 'HTTP_CORRELATION_ID'
+      HTTP_X_REQUEST_ID = 'HTTP_X_REQUEST_ID'
 
       def initialize(app)
         @app = app
       end
 
       def call(env)
-        Gitlab::JsonLogger.use_correlation_id(correlation_id) do
+        Gitlab::JsonLogger.use_correlation_id(correlation_id(env)) do
           @app.call(env)
         end
       end
 
       private
 
-      def correlation_id
-        env[CORRELATION_HEADER] || SecureRandom.hex
+      def correlation_id(env)
+        env[HTTP_X_REQUEST_ID] || SecureRandom.hex
       end
     end
   end