feat: support Query Logs

Rails 7.0 introduced support for Query Logs. These automatically append
comments to all SQL statements that are executed, so it is easier to
find queries that perform badly. Cloud Spanner does not include comments
from the SQL string in the query statistics, meaning that in order for
these comments to be useful, they need to be translated to request tags.

This change modifies the query execution path so the query transformer
that is used by Query Logs is called by the Cloud Spanner provider. The
comments that are added can then be translated to request tags. The
latter requires that Query Logs is configured with two specific options:
1. `ActiveRecord::QueryLogs.prepend_comment = true`
2. The first tag must be `{ request_tag:  "true" }`

See the included sample application for a full working sample.

Fixes #285

examples/snippets/query-logs/README.md

@@ -0,0 +1,43 @@
+# Sample - Query Logs
+
+__NOTE__: Query logs require additional configuration for Cloud Spanner. Please read the entire file.
+
+Rails 7.0 and higher supports [Query Logs](https://api.rubyonrails.org/classes/ActiveRecord/QueryLogs.html). Query Logs
+can be used to automatically annotate all queries that are executed based on the current execution context.
+
+The Cloud Spanner ActiveRecord provider can be used in combination with Query Logs. The query logs are automatically
+translated to request tags for the queries.
+See https://cloud.google.com/spanner/docs/introspection/troubleshooting-with-tags for more 
+information about request and transaction tags in Cloud Spanner.
+
+## Configuration
+Using Query Logs with Cloud Spanner requires some specific configuration:
+1. You must set `ActiveRecord::QueryLogs.prepend_comment = true`
+2. You must include `{ request_tag:  "true" }` as the first tag in your configuration.
+
+```ruby
+ActiveRecord::QueryLogs.prepend_comment = true
+config.active_record.query_log_tags = [
+  {
+    request_tag:  "true",
+  },
+  :namespaced_controller,
+  :action,
+  :job,
+  {
+    request_id: ->(context) { context[:controller]&.request&.request_id },
+    job_id: ->(context) { context[:job]&.job_id },
+    tenant_id: -> { Current.tenant&.id },
+    static: "value",
+  },
+]
+```
+
+The sample will automatically start a Spanner Emulator in a docker container and execute the sample
+against that emulator. The emulator will automatically be stopped when the application finishes.
+
+Run the application with the command
+
+```bash
+bundle exec rake run
+```

examples/snippets/query-logs/Rakefile

@@ -0,0 +1,13 @@
+# Copyright 2023 Google LLC
+#
+# Use of this source code is governed by an MIT-style
+# license that can be found in the LICENSE file or at
+# https://opensource.org/licenses/MIT.
+
+require_relative "../config/environment"
+require "sinatra/activerecord/rake"
+
+desc "Sample showing how to use automatic query log tagging on Cloud Spanner with ActiveRecord."
+task :run do
+  Dir.chdir("..") { sh "bundle exec rake run[query-logs]" }
+end

examples/snippets/query-logs/application.rb

@@ -0,0 +1,63 @@
+# Copyright 2023 Google LLC
+#
+# Use of this source code is governed by an MIT-style
+# license that can be found in the LICENSE file or at
+# https://opensource.org/licenses/MIT.
+
+require "io/console"
+require_relative "../config/environment"
+require_relative "models/singer"
+require_relative "models/album"
+
+class Application
+  def self.run
+    enable_query_logs
+
+    puts ""
+    puts "Query all Albums and include an automatically generated request tag"
+    albums = Album.all
+    puts "Queried #{albums.length} albums using an automatically generated request tag"
+
+    puts ""
+    puts "Press any key to end the application"
+    STDIN.getch
+  end
+
+  def self.enable_query_logs
+    # Enables Query Logs in a non-Rails application. Normally, this should be done
+    # as described here: https://api.rubyonrails.org/classes/ActiveRecord/QueryLogs.html
+    ActiveRecord.query_transformers << ActiveRecord::QueryLogs
+
+    # Query log comments *MUST* be prepended to be included as a request tag.
+    ActiveRecord::QueryLogs.prepend_comment = true
+
+    # This block manually enables Query Logs without a full Rails application.
+    # This should normally not be needed in your application.
+    ActiveRecord::QueryLogs.taggings.merge!(
+      application:  "example-app",
+      action:       "run-test-application",
+      pid:          -> { Process.pid.to_s },
+      socket:       ->(context) { context[:connection].pool.db_config.socket },
+      db_host:      ->(context) { context[:connection].pool.db_config.host },
+      database:     ->(context) { context[:connection].pool.db_config.database }
+    )
+
+    ActiveRecord::QueryLogs.tags = [
+      # The first tag *MUST* be the fixed value 'request_tag:true'.
+      {
+        request_tag:  "true"
+      },
+      :controller,
+      :action,
+      :job,
+      {
+        request_id: ->(context) { context[:controller]&.request&.request_id },
+        job_id: ->(context) { context[:job]&.job_id }
+      },
+      :db_host,
+      :database
+    ]
+  end
+end
+
+Application.run

examples/snippets/query-logs/config/database.yml

@@ -0,0 +1,8 @@
+development:
+  adapter: spanner
+  emulator_host: localhost:9010
+  project: test-project
+  instance: test-instance
+  database: testdb
+  pool: 5
+  timeout: 5000

examples/snippets/query-logs/db/migrate/01_create_tables.rb

@@ -0,0 +1,21 @@
+# Copyright 2023 Google LLC
+#
+# Use of this source code is governed by an MIT-style
+# license that can be found in the LICENSE file or at
+# https://opensource.org/licenses/MIT.
+
+class CreateTables < ActiveRecord::Migration[6.0]
+  def change
+    connection.ddl_batch do
+      create_table :singers do |t|
+        t.string :first_name
+        t.string :last_name
+      end
+
+      create_table :albums do |t|
+        t.string :title
+        t.references :singer, index: false, foreign_key: true
+      end
+    end
+  end
+end

examples/snippets/query-logs/db/schema.rb

@@ -0,0 +1,31 @@
+# This file is auto-generated from the current state of the database. Instead
+# of editing this file, please use the migrations feature of Active Record to
+# incrementally modify your database, and then regenerate this schema definition.
+#
+# This file is the source Rails uses to define your schema when running `bin/rails
+# db:schema:load`. When creating a new database, `bin/rails db:schema:load` tends to
+# be faster and is potentially less error prone than running all of your
+# migrations from scratch. Old migrations may fail to apply correctly if those
+# migrations use external dependencies or application code.
+#
+# It's strongly recommended that you check this file into your version control system.
+
+ActiveRecord::Schema[7.1].define(version: 1) do
+  connection.start_batch_ddl
+
+  create_table "albums", force: :cascade do |t|
+    t.string "title"
+    t.integer "singer_id", limit: 8
+  end
+
+  create_table "singers", force: :cascade do |t|
+    t.string "first_name"
+    t.string "last_name"
+  end
+
+  add_foreign_key "albums", "singers"
+  connection.run_batch
+rescue
+  abort_batch
+  raise
+end

examples/snippets/query-logs/db/seeds.rb

@@ -0,0 +1,24 @@
+# Copyright 2023 Google LLC
+#
+# Use of this source code is governed by an MIT-style
+# license that can be found in the LICENSE file or at
+# https://opensource.org/licenses/MIT.
+
+require_relative "../../config/environment.rb"
+require_relative "../models/singer"
+require_relative "../models/album"
+
+first_names = ["Pete", "Alice", "John", "Ethel", "Trudy", "Naomi", "Wendy", "Ruben", "Thomas", "Elly"]
+last_names = ["Wendelson", "Allison", "Peterson", "Johnson", "Henderson", "Ericsson", "Aronson", "Tennet", "Courtou"]
+
+adjectives = ["daily", "happy", "blue", "generous", "cooked", "bad", "open"]
+nouns = ["windows", "potatoes", "bank", "street", "tree", "glass", "bottle"]
+
+5.times do
+  Singer.create first_name: first_names.sample, last_name: last_names.sample
+end
+
+20.times do
+  singer_id = Singer.all.sample.id
+  Album.create title: "#{adjectives.sample} #{nouns.sample}", singer_id: singer_id
+end

examples/snippets/query-logs/models/album.rb

@@ -0,0 +1,9 @@
+# Copyright 2023 Google LLC
+#
+# Use of this source code is governed by an MIT-style
+# license that can be found in the LICENSE file or at
+# https://opensource.org/licenses/MIT.
+
+class Album < ActiveRecord::Base
+  belongs_to :singer
+end

examples/snippets/query-logs/models/singer.rb

@@ -0,0 +1,9 @@
+# Copyright 2023 Google LLC
+#
+# Use of this source code is governed by an MIT-style
+# license that can be found in the LICENSE file or at
+# https://opensource.org/licenses/MIT.
+
+class Singer < ActiveRecord::Base
+  has_many :albums
+end

lib/active_record/connection_adapters/spanner/database_statements.rb

@@ -13,6 +13,7 @@ module ConnectionAdapters
     module Spanner
       module DatabaseStatements
         VERSION_7_1_0 = Gem::Version.create "7.1.0"
+        RequestOptions = Google::Cloud::Spanner::V1::RequestOptions
 
         # DDL, DML and DQL Statements
 
@@ -30,6 +31,8 @@ def internal_exec_query sql, name = "SQL", binds = [], prepare: false, async: fa
         def internal_execute sql, name = "SQL", binds = [],
                              prepare: false, async: false # rubocop:disable Lint/UnusedMethodArgument
           statement_type = sql_statement_type sql
+          sql = transform sql
+          append_request_tag_from_query_logs sql, binds
 
           if preventing_writes? && [:dml, :ddl].include?(statement_type)
             raise ActiveRecord::ReadOnlyError(
@@ -40,40 +43,69 @@ def internal_execute sql, name = "SQL", binds = [],
           if statement_type == :ddl
             execute_ddl sql
           else
-            transaction_required = statement_type == :dml
-            materialize_transactions
-
-            # First process and remove any hints in the binds that indicate that
-            # a different read staleness should be used than the default.
-            staleness_hint = binds.find { |b| b.is_a? Arel::Visitors::StalenessHint }
-            if staleness_hint
-              selector = Google::Cloud::Spanner::Session.single_use_transaction staleness_hint.value
-              binds.delete staleness_hint
-            end
-            request_options = binds.find { |b| b.is_a? Google::Cloud::Spanner::V1::RequestOptions }
-            if request_options
-              binds.delete request_options
-            end
+            execute_query_or_dml statement_type, sql, name, binds
+          end
+        end
+
+        def execute_query_or_dml statement_type, sql, name, binds
+          transaction_required = statement_type == :dml
+          materialize_transactions
 
-            log_args = [sql, name]
-            log_args.concat [binds, type_casted_binds(binds)] if log_statement_binds
-
-            log(*log_args) do
-              types, params = to_types_and_params binds
-              ActiveSupport::Dependencies.interlock.permit_concurrent_loads do
-                if transaction_required
-                  transaction do
-                    @connection.execute_query sql, params: params, types: types, request_options: request_options
-                  end
-                else
-                  @connection.execute_query sql, params: params, types: types, single_use_selector: selector,
-                                            request_options: request_options
+          # First process and remove any hints in the binds that indicate that
+          # a different read staleness should be used than the default.
+          staleness_hint = binds.find { |b| b.is_a? Arel::Visitors::StalenessHint }
+          if staleness_hint
+            selector = Google::Cloud::Spanner::Session.single_use_transaction staleness_hint.value
+            binds.delete staleness_hint
+          end
+          request_options = binds.find { |b| b.is_a? Google::Cloud::Spanner::V1::RequestOptions }
+          if request_options
+            binds.delete request_options
+          end
+
+          log_args = [sql, name]
+          log_args.concat [binds, type_casted_binds(binds)] if log_statement_binds
+
+          log(*log_args) do
+            types, params = to_types_and_params binds
+            ActiveSupport::Dependencies.interlock.permit_concurrent_loads do
+              if transaction_required
+                transaction do
+                  @connection.execute_query sql, params: params, types: types, request_options: request_options
                 end
+              else
+                @connection.execute_query sql, params: params, types: types, single_use_selector: selector,
+                                          request_options: request_options
               end
             end
           end
         end
 
+        def append_request_tag_from_query_logs sql, binds
+          legacy_formatter_prefix = "/*request_tag:true,"
+          sql_commenter_prefix = "/*request_tag='true',"
+          if sql.start_with? legacy_formatter_prefix
+            append_request_tag_from_query_logs_with_format sql, binds, legacy_formatter_prefix
+          elsif sql.start_with? sql_commenter_prefix
+            append_request_tag_from_query_logs_with_format sql, binds, sql_commenter_prefix
+          end
+        end
+
+        def append_request_tag_from_query_logs_with_format sql, binds, prefix
+          end_of_comment = sql.index "*/", prefix.length
+          return unless end_of_comment
+
+          request_tag = sql[prefix.length, end_of_comment - prefix.length]
+          options = binds.find { |bind| bind.is_a? RequestOptions } || RequestOptions.new
+          if options.request_tag == ""
+            options.request_tag = request_tag
+          else
+            options.request_tag += "," + request_tag
+          end
+
+          binds.append options
+        end
+
         # The method signatures for executing queries and DML statements changed between Rails 7.0 and 7.1.
 
         if ActiveRecord.gem_version >= VERSION_7_1_0

lib/active_record/connection_adapters/spanner_adapter.rb

@@ -261,6 +261,14 @@ def type_map
         include TypeMapBuilder
       end
 
+      def transform sql
+        if ActiveRecord::VERSION::MAJOR >= 7
+          transform_query sql
+        else
+          sql
+        end
+      end
+
       # Overwrite the standard log method to be able to translate exceptions.
       def log sql, name = "SQL", binds = [], type_casted_binds = [], statement_name = nil, *args
         super