Exploring ActiveSupport.on_load

CryptKepper is ruby plugin I wrote to provide transparent ActiveRecord encryption. The first release supported PostreSQL pgpcrypto which used native SQL functions to perform the encryption and decryption of data. Since we’re using SQL to encrypt data, that means queries are being logged in plaintext. This is clearly not something you want:


irb(main)> ActiveRecord::Base.connection.execute("SELECT pgp_sym_encrypt('data', 'key')")
(1.8ms) SELECT pgp_sym_encrypt('data', 'key')

In order to scrub that from the log, all you need to do is attach an ActiveRecord::LogSubscriber. A LogSubscriber receives the payload of a log message and allowed you to manipulate the text before it’s stored. Here is the PostreSQL version I came up with:

require 'active_support/concern'
require 'active_support/lazy_load_hooks'

module CryptKeeper
  module LogSubscriber
    module PostgresPgp
      extend ActiveSupport::Concern

      included do
        alias_method_chain :sql, :postgres_pgp
      end

      # Public: Prevents sensitive data from being logged
      def sql_with_postgres_pgp(event)
        filter = /(pgp_sym_(encrypt|decrypt))\(((.|\n)*?)\)/i

        event.payload[:sql] = event.payload[:sql].gsub(filter) do |_|
          "#{$1}([FILTERED])"
        end

        sql_without_postgres_pgp(event)
      end
    end
  end
end

ActiveSupport.on_load :active_record do
  ActiveRecord::LogSubscriber.send :include, CryptKeeper::LogSubscriber::PostgresPgp
end

This redefines the `sql` method on ActiveRecord::Logsubscriber and performs a regex to replace sensitive data with [FILTERED]. This is achieved by using ActiveSupport.on_load to inject code when ActiveRecord is loaded. Perfect! Here is the new output:

irb(main)> ActiveRecord::Base.connection.execute("SELECT pgp_sym_encrypt('data', 'key')")

(0.3ms) SELECT pgp_sym_encrypt([FILTERED])

As time went on,  more encryptors and LogSubscribers were added. The problem was that since I was using ActiveSupport.on_load(:active_record), that meant all LogSubscribers were being injected even if you were only using one type of encryption. This didn’t cause any issues but running filters needlessly on queries isn’t something I wanted.

After exploring a few options I settled on ActiveSupport.on_load. The documentation for on_load isn’t great. The notion of load is not well defined. Digging into the code showed that what it’s really doing is firing hooks.

A hook is defined with ActiveSupport.on_load. That hook is then called, later, using run_load_hooks. The first argument to run_load_hooks is the name of the hook, the second is the object defining the hook. Here is an example. The first class creates the log subscriber and defines a hook named crypt_keeper_posgres_pgp_log. The code inside the on_load block is not run until it’s called with run_load_hooks.

require 'active_support/concern'
require 'active_support/lazy_load_hooks'

module CryptKeeper
  module LogSubscriber
    module PostgresPgp
      extend ActiveSupport::Concern

      included do
        alias_method_chain :sql, :postgres_pgp
      end

      # Public: Prevents sensitive data from being logged
      def sql_with_postgres_pgp(event)
        filter = /(pgp_sym_(encrypt|decrypt))\(((.|\n)*?)\)/i

        event.payload[:sql] = event.payload[:sql].gsub(filter) do |_|
          "#{$1}([FILTERED])"
        end

        sql_without_postgres_pgp(event)
      end
    end
  end
end

ActiveSupport.on_load :crypt_keeper_posgres_pgp_log do
  ActiveRecord::LogSubscriber.send :include, CryptKeeper::LogSubscriber::PostgresPgp
end

Next we create a class that calls the hook on initialize:


require 'crypt_keeper/log_subscriber/mysql_aes'

module CryptKeeper
  module Provider
    class MysqlAes
      include CryptKeeper::Helper::SQL

      attr_accessor :key

      # Public: Initializes the encryptor
      #
      #  options - A hash, :key is required
      def initialize(options = {})
        ActiveSupport.run_load_hooks(:crypt_keeper_mysql_aes_log, self)

        @key = options.fetch(:key) do
          raise ArgumentError, "Missing :key"
        end
      end

      # Public: Encrypts a string
      #
      # Returns an encrypted string
      def encrypt(value)
        Base64.encode64 escape_and_execute_sql(
          ["SELECT AES_ENCRYPT(?, ?)", value, key]).first
      end

      # Public: Decrypts a string
      #
      # Returns a plaintext string
      def decrypt(value)
        escape_and_execute_sql(
          ["SELECT AES_DECRYPT(?, ?)", Base64.decode64(value), key]).first
      end
    end
  end
end

This small change gave me the behavior I wanted; LogSubscribers are not installed until an encryptor requests it.