Deleted record audit log with Ecto and PostgreSQL

José Valim wrote about how to implement soft delete using a PostgreSQL trigger. The best reason for soft delete is when you need the ability to undelete records, e.g., you give a grace period of 30 days before the record is deleted permanently.

If the deletion of records is meant to be irreversible, this would be an anti-pattern. Soft delete for audit logging is problematic because you must be defensive in how you access data, and you must ensure you always use the right view or table partition.

For an audit log, we want to allow the record to be deleted from the table and add a log entry to another table. This could be done entirely in your application code, but this will not catch any deletions by other applications or clients.

As José writes in his blog post, the simple solution is to store a JSON blob of the data.

Deleted record audit log

For our purpose, we want to keep a paper trail of who deleted a record, when it was deleted, and why it was deleted.

We’ll create a migration that creates a deleted record log table and adds a trigger on tables to insert a log entry on DELETE operations.

defmodule MyApp.Repo.Migrations.CreateDeletedRecordLogsTable do
  use Ecto.Migration

  @trigger_on_tables ~w(table_a table_b table_c)

  def up do
    create table(:deleted_record_logs, primary_key: false) do
      add :record_table, :string, null: false, primary_key: true
      add :record_id, :string, null: false, primary_key: true
      add :record_data, :jsonb, null: false
      add :transaction_id, :bigint, null: false
      add :deleted_at, :utc_datetime_usec, null: false
      add :deleted_by, :string, null: false
      add :delete_reason, :text, null: false
    end

    execute """
      CREATE OR REPLACE FUNCTION log_deleted_record()
      RETURNS TRIGGER AS $$
      BEGIN
        INSERT INTO deleted_record_logs (
          record_table,
          record_id,
          record_data,
          transaction_id,
          deleted_at,
          deleted_by,
          delete_reason
        )
        VALUES (
          TG_TABLE_NAME,
          OLD.id,
          row_to_json(OLD)::jsonb,
          txid_current(),
          NOW(),
          current_setting('app.deleted_by', true),
          current_setting('app.delete_reason', true)
        );
        RETURN OLD;
      END;
      $$ LANGUAGE plpgsql;
      """

    for table <- @trigger_on_tables do
      execute """
        CREATE TRIGGER after_delete_trigger_#{table}
        AFTER DELETE ON #{table}
        FOR EACH ROW
        EXECUTE FUNCTION log_deleted_record();
        """
    end
  end

  def down do
    drop table(:deleted_record_logs)

    for table <- @trigger_on_tables do
      execute "DROP TRIGGER after_delete_trigger_#{table} ON #{table};"
    end

    execute "DROP FUNCTION log_deleted_record();"
  end
end

A log_deleted_record function will trigger on deletes of records for the referenced tables and insert into the logs table:

• Record table name
• Record ID
• Record data as a JSON blob
• Transaction ID
• When it was deleted
• Who deleted it
• Why it was deleted

The transaction ID is used to group records that were deleted within the same transaction.

The app.deleted_by and app.delete_reason run-time parameters should be set in the transaction before deleting the record. We require both deleted_by and delete_reason to not be NULL. If these are not specified in the run-time parameters, the deletion will halt with an insert error.

This is how you would delete a record:

Repo.transaction(fn ->
  Repo.query!("SET LOCAL app.deleted_by = 'my name")
  Repo.query!("SET LOCAL app.delete_reason = 'invalid record'")
  Repo.delete!(record)
end)

Using SET LOCAL ensures that these run-time parameters are only set for the current transaction.

Delete record context helper

To make it easier to work with, we want to set up a context function to prepare the run-time parameters for any deletes:

defmodule MyApp.Logs do
  @moduledoc false

  alias MyApp.Repo

  def with_delete_record_context!(deleted_by, delete_reason, callback_fn) do
    Repo.transaction(fn ->
      Repo.query!("SET LOCAL app.deleted_by = '#{escape_string(deleted_by)}'")
      Repo.query!("SET LOCAL app.delete_reason = '#{escape_string(delete_reason)}'")

      res = callback_fn.()

      Repo.query!("RESET app.deleted_by")
      Repo.query!("RESET app.delete_reason")

      res
    end)
  end

  defp escape_string(string) do
    :binary.replace(string, "'", "''", [:global])
  end
end

Now we can wrap our deletes:

MyApp.Logs.with_delete_record_context!("myname", "invalid record", fn ->
  Repo.delete!(record_1)
  Repo.delete!(record_2)
end)

Final words

With these triggers in place, we have strong guarantees for our audit log. Even if someone manually deletes one of the records, it will still be logged with deleted_by and delete_reason. I’ve rolled this out to a large production app where deletions are very consequential, and it has worked flawlessly.

defmodule MyApp.LogsTest do
  use MyApp.DataCase

  alias MyApp.{Logs, Repo}

  describe "with_delete_record_context!/2" do
    @deleted_by "username"
    @delete_reason "This was a bad entry"

    test "sets context" do
      assert Logs.with_delete_record_context!(@deleted_by, @delete_reason, fn ->
        assert Repo.query!("SHOW app.deleted_by").rows == [[@deleted_by]]
        assert Repo.query!("SHOW app.delete_reason").rows == [[@delete_reason]]

        :ok
      end) == :ok
    end

    test "escapes" do
      Logs.with_delete_record_context!("'\\  ", @delete_reason, fn ->
        assert Repo.query!("SHOW app.deleted_by").rows == [["'\\  "]]
      end)

      Logs.with_delete_record_context!(@deleted_by, "'\\  ", fn ->
        assert Repo.query!("SHOW app.delete_reason").rows == [["'\\  "]]
      end)

      Logs.with_delete_record_context!(@deleted_by, "'", fn ->
        assert Repo.query!("SHOW app.delete_reason").rows == [["'"]]
      end)
    end
  end
end