Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Log Stacktrace of current Python Interpreter via PostgreSQL trigger

I am trying to find a bug which happens from time to time on our production server, but could not be reproduced otherwise: some value in the DB gets changed in a way which I don't want it to.

I could write a PostgreSQL trigger which fires if this bug happens, and raise an exception from said trigger. I would see the Python traceback which executes the unwanted SQL statement.

But in this case I don't want to stop the processing of the request.

Is there a way to log the Python/Django traceback from within a PostgreSQL trigger?

I know that this is not trival since the DB code runs under a different linux process with a different user id.

I am using Python, Django, PostgreSQL, Linux.

I guess this is not easy since the DB trigger runs in a different context than the python interpreter.

Please ask if you need further information.

Update

One solution might be to overwrite connection.notices of psycopg2.

like image 278
guettli Avatar asked Aug 16 '18 09:08

guettli


3 Answers

Is there a way to log the Python/Django traceback from within a PostgreSQL trigger?

No, there is not

  • The (SQL) query is executed on the DBMS-server, and so is the code inside the trigger
  • The Python code is executed on the client which is a different process, possibly executed by a different user, and maybe even on a different machine.

The only connection between the server (which detects the condition) and the client (which needs to perform the stackdump) is the connected socket. You could try to extend the server's reply (if there is one) by some status code, which is used by the client to stackddump itself. This will only work if the trigger is part of the current transaction, not of some unrelated process.

The other way is: massive logging. Make the DBMS write every submitted SQL to its logfile. This can cause huge amounts of log entries, which you have to inspect.

like image 134
joop Avatar answered Oct 05 '22 18:10

joop


Given this setup

(django/python) -[SQL connection]-> (PostgreSQL server)

your intuition that

I guess this is not easy since the DB trigger runs in a different context than the python interpreter.

is correct. At least, we won't be able to do this exactly the way you want it; not without much acrobatics.

However, there are options, each with drawbacks:

  • If you are using django with SQLAlchemy, you can register event listeners (either ORM events or Core Events) that detect this bad SQL statement you are hunting, and log a traceback.
  • Write a wrapper around your SQL driver, check for the bad SQL statement you are hunting, and log the traceback every time it's detected.
  • Give every SQL transaction, or every django request, an ID (could just be some UUID in werkzeug's request-bound storage manager). From here, we gain more options:

    • Configure the logger to log this request ID everywhere, and log all SQL statements in SQLAlchemy. This lets you correlate Django requests, and specific function invocations, with SQL statements. You can do this with echo= in SQLAlchemy.
    • Include this request ID in every SQL statement (extra column?), then log this ID in the PostgreSQL trigger with RAISE NOTICE. This lets you correlate client-side activity in django against server-side activity in PostgreSQL.
  • In the spirit of "Test in Production" espoused by Charity Majors, send every request to a sandbox copy of your Django app that reads/writes a sandboxed copy of your production database. In the sandbox database, raise the exception and log your traceback.

    • You can take this idea further and create smaller "async" setups. For example, you can, for each request, trigger a async duplicate (say, with celery) of the same request that hits a DB configured with your PostgreSQL trigger to fail and log the traceback.
  • Use RAISE EXCEPTION in the PostgreSQL trigger to rollback the current transaction. In Python, catch that specific exception, log it, then repeat the transaction, changing the data slightly (extra column?) to indicate that this is a retry and the trigger should not fail.

Is there a reason you can't SELECT all row values into Python, then do the detection in Python entirely?

like image 32
James Lim Avatar answered Oct 05 '22 19:10

James Lim


So if you're able to detect the condition after the queries execute, then you can log the condition and/or throw an exception.

Then what you need is tooling like Sentry or New Relic.

like image 45
Melvyn Sopacua Avatar answered Oct 05 '22 19:10

Melvyn Sopacua