No database error visibility

[SAB13711]

When there is a database error, it does not show the error that blocked the database. Perhaps there is also not sufficient logic to stop the process when something fails.

Below is a snippet of code that calls an ORM object:

    def get_gift_cards_for_user(self, email: str) -> dict:
        """
        Returns all the gift cards for a specific user email.
        :param email: str -- the user's email
        :return:
        {
            "success": bool,
            "code": int,
            "msg": str,
            "error": str | None,
            "created_gift_cards": list,
            "owned_gift_cards": list
        }
        """
        try:
            Log.debug(
                "Getting created gift cards for user",
                email=email
            )
            created_gift_cards = GiftCard.where("created_by_email = ? AND is_deleted = 0", [email])

            Log.debug(
                "Getting owned gift cards for user",
                email=email
            )
            owned_gift_cards = GiftCard.where("owned_by_email = ? AND is_deleted = 0", [email])

            Log.debug(
                "Returning gift cards for user",
                email=email
            )
            return OperationResult(
                success=True,
                code=200,
                msg="Returning gift cards",
                data={
                    "created_gift_cards": [
                        self._enrich_gift_card(gc) for gc in created_gift_cards
                    ],
                    "owned_gift_cards": [
                        self._enrich_gift_card(gc) for gc in owned_gift_cards
                    ]
                }
            ).to_dict()

        except Exception as e:
            return self._error_result(500, "Could not get gift cards for user", str(e))

And here is the log that i see:

2026-06-08 11:16:47.722 |   |  
-- | -- | --
  |   | 2026-06-08 11:16:47.722 | 2026-06-08T09:16:47.722Z [ERROR  ] [b83e41207149e7ea80c873ca9353e0dd] [get_gift_cards_for_user] returning failed result: code:500, msg:Could not get gift cards for user, error:current transaction is aborted, commands ignored until end of transaction block |  
  |   | 2026-06-08 11:16:47.719 | 2026-06-08T09:16:47.718Z [DEBUG  ] [b83e41207149e7ea80c873ca9353e0dd] Getting created gift cards for user {"email": "schalk@codeinfinity.co.za"}

There are no logs after that point and it is the first point that a database call is made. It seems the very first call is already saying that the database connection is blocked.

[MichaelC8E]

Reproduced on tina4-python 3.13.4 + PostgreSQL 18 + psycopg2-binary 2.9.12

Findings

1. The bug location — postgres.py:146-152. PostgreSQLAdapter.fetch() runs a SELECT COUNT(*) before the paginated query to get the total. The COUNT is wrapped in a bare try/except: total = 0. No rollback, no savepoint, no log call. The original error is discarded silently.

# tina4_python/database/postgres.py:146-152 (verbatim, 3.13.4)
count_sql = f"SELECT COUNT(*) AS cnt FROM ({sql}) AS _count_subquery"
try:
    self._safe_execute(cursor, count_sql, params)
    total = cursor.fetchone()["cnt"]
except Exception:
    total = 0

2. Why discarding it is fatal — postgres.py:70. The PG connection is opened with _conn.autocommit = False. PG semantics: any failed query inside an open transaction puts the connection into aborted state. The bare except in finding 1 doesn't roll back, so the next line — the paginated SELECT — runs against a poisoned connection and raises InFailedSqlTransaction ("current transaction is aborted, commands ignored until end of transaction block"). That cascade message is the only thing the caller sees. The real error is already gone.

3. Reproduction output. Ran the SQL shape from the issue body against a real PG 18 instance with a BOOLEAN is_deleted column. Two outputs, two layers:

Raw psycopg2, bypassing the framework:

psycopg2.errors.UndefinedFunction: operator does not exist: boolean = integer
LINE 1: ...AND is_deleted = 0
                          ^
HINT:  No operator matches the given name and argument types.

Framework, through Model.where() on the same SQL:

InFailedSqlTransaction: current transaction is aborted,
commands ignored until end of transaction block

Bottom string matches the issue body character-for-character. The framework eats the useful one and surfaces the useless one.

4. The cause is not surfaced anywhere in the framework.

$ grep -rn "Log\." tina4_python/database/ tina4_python/orm/
(no matches in 3.13.4)

tina4_python.debug.Log exists framework-wide but is never called inside database/ or orm/. Database.get_error() returns None after a fetch() failure too — Database.fetch() doesn't touch last_error, only Database.execute() does. No log line, no error string, no structured trace — the original cause leaves no record.

5. The fix pattern is already in the same file — lines 99-122. The SELECT lastval() query a few lines up was patched for #38 with SAVEPOINT _t4_lastval_probe → ROLLBACK TO on failure → outer transaction survives. The COUNT query at line 147 needs the same wrapper. Pattern is in-tree, no design work.

Worth noting

• The trigger here is a BOOLEAN column compared to an integer literal — most plausible shape given the SQL in the issue body, but not the root cause. The cascade fires for any error inside the COUNT: missing column, type mismatch, function not found, deadlock victim, FK violation. The fix below closes the cascade regardless of trigger.

• Adjacent bug worth its own filing: SQLTranslator.boolean_to_int at adapter.py:538-542 unconditionally rewrites \bTRUE\b → 1 and \bFALSE\b → 0 on the PG translation path. Against a real BOOLEAN column this reintroduces the boolean-vs-integer mismatch in framework-generated SQL. Writing is_deleted = FALSE to dodge this issue still fails — the translator munges it back to 0 before psycopg2 sees it. The translator should skip this rewrite on engines with native boolean support.

Potential fix

Clone of the #38 pattern. Wrap the COUNT in a SAVEPOINT, log the cause on failure, fall back to total = 0 as before. Ideally do the same for the paginated SELECT so the connection stays usable on pagination errors too.

count_sql = f"SELECT COUNT(*) AS cnt FROM ({sql}) AS _count_subquery"
cursor.execute("SAVEPOINT _t4_count")
try:
    self._safe_execute(cursor, count_sql, params)
    total = cursor.fetchone()["cnt"]
    cursor.execute("RELEASE SAVEPOINT _t4_count")
except Exception as e:
    cursor.execute("ROLLBACK TO SAVEPOINT _t4_count")
    total = 0
    try:
        from tina4_python.debug import Log
        Log.error("PostgreSQL COUNT query failed", error=str(e), sql=sql)
    except Exception:
        pass  # logging must never break the data path

Closes the cascade. Preserves the original cause in the structured log. Diagnostic gap closes.

[andrevanzuydam]

Heads-up — even though this is closed already, just noting the fix shipped in v3.13.6 (just published to PyPI).

tina4_python/database/postgres.py now auto-rollbacks the connection when a query fails outside an explicit transaction, populates db.last_error with the original message, and logs the failure via Log.error with the SQL + params. Explicit transactions are left to the caller (so SAVEPOINT / retry patterns still work).

try:
    db.execute("SELECT * FROM table_that_does_not_exist")
except Exception:
    pass

# Before v3.13.6: this raised InFailedSqlTransaction (cascade)
# v3.13.6 onward: succeeds — the framework auto-rolled back
result = db.fetch("SELECT 1 AS one")
assert result.records[0]["one"] == 1

db.last_error  # → 'relation "table_that_does_not_exist" does not exist'

Cross-framework parity verified: this cascade is psycopg2-specific (DB-API 2.0 implicit-transaction semantics). PHP pg_query, Ruby pg gem, and Node node-postgres all run in libpq autocommit mode by default, so no equivalent fix was needed there.

Release notes: https://github.com/tina4stack/tina4-book/blob/main/book-1-python/chapters/36-releases.md