Auditní log změn

audit vzory ActiveRecord concerns

Systém pro správu zákazníků energetické společnosti zpracovává citlivá data: smlouvy, spotřeby, faktury, zálohy. Kdykoli operátor něco změní, musí být jasné co, kdy, kdo a proč. Místo hotové knihovny (jako paper_trail) jsem implementoval vlastní auditní log přesně šitý na míru.

Důvody byly dva.

Zaprvé, hotové knihovny ukládají hodnoty tak jak jsou a cizí klíče zůstávají jako čísla. Jenže záznam distributor_id: 7 → 12 je po čase k ničemu: distributor může být přejmenován nebo smazán. Potřeboval jsem jména resolvovat v době zápisu.

Zadruhé, celý systém se točí kolem zákazníků — každý záznam v historii musí být přiřazen ke konkrétnímu zákazníkovi, aby šlo na jednom místě vidět vše, co se v jeho datech dělo a nebylo třeba hledat historii mezi různými asociovanými objekty, které navíc třeba už ani neexistují. To je doménová logika, kterou generická knihovna neznala.

Datový model

Záznamy jsou uloženy ve dvou tabulkách. LogHeader zastřešuje jednu „operaci" — zachytí čas, uživatele a zákazníka, jehož dat se změna týká. LogItem pak popisuje konkrétní změnu jednoho záznamu.

app/models/log_header.rb, app/models/log_item.rb

# log_headers: user_id, customer_id, note, created_at
# log_items:   log_header_id, loggable_type, loggable_id, loggable_name, op, data (serialized hash)

class LogHeader < ApplicationRecord
  belongs_to :user, optional: true
  belongs_to :customer, optional: true
  has_many :log_items
end

class LogItem < ApplicationRecord
  belongs_to :log_header
  belongs_to :loggable, polymorphic: true, required: false  # musí přijmout i právě smazané záznamy

  serialize :data, Hash
end

loggable je polymorfní odkaz — jeden LogItem může popisovat změnu smlouvy, faktury, zálohy i zákazníka samotného. data je serializovaný hash ve tvaru { "attribute_name" => [stará_hodnota, nová_hodnota] }.

Concern `Loggable`

Každý model, u nějž chceme sledovat změny, přihrne concern Loggable a deklaruje, které atributy logovat:

app/models/customer.rb, app/models/invoice.rb

class Customer < ApplicationRecord
  include Loggable
  log_attributes :all, except: [:created_at, :updated_at, :oms_count]
end

class Invoice < ApplicationRecord
  include Loggable
  log_attributes :all, except: [:customer_id, :created_at, :updated_at, :items, :other]
end

Zkratka :all zapíše seznam sloupců z column_names v době načtení třídy; :except z něj pak vyřadí zadané atributy.

app/models/concerns/loggable.rb

module Loggable
  extend ActiveSupport::Concern

  included do
    class_attribute :logged_attributes
    class_attribute :logged_options

    self.logged_attributes = []
    self.logged_options = {}
  end

  module ClassMethods
    def log_attributes(*attrs)
      self.logged_options = attrs.extract_options!

      attrs.each do |attr|
        if attr == :all
          self.logged_attributes = column_names
        else
          self.logged_attributes << attr.to_s
        end
      end

      self.logged_attributes = self.logged_attributes - Array.wrap(logged_options[:except]).collect(&:to_s)
    end
  end
end

Callbacky: accumulate & flush

Callbacky neukládají změny do databáze hned. Místo toho přidají záznam do fronty uložené v thread-local proměnné skrze Log.pending a skutečný zápis proběhne až v before_commit, tedy v rámci téže transakce jako samotná změna dat. To umožňuje vícenásobné změny v rámci jedné transakce squashnout.

app/models/concerns/loggable.rb

module Loggable
  extend ActiveSupport::Concern

  included do
    around_create  :log_save
    around_update  :log_save
    around_destroy :log_destruction
    before_commit  :log_save_pending
  end

  def log_save
    if logged_attributes
      changes = self.changes
                    .slice(*logged_attributes)
                    .to_h { |k, v| [k, [log_transform_value(k, v[0]), log_transform_value(k, v[1])]] }

      Log.pending << {
        customer:   log_customer,
        user:       User.current,
        op:         new_record? ? :created : :updated,
        note:       Log.log_note,
        attributes: changes,
        obj:        self
      }
    end
    yield
  end

  def log_destruction
    if logged_attributes && persisted?
      changes = self.slice(*logged_attributes)
                    .to_h { |k, v| [k, [log_transform_value(k, v), log_transform_value(k, nil)]] }

      Log.pending << {
        customer:   log_customer,
        user:       User.current,
        op:         :destroyed,
        attributes: changes,
        note:       Log.log_note,
        obj:        self
      }
    end
    yield
  end

  def log_save_pending
    Log.save_pending
  end
end

around_create/update jsou zvoleny záměrně: musí obejmout celý process ukládání tak, aby se self.changes vyhodnotilo ještě před tím, než ActiveRecord interně vyprázdní dirty tracking. Pokud se save nepovede, přeskočí se i uložení logů, protože fronta se flushne teprve v before_commit.

Thread-local kontext

Aby byl záznam užitečný, potřebujeme vědět, kdo změnu provedl a (volitelně) proč. Oba údaje putují do logu jako kontext přes thread-local proměnné.

Aktuální uživatel

Již dříve zavedený mechanismus v ApplicationController nastaví User.current pomocí around_action pro každý request:

app/controllers/application_controller.rb

around_action :track_current_user

def track_current_user
  User.current = current_user
  yield
ensure
  User.current = nil
end

ensure zaručí, že vlákno (převzaté z poolu Pumy) nezanechá odkaz na starého uživatele.

app/models/user.rb

def self.current
  Thread.current['current_user']
end

def self.current=(user)
  Thread.current['current_user'] = user
end

Poznámka k operaci

Formuláře mohou posílat volitelný parametr log_note — třeba „Přegenerováno" nebo „Storno faktury #42". Controller jej nastaví přes Log.with_note:

app/controllers/application_controller.rb

around_action :log_note

def log_note
  if request.post? || request.patch? || request.put? || request.delete?
    Log.with_note(params[:log_note]) { yield }
  else
    yield
  end
end

app/models/log.rb

def self.with_note(note, &block)
  prev = Thread.current['log_note']
  Thread.current['log_note'] = note
  yield
ensure
  Thread.current['log_note'] = prev
end

with_note je zásobníkový (ukládá a obnovuje předchozí hodnotu), takže ho lze bezpečně vnořovat. Používá ho i business logika modelu přímo:

app/models/invoice.rb

def regenerate!
  Log.with_note("Přegenerováno") do
    # ... přepočítání položek, uložení
  end
end

Při zpracovávání konkrétního úkolu/požadavku z úkolníčku v rámci aplikace se text ve formuláři přednastaví podle otevřeného úkolu.

Transformace hodnot

Syrové hodnoty z databáze by v logu nebyly čitelné. Metoda log_transform_value je přeloží ještě před uložením do fronty: cizí klíče (např. distributor_id: 7) se nahradí čitelným jménem pomocí loggable_name ("PREdistribuce"), booleany se přeloží do češtiny a složené hodnoty jako adresa mají vlastní formátovač.

module Loggable
  def log_transform_value(attribute, value)
    if value && attribute.end_with?('_id') && (assoc = self.class.reflect_on_association(attribute[0...-3]))
      obj = assoc.klass.find(value) rescue nil
      return obj.loggable_name if obj&.respond_to?(:loggable_name)
      return obj.display_name  if obj&.respond_to?(:display_name)
    elsif value === true  then return "ANO"
    elsif value === false then return "NE"
    elsif value.is_a?(Hash) && attribute == "address"
      return Address::summary(value)
    end
    value
  end

  def loggable_name
    return display_name if respond_to?(:display_name)
    return name         if respond_to?(:name)
    ""
  end
end

Cílový zákazník

Pro nalezení zákazníka k němuž má být záznam přiložen se buď zavolá self.customer nebo řetěz volání definovaný jako option pro log_attributes. Např. log_attributes :all, customer: [:advance_period, :advance, :customer] znamená: pro získání zákazníka volej self.advance_period.advance.customer. Případně objekt může prostě metodu log_customer přetížit po svém.

module Loggable
  def log_customer
    if is_a?(Customer)
      self
    elsif respond_to?(:customer)
      customer
    elsif logged_options[:customer]
      target = self
      Array.wrap(logged_options[:customer]).each { |method| target = target.send(method) }
      target
    end
  end
end

Ukládání záznamu

Jeden request může model uložit víckrát. Například vytvoření zálohové faktury - vytvoří fakturu (1. uložení), vytvoří položky, pak doplní souhrn položek do faktury (2. uložení). Výsledný log by pak zbytečně obsahoval mezikroky. Log.save_pending je před zápisem squashne do jednoho. Pokud došlo ke smazání záznamu, zaznamenají se původní hodnoty.