Skip to content

fix(log): stabilize hstore audit snapshots - #821

Open
inkSence wants to merge 3 commits into
SuperCoopBerlin:masterfrom
inkSence:fix/issue-272-hstore-roundtrip
Open

fix(log): stabilize hstore audit snapshots#821
inkSence wants to merge 3 commits into
SuperCoopBerlin:masterfrom
inkSence:fix/issue-272-hstore-roundtrip

Conversation

@inkSence

@inkSence inkSence commented Jul 16, 2026

Copy link
Copy Markdown

Fix intermittent HStore audit log failures

Summary

This PR fixes the intermittent HStore failures reported in #272. It makes HStore adapter registration recover when the web process opens a PostgreSQL connection before the migration process creates the hstore extension.

The fix re-checks HStore availability for newly created connections and at the start of later requests. Once registration succeeds, it is remembered for the lifetime of the underlying raw database connection.

The PR also contains additional changes: it fixes audit snapshot field-exclusion handling so that sensitive fields such as passwords are not persisted, and it adjusts the development Docker environment so the regression tests can run with the required development dependencies.

Fixes #272.

Reproduction before the fix

We reproduced the problem with newly created Docker volumes. Following the README startup order, the web process was allowed to connect to PostgreSQL before migrations were applied. This reproduces the timing condition that leaves the web process with a stale HStore OID lookup.

Using generated synthetic test data, we then followed the reported workflow:

  1. Log in as the generated test user Roberto Cortes.
  2. Create a note on the user's profile.
  3. Edit the profile.
  4. Change the language from English to German.
  5. Replace the invalid default phone number with +12125552368.
  6. Save the profile.

Before the fix, saving the audited change failed. In our reproduction, the exception was:

django.db.utils.ProgrammingError

django.db.utils.ProgrammingError: can't adapt type 'dict'

The relevant part of the traceback was:

File "/app/tapir/accounts/views.py", line 106, in form_valid
    ).save()

File "/app/tapir/log/models.py", line 62, in save
    super(LogEntry, self).save(*args, **kwargs)

django.db.utils.ProgrammingError: can't adapt type 'dict'

This failure happened while saving the audit log, before reaching the original read-side symptom from #272:

'str' object has no attribute 'keys'

Both symptoms have the same underlying cause: the PostgreSQL connection used by the web process did not have working HStore type handlers.

Root cause

A Django web process may open its PostgreSQL connection before migrations create the hstore extension. During connection initialization, Django then caches an empty HStore OID lookup and cannot register the HStore adapters.

Creating the extension later clears that cache only in the migration process. The already running web process continues using its existing connection without HStore adapters.

The connection_created signal alone cannot recover this connection: it was already emitted when the connection was first opened, before HStore existed, and the same raw connection may remain open after the migration.

As a result, dictionaries cannot be adapted when writing an HStoreField, or HStore values are decoded as strings when reading them.

Fix

  • Clear and re-run Django's HStore OID lookup when checking an unregistered PostgreSQL connection.
  • Register the adapters through Django's own PostgreSQL type-handler implementation.
  • Check already initialized connections once when the signal handlers are registered.
  • Check newly created connections through connection_created.
  • Re-check already open connections through request_started, allowing a connection that was opened before the migration to recover on a later request.
  • Remember successful registration for the lifetime of each raw database connection and register again after a reconnect.
  • Allow database errors to propagate instead of hiding configuration or connectivity problems with broad exception handling.

The request-start check is inexpensive for an already registered raw connection: the connection is marked as registered, so later checks of the same raw connection return without repeating the OID lookup or adapter registration.

The fix is applied at the database connection boundary. It does not add a defensive JSON or string decoder that could conceal an incorrectly configured HStore connection.

Related changes

Audit snapshot field exclusion

Field exclusion happens at two points:

  • freeze_for_log() reads excluded_fields_for_logs from the domain model. This now correctly removes fields such as TapirUser.password before the snapshot is returned.
  • ModelLogEntry.populate_base() now recognizes both excluded_fields and exclude_fields when populating a log entry's values snapshot.

Both paths use non-failing removal so that a configured field does not cause an error when it is absent from the snapshot.

Development environment

The Docker development setup now keeps the container's virtual environment separate from a host-side .venv and installs the development dependencies required to run the focused regression tests. The project also declares its direct python-ldap dependency explicitly.

These environment changes support local verification but are independent of the runtime HStore registration fix.

Verification

Focused automated tests

The focused regression suite passed:

8 passed in 7.81s

It covers:

  • retrying on a later check after the HStore extension becomes available;
  • registering handlers again after the raw connection changes;
  • ignoring non-PostgreSQL and Django's no-database connections;
  • propagating database errors instead of swallowing them;
  • checking all initialized database connections;
  • saving and reloading audit snapshots as dictionaries;
  • rendering a reloaded audit entry;
  • excluding the password from frozen user snapshots.

The test command was:

docker compose exec -T web poetry run pytest \
  tapir/log/tests/test_apps.py \
  tapir/accounts/tests/test_update_tapir_user_log_entry.py -q

Fresh-container startup test

We removed the existing Docker volumes and recreated the services from scratch. The web process was deliberately allowed to connect to PostgreSQL before migrations were applied. We then applied all migrations and generated synthetic test data without restarting the web process.

The first request after the migration reached the login form successfully, and the web container's restart count remained zero. This confirms that the already running process continued serving requests without requiring a restart. The subsequent audited profile update verified that HStore registration had recovered. Depending on the database connection lifecycle, registration occurs either when request_started re-checks an existing raw connection or when connection_created initializes a replacement connection.

Manual browser verification

We then repeated the original audited profile-update workflow:

  1. Create a note.
  2. Change the language to German.
  3. Enter +12125552368 as the phone number.
  4. Save the profile.

The save completed successfully. The request returned a redirect instead of an HTTP 500 response, and the web logs contained no ProgrammingError. This confirms that the audited HStore write succeeded in the web process that had been started before the migration.

We additionally inspected the persisted audit entry and confirmed:

phone_number: +12125552368
old_values type: dict
new_values type: dict
logged new phone number: +12125552368

Manual inspection of the persisted entry confirmed that both HStore fields were decoded as dictionaries. The focused integration test additionally reloads and renders the entry, covering the original read-side failure.

Formatting and targeted lint checks passed. manage.py check only reported the pre-existing warning about the missing development dist directory, and poetry check --lock passed with its pre-existing license deprecation warning.

inkSence added 3 commits July 16, 2026 18:19
Install development dependencies in an isolated container virtualenv and declare python-ldap directly.
Retry HStore adapter registration after migrations and consistently exclude configured fields from audit snapshots.
Exercise adapter retries, reconnections, database errors, HStore round-tripping, rendering, and password exclusion.
@inkSence
inkSence marked this pull request as ready for review July 17, 2026 19:10

@Theophile-Madet Theophile-Madet left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

On the Hstore fix:

  • I'm not sure this is something we should fix in our code, it looks more like a bug in django.contrib.postgres. Have you looked for a ticket in https://code.djangoproject.com/query?
  • Keep your PR description short, this is way too long.

On the other changes:

  • Focus on the Hstore fix in this PR and do the other changes in separate dedicated PRs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

'str' object has no attribute 'keys' when changing phone number

2 participants