Add optimistic pausing to avoid stale reads

Instead of writer pinning, we'll track the last transaction ID of each
write in the session. Then on each read we'll wait for the replica to
report that this transaction is available.

If it doesn't become available within a reasonable timeout, we'll
proceed anyway, and accept the possibility of a stale read.

The hope here is that most of the time, the replica is caught up in the
time between a write request and the following read request. If it's
not, we now have a little tolerance to wait for it, which hopefully
proves enough to stale reads are not encountered in normal use.

We also disable the writer affinity opt-out mechanism that we had
before, since we will no longer be using writer affinity at the load
balancer.

app/controllers/application_controller.rb

@@ -4,7 +4,7 @@ class ApplicationController < ActionController::Base
   include CurrentRequest, CurrentTimezone, SetPlatform
   include TurboFlash, ViewTransitions
   include Saas
-  include RoutingHeaders, WriterAffinity
+  include RoutingHeaders
 
   etag { "v1" }
   stale_when_importmap_changes

app/controllers/cards/readings_controller.rb

@@ -1,8 +1,6 @@
 class Cards::ReadingsController < ApplicationController
   include CardScoped
 
-  skip_writer_affinity
-
   def create
     @notifications = @card.read_by(Current.user)
     record_board_access

app/controllers/concerns/writer_affinity.rb

@@ -1,14 +0,0 @@
-module WriterAffinity
-  extend ActiveSupport::Concern
-
-  class_methods do
-    def skip_writer_affinity(**)
-      before_action :set_writer_affinity_opt_out_header, **
-    end
-  end
-
-  private
-    def set_writer_affinity_opt_out_header
-      response.headers["X-Writer-Affinity"] = "false"
-    end
-end

config/initializers/multi_db.rb

@@ -1,7 +1,7 @@
 require "deployment"
 
 Rails.application.configure do
-  config.active_record.database_selector = { delay: 1.second }
+  config.active_record.database_selector = { delay: 0.seconds }
   config.active_record.database_resolver = Deployment::DatabaseResolver
   config.active_record.database_resolver_context = ActiveRecord::Middleware::DatabaseSelector::Resolver::Session
 end

gems/fizzy-saas/lib/fizzy/saas/engine.rb

@@ -1,9 +1,19 @@
+require_relative "metrics"
+require_relative "transaction_pinning"
+
 module Fizzy
   module Saas
     class Engine < ::Rails::Engine
       # moved from config/initializers/queenbee.rb
       Queenbee.host_app = Fizzy
 
+      initializer "fizzy_saas.transaction_pinning" do |app|
+        app.config.middleware.insert_after(
+          ActiveRecord::Middleware::DatabaseSelector,
+          TransactionPinning::Middleware
+        )
+      end
+
       config.to_prepare do
         Queenbee::Subscription.short_names = Subscription::SHORT_NAMES
         Queenbee::ApiToken.token = Rails.application.credentials.dig(:queenbee_api_token)

gems/fizzy-saas/lib/fizzy/saas/metrics.rb

@@ -0,0 +1,13 @@
+Yabeda.configure do
+  SHORT_HISTOGRAM_BUCKETS = [ 0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5 ]
+
+  group :fizzy do
+    counter :replica_stale,
+      comment: "Number of requests served from a stale replica"
+
+    histogram :replica_wait,
+      unit: :seconds,
+      comment: "Time spent waiting for replica to catch up with transaction",
+      buckets: SHORT_HISTOGRAM_BUCKETS
+  end
+end

gems/fizzy-saas/lib/fizzy/saas/transaction_pinning.rb

@@ -0,0 +1,65 @@
+module TransactionPinning
+  class Middleware
+    SESSION_KEY = :last_txn
+    DEFAULT_MAX_WAIT = 0.25
+
+    def initialize(app)
+      @app = app
+      @timeout = Rails.application.config.x.transaction_pinning&.timeout&.to_f || DEFAULT_MAX_WAIT
+    end
+
+    def call(env)
+      request = ActionDispatch::Request.new(env)
+      replica_metrics = {}
+
+      if ApplicationRecord.current_role == :reading
+        wait_for_replica_catchup(request, replica_metrics)
+      end
+
+      status, headers, body = @app.call(env)
+      headers.merge!(replica_metrics.transform_values(&:to_s))
+
+      if ApplicationRecord.current_role == :writing
+        capture_transaction_id(request)
+      end
+
+      [ status, headers, body ]
+    end
+
+    private
+      def wait_for_replica_catchup(request, replica_metrics)
+        if last_txn = request.session[SESSION_KEY].presence
+          has_transaction = tracking_replica_wait_time(replica_metrics) do
+            replica_has_transaction(last_txn)
+          end
+
+          unless has_transaction
+            Yabeda.fizzy.replica_stale.increment
+            replica_metrics["X-Replica-Stale"] = true
+          end
+        end
+      end
+
+      def capture_transaction_id(request)
+        request.session[SESSION_KEY] = ApplicationRecord.connection.show_variable("global.gtid_executed")
+      end
+
+      def replica_has_transaction(txn)
+        sql = ApplicationRecord.sanitize_sql_array([ "SELECT WAIT_FOR_EXECUTED_GTID_SET(?, ?)", txn, @timeout ])
+        ApplicationRecord.connection.select_value(sql) == 0
+      rescue => e
+        Sentry.capture_exception(e, extra: { gtid: txn })
+        true # Treat as if we're up to date, since we don't know
+      end
+
+      def tracking_replica_wait_time(replica_metrics)
+        started_at = Time.current
+
+        Yabeda.fizzy.replica_wait.measure do
+          yield
+        end.tap do
+          replica_metrics["X-Replica-Wait"] = Time.current - started_at
+        end
+      end
+  end
+end

script/configure-lb-production.sh

@@ -10,7 +10,7 @@ ssh app@fizzy-lb-101.df-iad-int.37signals.com \
       --force \
       --tls \
       --host=app.fizzy.do \
-      --writer-affinity-timeout=1s \
+      --writer-affinity-timeout=0 \
       --tls-acme-cache-path=/certificates \
       --target=fizzy-app-101.df-iad-int.37signals.com \
       --target=fizzy-app-102.df-iad-int.37signals.com
@@ -24,7 +24,7 @@ ssh app@fizzy-lb-01.sc-chi-int.37signals.com \
       --force \
       --tls \
       --host=app.fizzy.do \
-      --writer-affinity-timeout=1s \
+      --writer-affinity-timeout=0 \
       --tls-acme-cache-path=/certificates \
       --target=fizzy-app-101.df-iad-int.37signals.com \
       --target=fizzy-app-102.df-iad-int.37signals.com \
@@ -40,7 +40,7 @@ ssh app@fizzy-lb-401.df-ams-int.37signals.com \
       --force \
       --tls \
       --host=app.fizzy.do \
-      --writer-affinity-timeout=1s \
+      --writer-affinity-timeout=0 \
       --tls-acme-cache-path=/certificates \
       --target=fizzy-app-101.df-iad-int.37signals.com \
       --target=fizzy-app-102.df-iad-int.37signals.com \

script/configure-lb-staging.sh

@@ -10,7 +10,7 @@ ssh app@fizzy-staging-lb-01.sc-chi-int.37signals.com \
       --force \
       --tls \
       --host=fizzy.37signals-staging.com \
-      --writer-affinity-timeout=1s \
+      --writer-affinity-timeout=0 \
       --tls-acme-cache-path=/certificates \
       --target=fizzy-staging-app-101.df-iad-int.37signals.com \
       --target=fizzy-staging-app-102.df-iad-int.37signals.com \
@@ -25,7 +25,7 @@ ssh app@fizzy-staging-lb-101.df-iad-int.37signals.com \
       --force \
       --tls \
       --host=fizzy.37signals-staging.com \
-      --writer-affinity-timeout=1s \
+      --writer-affinity-timeout=0 \
       --tls-acme-cache-path=/certificates \
       --target=fizzy-staging-app-101.df-iad-int.37signals.com \
       --target=fizzy-staging-app-102.df-iad-int.37signals.com
@@ -38,7 +38,7 @@ ssh app@fizzy-staging-lb-401.df-ams-int.37signals.com \
       --force \
       --tls \
       --host=fizzy.37signals-staging.com \
-      --writer-affinity-timeout=1s \
+      --writer-affinity-timeout=0 \
       --tls-acme-cache-path=/certificates \
       --target=fizzy-staging-app-101.df-iad-int.37signals.com \
       --target=fizzy-staging-app-102.df-iad-int.37signals.com \

test/controllers/cards/readings_controller_test.rb

@@ -35,12 +35,6 @@ class Cards::ReadingsControllerTest < ActionDispatch::IntegrationTest
     assert_response :success
   end
 
-  test "create opts-out of writer affinity in the load balancer" do
-    post card_reading_path(cards(:logo)), as: :turbo_stream
-
-    assert_equal "false", response.headers["X-Writer-Affinity"]
-  end
-
   test "destroy" do
     freeze_time