Subject: psycopg2: proper positioning of .commit() within try: except: blocks

From: Karsten Hilbert <[email-masked]>
Date: Sat, 7 Sep 2024 17:48:01 +0200

Dear all,

unto now I had been thinking this is a wise idiom (in code
that needs not care whether it fails to do what it tries to
do^1):

	conn = psycopg2.connection(...)
	curs = conn.cursor()
	try:
		curs.execute(SOME_SQL)
	except PSYCOPG2-Exception:
		some logging being done, and, yes, I
		can safely inhibit propagation^1
	finally:
		conn.commit()		# will rollback, if SOME_SQL failed
		conn.close()

So today I head to learn that conn.commit() may very well
raise a DB related exception, too:

	psycopg2.errors.SerializationFailure: could not serialize access due to read/write dependencies among transactions
	DETAIL:  Reason code: Canceled on identification as a pivot, during commit attempt.
	TIP:  The transaction might succeed if retried.

Now, what is the proper placement of the .commit() ?

(doing "with ... as conn:" does not free me of committing appropriately)

Should I

	try:
		curs.execute(SOME_SQL)
		conn.commit()
	except PSYCOPG2-Exception:
		some logging being done, and, yes, I
		can safely inhibit propagation^1
	finally:
		conn.close()			# which should .rollback() automagically in case we had not reached to .commit()

?

Thanks for insights,
Karsten

#-------------------------------
^1:

	This particular code is writing configuration defaults
	supplied in-code when no value is yet to be found in the
	database. If it fails, no worries, the supplied default
	is used by follow-on code and storing it is re-tried next
	time around.

#-------------------------------
Exception details:

	Traceback (most recent call last):
	  File "/usr/share/gnumed/Gnumed/wxpython/gmGuiMain.py", line 3472, in OnInit
	    frame = gmTopLevelFrame(None, id = -1, title = _('GNUmed client'), size = (640, 440))
	            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	  File "/usr/share/gnumed/Gnumed/wxpython/gmGuiMain.py", line 191, in __init__
	    self.LayoutMgr = gmHorstSpace.cHorstSpaceLayoutMgr(self, -1)
	                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	  File "/usr/share/gnumed/Gnumed/wxpython/gmHorstSpace.py", line 215, in __init__
	    self.top_panel = gmTopPanel.cTopPnl(self, -1)
	                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	  File "/usr/share/gnumed/Gnumed/wxpython/gmTopPanel.py", line 52, in __init__
	    wxgTopPnl.wxgTopPnl.__init__(self, *args, **kwargs)
	  File "/usr/share/gnumed/Gnumed/wxGladeWidgets/wxgTopPnl.py", line 33, in __init__
	    self._TCTRL_patient_selector = cActivePatientSelector(self, wx.ID_ANY, "")
	                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	  File "/usr/share/gnumed/Gnumed/wxpython/gmPatSearchWidgets.py", line 1295, in __init__
	    cfg.get2 (
	  File "/usr/share/gnumed/Gnumed/pycommon/gmCfg.py", line 248, in get2
	    self.set (
	  File "/usr/share/gnumed/Gnumed/pycommon/gmCfg.py", line 367, in set
	    rw_conn.commit()		# will rollback if transaction failed
	    ^^^^^^^^^^^^^^^^
	psycopg2.errors.SerializationFailure: could not serialize access due to read/write dependencies among transactions
	DETAIL:  Reason code: Canceled on identification as a pivot, during commit attempt.
	TIP:  The transaction might succeed if retried.

	2024-08-20 22:17:04  INFO      gm.cfg        [140274204403392 UpdChkThread-148728]  (/usr/share/gnumed/Gnumed/pycommon/gmCfg.py::get2() #148): creating option [horstspace.update.consider_latest_branch] with default [True]
	2024-08-20 22:17:04  DEBUG     gm.db_pool    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmConnectionPool.py::exception_is_connection_loss() #667): interpreting: could not serialize access due to read/write dependencies among transactions
	DETAIL:  Reason code: Canceled on identification as a pivot, during commit attempt.
	TIP:  The transaction might succeed if retried.

	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #170): exception: could not serialize access due to read/write dependencies among transactions
	DETAIL:  Reason code: Canceled on identification as a pivot, during commit attempt.
	TIP:  The transaction might succeed if retried.

	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #171): type: <class 'psycopg2.errors.SerializationFailure'>
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #172): list of attributes:
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   add_note: <built-in method add_note of SerializationFailure object at 0x7f942a3c9cf0>
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   args: ('could not serialize access due to read/write dependencies among transactions\nDETAIL:  Reason code: Canceled on identification as a pivot, during commit attempt.\nTIP:  The transaction might succeed if retried.\n',)
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   cursor: None
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   diag: <psycopg2.extensions.Diagnostics object at 0x7f942a2b9e10>
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   pgcode: 40001
	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   pgerror: ERROR:  could not serialize access due to read/write dependencies among transactions
	DETAIL:  Reason code: Canceled on identification as a pivot, during commit attempt.
	TIP:  The transaction might succeed if retried.

	2024-08-20 22:17:04  DEBUG     gm.logging    [140274459512896 MainThread]  (/usr/share/gnumed/Gnumed/pycommon/gmLog2.py::log_stack_trace() #178):   with_traceback: <built-in method with_traceback of SerializationFailure object at 0x7f942a3c9cf0>

--
GPG  40BE 5B0E C98E 1713 AFA6  5BC0 3BEA AC80 7D4F C89B

---

From: Adrian Klaver <[email-masked]>
Date: Sat, 7 Sep 2024 09:46:03 -0700

> 	conn = psycopg2.connection(...)

In the above do you have:

https://www.psycopg.org/docs/extensions.html#psycopg2.extensions.ISOLATION_LEVEL_SERIALIZABLE

psycopg2.extensions.ISOLATION_LEVEL_SERIALIZABLE

Or is that in some other concurrent transaction?

> 		conn.commit()		# will rollback, if SOME_SQL failed

It will if you use with conn:, otherwise it up to you to do the rollback()

Are you are doing a rollback() in except PSYCOPG2-Exception: ?

-- 
Adrian Klaver
[email-masked]

---

From: Karsten Hilbert <[email-masked]>
Date: Sat, 7 Sep 2024 21:44:36 +0200

> psycopg2.extensions.ISOLATION_LEVEL_SERIALIZABLE

I do indeed.

> Or is that in some other concurrent transaction?

In fact in that codebase all transactions -- running
concurrently or not -- are set to SERIALIZABLE.

They are not psycopg2.extensions.ISOLATION_LEVEL_AUTOCOMMIT,
for that matter.

> Are you are doing a rollback() in except PSYCOPG2-Exception: ?

No I don't but - to my understanding - an ongoing transaction
is being closed upon termination of the hosting connection.
Unless .commit() is explicitely being issued somewhere in the
code that closing of a transaction will amount to a ROLLBACK.

In case of SQL having failed within a given transaction a
COMMIT will fail-but-rollback, too (explicit ROLLBACK would
succeed while a COMMIT would fail and, in-effect, roll back).

IOW, when SOME_SQL has failed it won't matter that I close
the connection with conn.commit() and it won't matter that
conn.commit() runs a COMMIT on the database -- an open
transaction having run that failed SQL will still roll back
as if ROLLBACK had been issued. Or else my mental model is
wrong.

	https://www.psycopg.org/docs/connection.html#connection.close

In the particular case I was writing about the SQL itself
succeeded but then the COMMIT failed due to serialization. I
was wondering about where to best place any needed
conn.commit(). My knee-jerk reaction was to then put it last
in the try: block...

All this is probably more related to Python than to PostgreSQL.

Thanks,
Karsten

---

From: Adrian Klaver <[email-masked]>
Date: Sat, 7 Sep 2024 13:03:34 -0700

> 	https://www.psycopg.org/docs/connection.html#connection.close

Which says:

" Note that closing a connection without committing the changes first 
will cause any pending change to be discarded as if a ROLLBACK was 
performed"

That indicates the ROLLBACK is done on the close() not the commit() and 
only if a commit() was not issued first.

NOTE: If you use the with context manager the transaction automatically 
commits on success and rolls back exception, though it does not close 
the connection. This is changed in psycopg3 where the connection is closed

In the case you show you are doing commit() before the close() so any 
errors in the transactions will show up then. My first thought would be 
to wrap the commit() in a try/except and deal with error there.

---

From: Karsten Hilbert <[email-masked]>
Date: Sat, 7 Sep 2024 22:45:24 +0200

Am Sat, Sep 07, 2024 at 01:03:34PM -0700 schrieb Adrian Klaver:

> In the case you show you are doing commit() before the close() so any errors in the
> transactions will show up then. My first thought would be to wrap the commit() in a
> try/except and deal with error there.

Right, and this was suggested elsewhere ;)

And, yeah, the actual code is much more involved :-D

#------------------------------------------------------------------------
def __safely_close_cursor_and_rollback_close_conn(close_cursor=None, rollback_tx=None, close_conn=None):
	if close_cursor:
		try:
			close_cursor()
		except PG_ERROR_EXCEPTION as pg_exc:
			_log.exception('cannot close cursor')
			gmConnectionPool.log_pg_exception_details(pg_exc)
	if rollback_tx:
		try:
			# need to rollback so ABORT state isn't retained in pooled connections
			rollback_tx()
		except PG_ERROR_EXCEPTION as pg_exc:
			_log.exception('cannot rollback transaction')
			gmConnectionPool.log_pg_exception_details(pg_exc)
	if close_conn:
		try:
			close_conn()
		except PG_ERROR_EXCEPTION as pg_exc:
			_log.exception('cannot close connection')
			gmConnectionPool.log_pg_exception_details(pg_exc)

#------------------------------------------------------------------------
def run_rw_queries (
	link_obj:_TLnkObj=None,
	queries:_TQueries=None,
	end_tx:bool=False,
	return_data:bool=None,
	get_col_idx:bool=False,
	verbose:bool=False
) -> tuple[list[dbapi.extras.DictRow], dict[str, int] | None]:
	"""Convenience function for running read-write queries.

	Typically (part of) a transaction.

	Args:
		link_obj: None, cursor, connection
		queries:

		* a list of dicts [{'cmd': <string>, 'args': <dict> or <tuple>)
		* to be executed as a single transaction
		* the last query may usefully return rows, such as:

			SELECT currval('some_sequence');
				or
			INSERT/UPDATE ... RETURNING some_value;

		end_tx:

		* controls whether the transaction is finalized (eg.
		  COMMITted/ROLLed BACK) or not, this allows the
		  call to run_rw_queries() to be part of a framing
		  transaction
		* if link_obj is a *connection* then "end_tx" will
		  default to False unless it is explicitly set to
		  True which is taken to mean "yes, you do have full
		  control over the transaction" in which case the
		  transaction is properly finalized
		* if link_obj is a *cursor* we CANNOT finalize the
		  transaction because we would need the connection for that
		* if link_obj is *None* "end_tx" will, of course, always
		  be True, because we always have full control over the
		  connection, not ending the transaction would be pointless

		return_data:

		* if true, the returned data will include the rows
		    the last query selected
		* if false, it returns None instead

		get_col_idx:

		* True: the returned tuple will include a dictionary
		    mapping field names to column positions
		* False: the returned tuple includes None instead of a field mapping dictionary

	Returns:

		* (None, None) if last query did not return rows
		* ("fetchall() result", <index>) if last query returned any rows and "return_data" was True

		* for *index* see "get_col_idx"
	"""
	assert queries is not None, '<queries> must not be None'

	if link_obj is None:
		conn = get_connection(readonly = False)
		curs = conn.cursor()
		conn_close = conn.close
		tx_commit = conn.commit
		tx_rollback = conn.rollback
		curs_close = curs.close
		notices_accessor = conn
	else:
		conn_close = lambda *x: None
		tx_commit = lambda *x: None
		tx_rollback = lambda *x: None
		curs_close = lambda *x: None
		if isinstance(link_obj, dbapi._psycopg.cursor):
			curs = link_obj
			notices_accessor = curs.connection
		elif isinstance(link_obj, dbapi._psycopg.connection):
			if end_tx:
				tx_commit = link_obj.commit
				tx_rollback = link_obj.rollback
			curs = link_obj.cursor()
			curs_close = curs.close
			notices_accessor = link_obj
		else:
			raise ValueError('link_obj must be cursor, connection or None but not [%s]' % link_obj)

	for query in queries:
		try:
			args = query['args']
		except KeyError:
			args = None
		try:
			curs.execute(query['cmd'], args)
			if verbose:
				gmConnectionPool.log_cursor_state(curs)
			for notice in notices_accessor.notices:
				_log.debug(notice.replace('\n', '/').replace('\n', '/'))
			del notices_accessor.notices[:]
		# DB related exceptions
		except dbapi.Error as pg_exc:
			_log.error('query failed in RW connection')
			gmConnectionPool.log_pg_exception_details(pg_exc)
			for notice in notices_accessor.notices:
				_log.debug(notice.replace('\n', '/').replace('\n', '/'))
			del notices_accessor.notices[:]
			__safely_close_cursor_and_rollback_close_conn (
				curs_close,
				tx_rollback,
				conn_close
			)
			# privilege problem ?
			if pg_exc.pgcode == PG_error_codes.INSUFFICIENT_PRIVILEGE:
				details = 'Query: [%s]' % curs.query.decode(errors = 'replace').strip().strip('\n').strip().strip('\n')
				if curs.statusmessage != '':
					details = 'Status: %s\n%s' % (
						curs.statusmessage.strip().strip('\n').strip().strip('\n'),
						details
					)
				if pg_exc.pgerror is None:
					msg = '[%s]' % pg_exc.pgcode
				else:
					msg = '[%s]: %s' % (pg_exc.pgcode, pg_exc.pgerror)
				raise gmExceptions.AccessDenied (
					msg,
					source = 'PostgreSQL',
					code = pg_exc.pgcode,
					details = details
				)

			# other DB problem
			gmLog2.log_stack_trace()
			raise

		# other exception
		except Exception:
			_log.exception('error running query in RW connection')
			gmConnectionPool.log_cursor_state(curs)
			for notice in notices_accessor.notices:
				_log.debug(notice.replace('\n', '/').replace('\n', '/'))
			del notices_accessor.notices[:]
			gmLog2.log_stack_trace()
			__safely_close_cursor_and_rollback_close_conn (
				curs_close,
				tx_rollback,
				conn_close
			)
			raise

	data = None
	col_idx = None
	if return_data:
		try:
			data = curs.fetchall()
		except Exception:
			_log.exception('error fetching data from RW query')
			gmLog2.log_stack_trace()
			__safely_close_cursor_and_rollback_close_conn (
				curs_close,
				tx_rollback,
				conn_close
			)
			raise

		if get_col_idx:
			col_idx = get_col_indices(curs)
	curs_close()
	tx_commit()
	conn_close()
	return (data, col_idx)

#------------------------------------------------------------------------

Best,
Karsten

---

From: Adrian Klaver <[email-masked]>
Date: Sat, 7 Sep 2024 14:09:28 -0700

> And, yeah, the actual code is much more involved :-D

I see that.

The question is does the full code you show fail?

The code sample you show in your original post is doing something very 
different then what you show in your latest post. At this point I do not 
understand the exact problem we are dealing with.

---

From: Karsten Hilbert <[email-masked]>
Date: Sat, 7 Sep 2024 23:20:57 +0200

Am Sat, Sep 07, 2024 at 02:09:28PM -0700 schrieb Adrian Klaver:

> The code sample you show in your original post is doing something very different then
> what you show in your latest post. At this point I do not understand the exact problem
> we are dealing with.

We are not dealing with an unsolved problem. I had been
asking for advice  where to best place that .commit() call in
case I am overlooking benefits and drawbacks of choices.

The

	try:
		do something
	except:
		log something
	finally:
		.commit()

cadence is fairly Pythonic and elegant in that it ensures the
the .commit() will always be reached regardless of exceptions
being thrown or not and them being handled or not.

It is also insufficient because the .commit() itself may
elicit exceptions (from the database).

So there's choices:

Ugly:

	try:
		do something
	except:
		log something
	finally:
		try:
			.commit()
		except:
			log some more

Fair but not feeling quite safe:

	try:
		do something
		.commit()
	except:
		log something

Boring and repetitive and safe(r):

	try:
		do something
	except:
		log something
	try:
		.commit()
	except:
		log something

I eventually opted for the last version, except for factoring
out the second try: except: block.

Best,
Karsten

---

From: Adrian Klaver <[email-masked]>
Date: Sat, 7 Sep 2024 14:47:49 -0700

> being thrown or not and them being handled or not.

Elegant is nice, but correct is better:)

> elicit exceptions (from the database).

Yeah with Serializable that is part of the package:

"While PostgreSQL's Serializable transaction isolation level only allows 
concurrent transactions to commit if it can prove there is a serial 
order of execution that would produce the same effect ..."

> out the second try: except: block.

I'm not following, if you do that then you won't have a commit.

---

From: Karsten Hilbert <[email-masked]>
Date: Sat, 7 Sep 2024 23:59:41 +0200

> Yeah with Serializable that is part of the package:

No complaints :-)

> I'm not following, if you do that then you won't have a commit.

Perhaps my pseudo-code was to abbreviated.

	conn = psycopg2.connection()
	curs = conn.cursor()
	curs.execute(SQL)
	curs.close()
	conn.commit()
	conn.close()

Written more safely:

	conn = psycopg2.connection()
	curs = conn.cursor()
	try:
		curs.execute(SQL)
	except SOME_PG_EXCEPTION_VIA_PSYCOPG2:
		some_panicstricken_logging()
	curs.close()
	try:
		conn.commit()
	except SOME_PG_EXCEPTION_VIA_PSYCOPG2__SUCH_AS_SERIALIZATION_ERROR:
		some_more_of_the_panicstricken_logging()
	conn.close()

now factored out:

	def __commit_me_logging_errors(commit_func):
		try:
			commit_func()
		except SOME_PG_EXCEPTION_VIA_PSYCOPG2__SUCH_AS_SERIALIZATION_ERROR:
			some_more_of_the_panicstricken_logging()
		return

	conn = psycopg2.connection()
	curs = conn.cursor()
	try:
		curs.execute(SQL)
	except SOME_PG_EXCEPTION_VIA_PSYCOPG2:
		some_panicstricken_logging()
	curs.close()
	__commit_me_logging_errors(conn.commit)
	conn.close()

More clear ?

Karsten

---

From: Adrian Klaver <[email-masked]>
Date: Sat, 7 Sep 2024 15:09:28 -0700

> 	__commit_me_logging_errors(conn.commit)

Yes.