diff --git a/CHANGELOG.md b/CHANGELOG.md index 6b22b15..2df631a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,16 @@ # Changelog +## 0.5.2 - 2026-08-09 + +- Read the database clock once per transaction instead of once per step, and + resolve the SQLite busy wait from configuration instead of querying the + connection for it. A synchronous call now issues 49 database queries instead + of 66, which matters most on PostgreSQL and MySQL where every query is a + network round trip. +- Apply every migration in the benchmark harness. It applied only the initial + migration, so the `state_revision` column added in 0.4.0 was missing, every + message failed at commit, and the synchronous benchmarks timed out. + ## 0.5.1 - 2026-08-07 - Restore the SQLite busy wait that a synchronous invocation suspends for its diff --git a/Gemfile.lock b/Gemfile.lock index 77cc4ad..d54a357 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -1,7 +1,7 @@ PATH remote: . specs: - solid_objects (0.5.1) + solid_objects (0.5.2) actioncable (>= 8.0) actionpack (>= 8.0) actionview (>= 8.0) @@ -373,7 +373,7 @@ CHECKSUMS rubocop-rails-omakase (1.1.0) sha256=2af73ac8ee5852de2919abbd2618af9c15c19b512c4cfc1f9a5d3b6ef009109d ruby-progressbar (1.13.0) sha256=80fc9c47a9b640d6834e0dc7b3c94c9df37f08cb072b7761e4a71e22cff29b33 securerandom (0.4.1) sha256=cc5193d414a4341b6e225f0cb4446aceca8e50d5e1888743fac16987638ea0b1 - solid_objects (0.5.1) + solid_objects (0.5.2) sqlite3 (2.9.5-aarch64-linux-gnu) sha256=78075b6337d3d182c6d2b4691049ed45cd220826160c9ea18946bf6a1de200dc sqlite3 (2.9.5-aarch64-linux-musl) sha256=18c801185deb4adc01ddb281e8f672a39e3d1729979ca91e39439cd3eac0402d sqlite3 (2.9.5-arm-linux-gnu) sha256=1bdfca0c7d63998c60b0f4a8e3c8df2d33800ccc4abd2d612eddbbbc92a4c48b diff --git a/benchmark/support.rb b/benchmark/support.rb index fd536b3..cbdc0b9 100644 --- a/benchmark/support.rb +++ b/benchmark/support.rb @@ -228,7 +228,9 @@ def establish_connection # @rbs () -> void def migrate require_relative "../db/migrate/20260805000000_create_solid_objects_tables" + require_relative "../db/migrate/20260806000000_add_state_revision_to_solid_objects_instances" CreateSolidObjectsTables.new.migrate(:up) + AddStateRevisionToSolidObjectsInstances.new.migrate(:up) end # @rbs () -> void diff --git a/docs/benchmarks.md b/docs/benchmarks.md index f6411fe..0f04306 100644 --- a/docs/benchmarks.md +++ b/docs/benchmarks.md @@ -41,6 +41,13 @@ scenario used four worker threads. | Synchronous latency | p50 1.8 ms, p95 25.6 ms, p99 156.2 ms | | Activation reuse | 98.0%, four activations for 200 messages | | Queries for one message turn | 29 | +| Queries for one synchronous call | 49 | + +A synchronous call costs far more queries than a worker turn because the caller +also registers or heartbeats its caller process, claims the activation, and +observes the result. Query count, not query time, dominates synchronous latency +on a networked database: measured locally against SQLite, database time is +roughly 5% of a call and the remaining 95% is Ruby. The difference between the SQLite development result and the MySQL adoption result is why Solid Objects does not publish one latency promise. Network diff --git a/lib/solid_objects/database_adapter.rb b/lib/solid_objects/database_adapter.rb index 09e1b79..b8a9f73 100644 --- a/lib/solid_objects/database_adapter.rb +++ b/lib/solid_objects/database_adapter.rb @@ -4,6 +4,9 @@ module SolidObjects class DatabaseAdapter + TRANSACTION_CLOCK = :solid_objects_transaction_clock + TRANSACTION_CLOCK_SCOPE = :solid_objects_transaction_clock_scope + class << self # @rbs (untyped) -> DatabaseAdapter def for(connection) @@ -46,10 +49,9 @@ def current_time_expression # @rbs () -> Time def database_now - value = with_connection do |connection| - connection.select_value("SELECT #{current_time_expression}") - end - value.is_a?(Time) ? value.utc : Time.parse("#{value} UTC").utc + return read_database_now unless ActiveSupport::IsolatedExecutionState[TRANSACTION_CLOCK_SCOPE] + + ActiveSupport::IsolatedExecutionState[TRANSACTION_CLOCK] ||= read_database_now end # @rbs () { () -> untyped } -> untyped @@ -70,7 +72,7 @@ def transaction(&block) with_transaction_deadline(connection) do connection.transaction(requires_new: true) do configure_transaction_deadline(connection) - block.call + with_transaction_clock { block.call } end end end @@ -91,6 +93,27 @@ def lock_candidates(relation) attr_reader :connection_pool, :fixed_connection + # @rbs () { () -> untyped } -> untyped + def with_transaction_clock + return yield if ActiveSupport::IsolatedExecutionState[TRANSACTION_CLOCK_SCOPE] + + ActiveSupport::IsolatedExecutionState[TRANSACTION_CLOCK_SCOPE] = true + begin + yield + ensure + ActiveSupport::IsolatedExecutionState[TRANSACTION_CLOCK_SCOPE] = false + ActiveSupport::IsolatedExecutionState[TRANSACTION_CLOCK] = nil + end + end + + # @rbs () -> Time + def read_database_now + value = with_connection do |connection| + connection.select_value("SELECT #{current_time_expression}") + end + value.is_a?(Time) ? value.utc : Time.parse("#{value} UTC").utc + end + # @rbs (untyped) { () -> untyped } -> untyped def with_transaction_deadline(_connection) yield diff --git a/lib/solid_objects/database_adapters/sqlite.rb b/lib/solid_objects/database_adapters/sqlite.rb index 01e9bfe..7bff5bf 100644 --- a/lib/solid_objects/database_adapters/sqlite.rb +++ b/lib/solid_objects/database_adapters/sqlite.rb @@ -80,13 +80,13 @@ def with_transaction_deadline(connection) # @rbs (untyped) -> Hash[Symbol, untyped]? def restorable_busy_wait(connection) - pragma_timeout = connection.select_value("PRAGMA busy_timeout").to_i - return { pragma_timeout: } if pragma_timeout.positive? - handler_timeout = configured_busy_handler_timeout(connection) - return nil unless handler_timeout + return { handler_timeout: } if handler_timeout + + pragma_timeout = connection.select_value("PRAGMA busy_timeout").to_i + return nil unless pragma_timeout.positive? - { pragma_timeout:, handler_timeout: } + { pragma_timeout: } end # @rbs (untyped, Hash[Symbol, untyped]) -> void diff --git a/lib/solid_objects/version.rb b/lib/solid_objects/version.rb index 4e07a1e..c74c6b0 100644 --- a/lib/solid_objects/version.rb +++ b/lib/solid_objects/version.rb @@ -1,5 +1,5 @@ # rbs_inline: enabled module SolidObjects - VERSION = "0.5.1" + VERSION = "0.5.2" end diff --git a/sig/generated/lib/solid_objects/database_adapter.rbs b/sig/generated/lib/solid_objects/database_adapter.rbs index 103df0e..bd9909c 100644 --- a/sig/generated/lib/solid_objects/database_adapter.rbs +++ b/sig/generated/lib/solid_objects/database_adapter.rbs @@ -2,6 +2,10 @@ module SolidObjects class DatabaseAdapter + TRANSACTION_CLOCK: ::Symbol + + TRANSACTION_CLOCK_SCOPE: ::Symbol + # @rbs (untyped) -> DatabaseAdapter def self.for: (untyped) -> DatabaseAdapter @@ -42,6 +46,12 @@ module SolidObjects attr_reader fixed_connection: untyped + # @rbs () { () -> untyped } -> untyped + def with_transaction_clock: () { () -> untyped } -> untyped + + # @rbs () -> Time + def read_database_now: () -> Time + # @rbs (untyped) { () -> untyped } -> untyped def with_transaction_deadline: (untyped) { () -> untyped } -> untyped diff --git a/test/integration/synchronous_invocation_test.rb b/test/integration/synchronous_invocation_test.rb index 4031162..ec10994 100644 --- a/test/integration/synchronous_invocation_test.rb +++ b/test/integration/synchronous_invocation_test.rb @@ -502,6 +502,56 @@ def wait(timeout:) release_sqlite_write_lock(lock) if lock end + test "sync does not re-read the SQLite busy wait it already knows how to restore" do + skip unless SolidObjects::Record.connection.adapter_name.match?(/sqlite/i) + CounterActor.ref("pragma-warm").increment + statements = [] + subscription = ActiveSupport::Notifications.subscribe("sql.active_record") do |event| + statements << event.payload[:sql] + end + + CounterActor.ref("pragma-warm").increment + + ActiveSupport::Notifications.unsubscribe(subscription) + assert_empty statements.grep(/\APRAGMA busy_timeout\z/i), + "the configured busy wait is known without asking the database for it" + refute_empty statements.grep(/\APRAGMA busy_timeout = 0\z/i), + "the busy wait must still be suspended for the deadline" + end + + test "a transaction reads the database clock once and shares the reading" do + readings = [] + clock_reads = count_clock_reads do + SolidObjects.database_adapter.transaction do + 3.times { readings << SolidObjects.database_adapter.database_now } + end + end + + assert_equal 1, clock_reads + assert_equal 1, readings.uniq.length + end + + test "the shared clock reading does not outlive its transaction" do + reads = count_clock_reads do + 2.times do + SolidObjects.database_adapter.transaction { SolidObjects.database_adapter.database_now } + end + end + + assert_equal 2, reads + assert_equal 1, count_clock_reads { SolidObjects.database_adapter.database_now } + end + + test "sync stops re-reading the database clock for every step" do + reference = CounterActor.ref("clock-warm") + reference.increment + + clock_reads = count_clock_reads { reference.increment } + + assert_operator clock_reads, :<=, 4, + "a synchronous call should read the clock once per transaction, not once per step" + end + test "sync discovers the configured SQLite busy wait it has to restore" do skip unless SolidObjects::Record.connection.adapter_name.match?(/sqlite/i) @@ -853,6 +903,17 @@ def invoke_with_immediate_sqlite_lock_failure(message_reference) captured end + def count_clock_reads + reads = 0 + subscription = ActiveSupport::Notifications.subscribe("sql.active_record") do |event| + reads += 1 if event.payload[:sql].match?(/STRFTIME|CURRENT_TIMESTAMP/i) + end + yield + reads + ensure + ActiveSupport::Notifications.unsubscribe(subscription) if subscription + end + def process_write?(payload) payload.fetch(:sql).match?(/\A(?:INSERT|UPDATE)/) && payload.fetch(:sql).include?(SolidObjects::Process.table_name)