Audit Logging in Phoenix Without Leaking Passwords
Why your Ecto audit log misses update_all, and other traps I found while building one.
Sooner or later, every app gets the question: "Who changed this record, and when?"
Sometimes it comes from a compliance checklist. More often it comes during an incident, when a customer's plan was downgraded, a price changed, or an admin account appeared from nowhere, and nobody can say how.
I recently built audit logging for a Phoenix app. The first version took ten minutes. Finding everything that was wrong with it took a lot longer. This post walks through the traps I hit, how to avoid them in plain Ecto, and how PostgreSQL triggers cover the changes your Elixir code never sees.
The ten-minute version
Here's the audit log most of us write first:
def update_user(user, attrs, actor) do
changeset = User.changeset(user, attrs)
with {:ok, updated} <- Repo.update(changeset) do
Repo.insert!(%AuditLog{
action: "update",
table: "users",
record_id: to_string(updated.id),
actor_id: to_string(actor.id),
changes: changeset.changes
})
{:ok, updated}
end
end
It works in development and it passes the tests. It also has four problems.
Trap 1: it isn't atomic
The update and the audit insert are two separate database calls. If the audit insert fails (a constraint, a timeout, a deploy at the wrong moment), the user is updated and there's no record of it. An audit log with gaps is worse than none, because people trust it.
Trap 2: it logs plaintext passwords
This is the one that surprised me. If you used phx.gen.auth, your User schema has:
field :password, :string, virtual: true, redact: true
Then a password change runs a changeset that casts :password, so changeset.changes contains:
%{password: "correct horse battery staple", hashed_password: "$2b$12$..."}
redact: true only hides the field from inspect/2. It does nothing to changeset.changes. So the naive version writes your users' plaintext passwords into the audit table, and the hash as well for good measure.
Virtual fields are a common place for secrets: passwords, confirmation fields, one-time tokens. None of them are database columns, so none of them belong in an audit log of database changes.
Trap 3: nested changesets come along
If the form uses cast_assoc or cast_embed, changeset.changes holds whole Ecto.Changeset structs for the children. Serialize those and you store their params (raw user input, including any secrets in the child form), plus validations, types, repo and more. You get a large, noisy JSON blob that leaks data.
Trap 4: there's no "before"
changeset.changes only has the new values. "Price changed to 49" is much less useful than "price changed from 19 to 49".
Fixing it in plain Ecto
Use one transaction
Ecto.Multi puts the change and the audit row in one transaction, so they succeed or fail together:
Ecto.Multi.new()
|> Ecto.Multi.update(:user, changeset)
|> Ecto.Multi.insert(:audit, fn %{user: user} ->
AuditLog.changeset(%AuditLog{}, %{
action: "update",
table: "users",
record_id: to_string(user.id),
actor_id: to_string(actor.id),
changes: diff(changeset)
})
end)
|> Repo.transaction()
If either step fails, both roll back.
Only diff real columns
Ecto already knows which fields are persisted. __schema__(:fields) excludes virtual fields and associations:
defp diff(changeset) do
schema = changeset.data.__struct__
persisted = schema.__schema__(:fields)
applied = Ecto.Changeset.apply_changes(changeset)
changeset.changes
|> Map.keys()
|> Enum.filter(&(&1 in persisted))
|> Map.new(fn field ->
{field, %{from: Map.get(changeset.data, field), to: Map.get(applied, field)}}
end)
|> Map.reject(fn {_field, %{from: from, to: to}} -> from == to end)
end
This gets you three things:
-
No virtual fields:
:passwordis never a candidate. - No associations: child records should be audited as their own rows.
-
Applied values:
apply_changes/1turns embedded changesets into plain structs, so you store the resulting data rather than the changeset internals.
You'll still want a deny-list for persisted secrets such as hashed_password and API tokens, and probably redaction ("[REDACTED]") for fields like email where you want to know that something changed but not what it changed to.
What your wrappers will never see
Even with all of that, the audit log only covers changes that go through update_user/3. That leaves out:
-
Repo.update_all(User, set: [plan: "free"])in a background job -
Repo.insert_allimports - a plain
Repo.updatesomeone wrote in a hurry - a migration that backfills data
- someone fixing a row by hand in
psqlat 2am
For an audit log, those can be the changes that matter most. The only layer that sees all of them is the database itself.
Postgres triggers
A row-level trigger runs for every insert, update and delete on a table, however it happened. The core idea fits on one screen:
CREATE FUNCTION audit_capture() RETURNS trigger LANGUAGE plpgsql AS $$
DECLARE
v_old jsonb := CASE WHEN TG_OP IN ('UPDATE', 'DELETE') THEN to_jsonb(OLD) END;
v_new jsonb := CASE WHEN TG_OP IN ('INSERT', 'UPDATE') THEN to_jsonb(NEW) END;
v_changes jsonb := '{}';
v_col text;
BEGIN
FOR v_col IN SELECT jsonb_object_keys(coalesce(v_new, v_old)) LOOP
CONTINUE WHEN v_col = 'hashed_password';
CONTINUE WHEN coalesce(v_old -> v_col, 'null') = coalesce(v_new -> v_col, 'null');
v_changes := v_changes || jsonb_build_object(
v_col, jsonb_build_object('from', v_old -> v_col, 'to', v_new -> v_col)
);
END LOOP;
INSERT INTO audit_events (action, "table", changes, actor_id)
VALUES (
lower(TG_OP),
TG_TABLE_NAME,
v_changes,
nullif(current_setting('app.actor_id', true), '')
);
RETURN NULL;
END;
$$;
CREATE TRIGGER audit AFTER INSERT OR UPDATE OR DELETE ON users
FOR EACH ROW EXECUTE FUNCTION audit_capture();
to_jsonb(OLD) and to_jsonb(NEW) turn the row into JSON, and the loop keeps only the columns that changed. Because the trigger runs inside the same transaction as the write, it's atomic for free.
Getting the actor into the database
The database doesn't know who current_user is. The trick is a transaction-local setting:
Repo.transaction(fn ->
Repo.query!("SELECT set_config('app.actor_id', $1, true)", [to_string(user.id)])
Repo.update_all(User, set: [plan: "free"])
end)
The true makes the setting local to the transaction, so it disappears at commit or rollback and never leaks to the next request using that pooled connection. The trigger reads it with current_setting('app.actor_id', true).
Some gotchas I hit along the way:
-
After the transaction, the setting is an empty string, not
NULL. Once a custom setting has been used in a session, it reverts to''. Hence thenullif(..., ''). -
Savepoints don't scope it. A
Repo.transactionnested in another one becomes a savepoint, and the setting lasts until the outermost transaction ends. That includes Ecto's SQL sandbox in tests, which wraps every test in a transaction. - Values come out as Postgres JSON. Decimals become JSON numbers and timestamps lose Ecto's types, so trigger-recorded changes don't look exactly like the ones your Elixir code records.
- Duplicate events. If you keep the Elixir-side audit (which knows more, like schema-level redaction and request metadata) and add triggers, every normal write is recorded twice. One fix is for the Elixir side to set a transaction-local "skip" flag just before its own statement and clear it straight after. The trigger checks the flag, and everything else in the transaction is still captured.
Packaging it up: AuditTrailEx
I wrapped all of this into a library, AuditTrailEx. Setup is a dependency and a migration:
# mix.exs
{:audit_trail_ex, "~> 0.2.0"}
# a migration
def up, do: AuditTrailEx.Migration.up()
def down, do: AuditTrailEx.Migration.down()
# config/config.exs
config :audit_trail_ex,
excluded_fields: [:hashed_password, :current_password],
redacted_fields: [:email]
Then use it in place of Repo writes:
{:ok, user} =
AuditTrailEx.update(Repo, User.changeset(user, attrs),
actor: current_user,
metadata: %{request_id: request_id}
)
It handles everything above: one transaction, persisted columns only, before-and-after values, exclusion and redaction (globally, per schema or per call), and Ecto.Multi support. It also turns events into readable text:
AuditTrailEx.history(Repo, User, user.id)
|> List.first()
|> AuditTrailEx.describe_text()
# Update MyApp.Accounts.User [42]
#
# Name changed
# From: "John"
# To: "Johnny"
The trigger approach is optional, and both approaches write to the same table:
# a migration
AuditTrailEx.Trigger.install()
AuditTrailEx.Trigger.create(MyApp.Accounts.User)
# config: AuditTrailEx tells the trigger to skip writes it already recorded
config :audit_trail_ex, trigger_capture: true
AuditTrailEx.with_context(Repo, [actor: current_user], fn ->
Repo.update_all(User, set: [plan: "free"])
end)
Grouping events by transaction
One request often changes several tables: an order, its line items, and a stock count updated by a trigger. To answer "what did this request change?", every audit row needs to know which transaction wrote it.
Postgres has an id for that: pg_current_xact_id(), which is unique for the life of the database. Make it the column default and every insert into the audit table records it, whether it came from Elixir or from a trigger, with no extra query:
add :transaction_id, :bigint, default: fragment("pg_current_xact_id()::text::bigint")
One gotcha if you add this to an existing table: adding a column with a volatile default makes Postgres rewrite the table and stamp every existing row with the migration's own transaction id. Add the column first, then ALTER COLUMN ... SET DEFAULT in a separate step.
AuditTrailEx does this for you:
[event | _] = AuditTrailEx.history(Repo, User, user.id)
# Everything committed in the same transaction, across tables
AuditTrailEx.by_transaction(Repo, event)
Limitations, to be upfront: it's an early 0.x release, it's mainly tested on PostgreSQL (triggers need 13 or later), exclusion is by field name, and TRUNCATE isn't captured. Established libraries like PaperTrail, ExAudit and Carbonite are worth a look too. Pick the one that matches how you want to capture changes.
Takeaways
Even if you never use the library, these are worth checking in your own audit log:
- Write the audit row in the same transaction as the change.
-
Diff
__schema__(:fields), notchangeset.changes, so virtual fields and nested changesets never reach the log. Check what yours does with aphx.gen.authpassword change. - Store before and after values, not just the new ones.
-
Remember what your Elixir code can't see.
update_all, raw SQL and manual fixes need database triggers. - Record the transaction id, so you can see everything one request changed, not just one row.
Next on the roadmap is read-only reconstruction: rebuilding a record as it was at a given time. (Automatic revert is on hold after feedback from the community: most people want to look at past state, and reverting changes across tables safely is much harder.) The open question is how to represent fields that can't be rebuilt, such as redacted ones or anything from before auditing started. If you have opinions, I'd love to hear them in the Elixir Forum thread or on GitHub.
Thanks for reading!
Top comments (0)