Adds metrics to measure database transactionstransaction-metrics

Currently we don't have good insight into the affect of Rails
transaction blocks on the application. If these blocks are held open for
extended periods, they can have detrimental effects on the application.

This change will allow us to track these transactions, with the aim
of reducing their duration.

4 files changed, 42 insertions, 0 deletions

diff --git a/changelogs/unreleased/transaction-metrics.yml b/changelogs/unreleased/transaction-metrics.yml
new file mode 100644
index 00000000000..8b6e9c7d9d1
--- /dev/null
+++ b/changelogs/unreleased/transaction-metrics.yml
@@ -0,0 +1,5 @@
+---
+title: Adds metrics to measure cost of expensive operations
+merge_request: 29928
+author:
+type: other
diff --git a/config/initializers/transaction_metrics.rb b/config/initializers/transaction_metrics.rb
new file mode 100644
index 00000000000..0175d487e66
--- /dev/null
+++ b/config/initializers/transaction_metrics.rb
@@ -0,0 +1,3 @@
+# frozen_string_literal: true
+
+Gitlab::Database.install_monkey_patches
diff --git a/lib/gitlab/database.rb b/lib/gitlab/database.rb
index e4d4779ba9a..62567be5258 100644
--- a/lib/gitlab/database.rb
+++ b/lib/gitlab/database.rb
@@ -2,6 +2,8 @@
 
 module Gitlab
   module Database
+    include Gitlab::Metrics::Methods
+
     # The max value of INTEGER type is the same between MySQL and PostgreSQL:
     # https://www.postgresql.org/docs/9.2/static/datatype-numeric.html
     # http://dev.mysql.com/doc/refman/5.7/en/integer-types.html
@@ -11,6 +13,10 @@ module Gitlab
     # https://dev.mysql.com/doc/refman/5.7/en/datetime.html
     MAX_TIMESTAMP_VALUE = Time.at((1 << 31) - 1).freeze
 
+    define_histogram :gitlab_database_transaction_seconds do
+      docstring "Time spent in database transactions, in seconds"
+    end
+
     def self.config
       ActiveRecord::Base.configurations[Rails.env]
     end
@@ -286,5 +292,32 @@ module Gitlab
       0
     end
     private_class_method :open_transactions_baseline
+
+    # Monkeypatch rails with upgraded database observability
+    def self.install_monkey_patches
+      ActiveRecord::Base.prepend(ActiveRecordBaseTransactionMetrics)
+    end
+
+    # observe_transaction_duration is called from ActiveRecordBaseTransactionMetrics.transaction and used to
+    # record transaction durations.
+    def self.observe_transaction_duration(duration_seconds)
+      labels = Gitlab::Metrics::Transaction.current&.labels || {}
+      gitlab_database_transaction_seconds.observe(labels, duration_seconds)
+    rescue Prometheus::Client::LabelSetValidator::LabelSetError => err
+      # Ensure that errors in recording these metrics don't affect the operation of the application
+      Rails.logger.error("Unable to observe database transaction duration: #{err}")
+    end
+
+    # MonkeyPatch for ActiveRecord::Base for adding observability
+    module ActiveRecordBaseTransactionMetrics
+      # A monkeypatch over ActiveRecord::Base.transaction.
+      # It provides observability into transactional methods.
+      def transaction(options = {}, &block)
+        start_time = Gitlab::Metrics::System.monotonic_time
+        super(options, &block)
+      ensure
+        Gitlab::Database.observe_transaction_duration(Gitlab::Metrics::System.monotonic_time - start_time)
+      end
+    end
   end
 end
diff --git a/lib/gitlab/optimistic_locking.rb b/lib/gitlab/optimistic_locking.rb
index 868b2ae641a..0c0f46d3b77 100644
--- a/lib/gitlab/optimistic_locking.rb
+++ b/lib/gitlab/optimistic_locking.rb
@@ -5,6 +5,7 @@ module Gitlab
     module_function
 
     def retry_lock(subject, retries = 100, &block)
+      # TODO(Observability): We should be recording details of the number of retries and the duration of the total execution here
       ActiveRecord::Base.transaction do
         yield(subject)
       end