Improve exception handling with `cursor.close()` after errors

[Daniel Hahler]

cursor.close() is explicitly after Exceptions with cursor.execute(), and has a comment already that it might fail: ​https://github.com/django/django/blob/322a1a037d4d2f18744c5d1a1efc2e84d4c5e94b/django/db/models/sql/compiler.py#L1210-L1215

        try:
            cursor.execute(sql, params)
        except Exception:
            # Might fail for server-side cursors (e.g. connection closed)
            cursor.close()

The code there was changed to ignore any exception in ​https://github.com/django/django/commit/6b6be692fcd102436c7abef1d7b3fa1d37ad4bdf (Refs #16614), but then changed to the current code in ​https://github.com/django/django/commit/d170c63351944fd91b2206d10f89e7ff75b53b76 (​https://github.com/django/django/commit/d170c63351944fd91b2206d10f89e7ff75b53b76#diff-f58de2deaccecd2d53199c5ca29e3e1050ec2adb80fb057cdfc0b4e6accdf14f).

The current approach however will create a chained exception always, and especially will add it as context, and not as cause (see ​https://blog.ram.rachum.com/post/621791438475296768/improving-python-exception-chaining-with).

I suggest that exceptions in cursor.close() should get ignored as being expected in a lot / most cased, and it being done only to ensure the connection gets closed really, and should get raised from otherwise.

The main motivation here is that it makes it hard/confusing to see the real error, e.g. when running tests or doing development, and the DB is out of sync.

PR: ​https://github.com/django/django/pull/15141

[Carlton Gibson]

There was an extended discussion of the merits of the raise...from syntax around #31177 (​Mailing list thread).

The summary of that was that, in general, given that exceptions are automatically chained, the different message between the chained exceptions was not worth the noise.

The cited exceptions were using raise...from to remove noise from an long-chain of exceptions, when you wished to pull-out the real cause that may perhaps lie a frame frames deep, and using from None to suppress chaining, when the underlying exception is not informative.

I'm going to close as wontfix on the basis of that discussion. If you think this case is different you can message the DevelopersMailingList. (If so, please give a concrete example of how the change is supposed to help — I couldn't really see if from the description here — it seems like a lot of effort to change the message between the tracebacks, but maybe you're using the __cause__ attribute in a way that merits it…? 🤔)

[Daniel Hahler]

Sorry for not having read the mailing list thread yet, but only your summary of it above.
I think the main issue with context vs. cause is an important detail. I can see that it might not worth changing it all over the code base, but it should be considered when fixing code.

The main issue I see here is that there will be an exception almost always (at least with named cursors in PostgreSQL AFAICS), and therefore it should not even be chained in this case: it really just hides the actual error, just because it is trying to ensure a (never properly opened/used) cursor is closed always.

I might follow up on the mailing list, but do not really feel like subscribing there also etc, especially since the issue here is not about context or cause, but only using raise from properly (according to ​https://blog.ram.rachum.com/post/621791438475296768/improving-python-exception-chaining-with) when not swallowing/hiding the expected exception.

[Carlton Gibson]

Hi Daniel. Thanks for the reply.

It's OK to not read the thread :)

...not about context or cause, but only using raise from properly (according to...

It's the force of properly here that's in doubt.

On investigation, the difference between the two syntaxes amounted to no more (not much more) that the text used between the tracebacks — which are chained either way, either implicitly or explicitly, unless from None is used. That difference in text, "During handling of the above exception, another exception occurred" vs "The above exception was the direct cause of the following exception", wasn't felt significant — not compared to the more verbose syntax, and in the PR you have here, much more verbose block in order to decide when to use it.

Thus, with the exceptions noted above, it was decided not to use the from syntax. (We didn't agree with the blog post that not using it was improper.)

So, if there's a concrete example, of "Look, you get this benefit", then I'm really happy to look at that, and learn a trick, but pending that, we have to go with the previous consensus. I hope that makes sense. Thanks!

[Daniel Hahler]

The main issue here is not about how to raise in case it should be raised, but to not raise in the first place, if an error is expected.
It is meant to fix https://code.djangoproject.com/ticket/16614#comment:31 again, which regressed.

[Carlton Gibson]

Hi Daniel.

I'm really sorry but I'm failing to see the point you're trying to make here... There's clearly something I'm missing because you keep trying to get it across to me, but I just don't get it. Can I please ask you to take a step back and explain it to me from the top clearly so that I can see the issue?

It looks to me like the code we have here when there's no exception in cursor.close() is equivalent to this:

def will_raise(msg):
    raise Exception(msg)


try:
    will_raise("Outer")
except Exception:
    raise

When I run that, I get this output:

% python3 exceptions.py
Traceback (most recent call last):
  File "/Users/carlton/Desktop/exceptions.py", line 6, in <module>
    will_raise("Outer")
  File "/Users/carlton/Desktop/exceptions.py", line 2, in will_raise
    raise Exception(msg)
Exception: Outer

When there is an exception in cursor.close() it looks like this:

def will_raise(msg):
    raise Exception(msg)


try:
    will_raise("Outer")
except Exception:
    will_raise("Inner")
    raise

Which gives this output:

% python3 exceptions.py
Traceback (most recent call last):
  File "/Users/carlton/Desktop/exceptions.py", line 6, in <module>
    will_raise("Outer")
  File "/Users/carlton/Desktop/exceptions.py", line 2, in will_raise
    raise Exception(msg)
Exception: Outer

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/carlton/Desktop/exceptions.py", line 8, in <module>
    will_raise("Inner")
  File "/Users/carlton/Desktop/exceptions.py", line 2, in will_raise
    raise Exception(msg)
Exception: Inner

Your suggestion seems to be to make it equivalent to:

def will_raise(msg):
    raise Exception(msg)


try:
    will_raise("Outer")
except Exception as o:
    try:
        will_raise("Inner")
    except Exception as i:
        raise i from o
    raise

... which has the output:

% python3 exceptions.py
Traceback (most recent call last):
  File "/Users/carlton/Desktop/exceptions.py", line 19, in <module>
    will_raise("Outer")
  File "/Users/carlton/Desktop/exceptions.py", line 15, in will_raise
    raise Exception(msg)
Exception: Outer

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/carlton/Desktop/exceptions.py", line 24, in <module>
    raise i from o
  File "/Users/carlton/Desktop/exceptions.py", line 22, in <module>
    will_raise("Inner")
  File "/Users/carlton/Desktop/exceptions.py", line 15, in will_raise
    raise Exception(msg)
Exception: Inner

Which is exactly the same bar the "direct cause" wording change, that was agreed on the mailing list discussion to be not worth the verbosity of the code change.
(The line numbers are different, because I have the original version commented above in the file — not because of a logic change.)

So what's it fixing? (Again: Sorry to not be seeing this, but I'm just not getting the point you want to make.)

It is meant to fix https://code.djangoproject.com/ticket/16614#comment:31 again, which regressed.

But it didn't regress. Both Outer and Inner are given in the traceback. Outer is given first, plus the additional info that Inner occurred whilst we were handling that.
This behaviour in Python 3 is what justifies the change in ​https://github.com/django/django/commit/d170c63351944fd91b2206d10f89e7ff75b53b76#diff-f58de2deaccecd2d53199c5ca29e3e1050ec2adb80fb057cdfc0b4e6accdf14fR878-R879 — the original error is raised.

If you can put together an actual example of the problem you're hitting coming up, that might make it easier. It's very hard to see when it's just a couple of lines changed with no test-case or reproduce. (I appreciate cursor errors can be hard to test...)

[Daniel Hahler]

The main thing this is meant to fix is not raising errors from cursor.close() in the first place.
The difference between "caused by" and "then triggered also" is only relevant for when it should not get swallowed (based on if it is expected because there was an error already).

What you currently get during a test run with a missing migration:

Traceback (most recent call last):
  File "…/Vcs/django/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
psycopg2.errors.UndefinedColumn: column foo.bar does not exist
LINE 1: ...
                                                             ^


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "…/Vcs/django/django/db/models/sql/compiler.py", line 1361, in execute_sql
    cursor.execute(sql, params)
…
  File "…/Vcs/django/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.ProgrammingError: column foo.bar does not exist
LINE 1: ...
                                                             ^


During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "…/project/.venv/lib/python3.10/site-packages/pytest_django/fixtures.py", line 122, in django_db_setup
    db_cfg = setup_databases(
…
  File "…/Vcs/django/django/db/models/sql/compiler.py", line 1364, in execute_sql
    cursor.close()
psycopg2.errors.InvalidCursorName: cursor "_django_curs_140147764090688_sync_10" does not exist

psycopg2.errors.InvalidCursorName is expected to happen here, and obfuscates/hides the real error (e.g. when it gets used for display in the short test summary etc).

The (current) patch changes it to:

Traceback (most recent call last):
  File "…/Vcs/django/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
psycopg2.errors.UndefinedColumn: column foo.bar does not exist
LINE 1: ...
                                                             ^


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "…/project/.venv/lib/python3.10/site-packages/pytest_django/fixtures.py", line 122, in django_db_setup
    db_cfg = setup_databases(
…
  File "…/Vcs/django/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.ProgrammingError: column foo.bar does not exist
LINE 1: ...
                                                             ^

[Carlton Gibson]

The main thing … is not raising errors from cursor.close() in the first place … e.g. when it gets used for display in the short test summary etc.

So the request is suppressing the chained nested exception — you don't want the newer Python 3 behaviour in this case — which would be a new feature, rather than a fixing a regression from #16614.

And the reason you want this if because your test runner (presumably pytest) formats its output in a given way? (Is that it?)

[Daniel Hahler]

https://code.djangoproject.com/ticket/16614#comment:31 is about "Refs #16614 -- Prevented database errors from being masked by cursor close.".

The fix there ignored all exceptions (​https://github.com/django/django/commit/6b6be692fcd102436c7abef1d7b3fa1d37ad4bdf).
The fix I've done for the regression is a bit smarter to still raise in case of unexpected errors.
(This could also be removed in case you want a more concise patch, but even when it is unlikely that it would swallow something unwanted, I've meant to put attention to detail there - just in line with the difference that we've previously discussed here)

[Carlton Gibson]

Hi Daniel.

It wasn't really that 6b6be692fcd102436c7abef1d7b3fa1d37ad4bdf ignored all exceptions. Rather it stopped the source exception being masked, with the explicit intention that the new chained behaviour would be preferred when it was available:

# Ignore clean up errors and raise the original error instead.
# Python 2 doesn't chain exceptions. Remove this error
# silencing when dropping Python 2 compatibility.

Given that it's clearly not a regression in d170c63351944fd91b2206d10f89e7ff75b53b76 — that was the intended change all along.

You're then asking for a change in behaviour to remove information from the traceback. Maybe that's OK if there's a good reason, but otherwise the presumption would be wontfix.

I'm not sure about the patch itself: it would be easier to consider in a fresh PR, with a regression test.

[Daniel Hahler]

Ok, fair enough - it is only fixing a regression on Python 3 then (for me), that was actually done as a workaround.

I suggest reading the original tickets description maybe then: my intention was to not mask / "extend" the actual exception with more information (the (IMHO incorrectly chained) error during cleanup, that is expected to fail). It is similar to a file.close() when it is expected that it wasn't created or its handler being invalid already.

Replying to ​https://github.com/django/django/commit/6b6be692fcd102436c7abef1d7b3fa1d37ad4bdf#r67292630:

The cleanup part of the chain adds noise to the actual source of the error, so maybe it can be improved. But that’s an improvement over the existing situation, not a regression.

Ok, I see. That's what I've meant to do: basically restoring the behavior with Python 3 (when the workaround for Python 2 was in place), while being a bit smarter to only ignore/swallow expected errors.
I was not aware that the intention with the Python 2 workaround was to chain ("add useless noise") always with Python 3.

The question here really is also: if you would know that the connection is invalid, and that close() would throw: would you call it in the first place?

As for a new PR I'd rather update the existing one, but cannot re-open it as mentioned there.