Re: [psycopg] Changing set_session implementation

Поиск
Список
Период
Сортировка
Искать
От
Karsten Hilbert
Тема
Re: [psycopg] Changing set_session implementation
Дата
Msg-id
20170803210818.xyf6ike2uqmckeav@hermes.hilbert.loc
Ответ на
Список
Дерево обсуждения
[psycopg] Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
[psycopg] problem with readonly/autocommit, was: Changing set_sessionimplementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
[psycopg] 2.7.2 still problem with readonly/autocommit, was: Changingset_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] 2.7.2 still problem with readonly/autocommit, was:Changing set_session implementation Karsten Hilbert <Karsten.Hilbert@gmx.net>
Re: [psycopg] Changing set_session implementation Christophe Pettus <xof@thebuild.com>
Re: [psycopg] Changing set_session implementation Daniele Varrazzo <daniele.varrazzo@gmail.com>
Re: [psycopg] Changing set_session implementation Christophe Pettus <xof@thebuild.com>
Regarding the below problem with readwrite autocommit
connections in default-readonly databases I have whittled
down a test case to the following (attached):

	db = u'gnumed_v20'		# a database configured "alter database %s set default_transaction_read_only to on"
	user = 'gm-dbo'			# a user with CREATE DATABASE powers

	cmd_def_tx_ro = "SELECT upper(source), name, upper(setting) FROM pg_settings WHERE name = 'default_transaction_read_only'"
	cmd_create_db = "create database %s_copy template %s" % (db, db)

	import sys
	import psycopg2

	conn = psycopg2.connect(dbname = db, user = user)
	print 'conn:', conn
	print 'readonly:', conn.readonly
	print 'autocommit:', conn.autocommit
	conn.autocommit = False
	conn.readonly = False							# <========== comment out for success
	conn.autocommit = True
	print 'autocommit now:', conn.autocommit
	conn.readonly = False
	print 'readonly now:', conn.readonly
	curs = conn.cursor()
	curs.execute(cmd_def_tx_ro)
	print 'should show DEFAULT_TRANSACTION_READ_ONLY set to ON'
	print curs.fetchall()
	curs.close()
	conn.commit()
	print 'the following CREATE DATABASE should fail'
	curs = conn.cursor()
	try:
		curs.execute(cmd_create_db)
	except psycopg2.InternalError as ex:
		print 'SQL failed:'
		print ex

	print 'shutting down'

	curs.close()
	conn.rollback()
	conn.close()

which shows on the console:

	ncq@hermes:~$ python x-test-default_ro.py
	conn: 
	readonly: None
	autocommit: False
	autocommit now: True
	readonly now: False
	should show DEFAULT_TRANSACTION_READ_ONLY set to ON
	[('DATABASE', 'default_transaction_read_only', 'ON')]
	the following CREATE DATABASE should fail
	SQL failed:
	cannot execute CREATE DATABASE in a read-only transaction

	shutting down

The PostgreSQL log shows:

	2017-08-03 21:00:19 GMT LOG:  00000: Verbindung empfangen: Host=[local]
	2017-08-03 21:00:19 GMT ORT:  BackendInitialize, postmaster.c:4135
	2017-08-03 21:00:19 GMT LOG:  00000: Verbindung autorisiert: Benutzer=gm-dbo Datenbank=gnumed_v20
	2017-08-03 21:00:19 GMT ORT:  PerformAuthentication, postinit.c:272
	2017-08-03 21:00:19 GMT LOG:  00000: statement: SELECT upper(source), name, upper(setting) FROM pg_settings WHERE name = 'default_transaction_read_only'
	2017-08-03 21:00:19 GMT LOCATION:  exec_simple_query, postgres.c:935
	2017-08-03 21:00:19 GMT LOG:  00000: statement: create database gnumed_v20_copy template gnumed_v20
	2017-08-03 21:00:19 GMT LOCATION:  exec_simple_query, postgres.c:935
	2017-08-03 21:00:19 GMT ERROR:  25006: cannot execute CREATE DATABASE in a read-only transaction
	2017-08-03 21:00:19 GMT LOCATION:  PreventCommandIfReadOnly, utility.c:236
	2017-08-03 21:00:19 GMT STATEMENT:  create database gnumed_v20_copy template gnumed_v20
	2017-08-03 21:00:19 GMT LOG:  00000: disconnection: session time: 0:00:00.007 user=gm-dbo database=gnumed_v20 host=[local]
	2017-08-03 21:00:19 GMT LOCATION:  log_disconnections, postgres.c:4501

Commenting out the marked line makes it work and the log shows:

	2017-08-03 21:01:24 GMT LOG:  00000: Verbindung empfangen: Host=[local]
	2017-08-03 21:01:24 GMT ORT:  BackendInitialize, postmaster.c:4135
	2017-08-03 21:01:24 GMT LOG:  00000: Verbindung autorisiert: Benutzer=postgres Datenbank=postgres
	2017-08-03 21:01:24 GMT ORT:  PerformAuthentication, postinit.c:272
	2017-08-03 21:01:25 GMT LOG:  00000: Anweisung: drop database gnumed_v20_copy ;
	2017-08-03 21:01:25 GMT ORT:  exec_simple_query, postgres.c:935
	2017-08-03 21:01:26 GMT LOG:  00000: Verbindungsende: Sitzungszeit: 0:00:02.324 Benutzer=postgres Datenbank=postgres Host=[local]
	2017-08-03 21:01:26 GMT ORT:  log_disconnections, postgres.c:4501
	2017-08-03 21:01:33 GMT LOG:  00000: Verbindung empfangen: Host=[local]
	2017-08-03 21:01:33 GMT ORT:  BackendInitialize, postmaster.c:4135
	2017-08-03 21:01:33 GMT LOG:  00000: Verbindung autorisiert: Benutzer=gm-dbo Datenbank=gnumed_v20
	2017-08-03 21:01:33 GMT ORT:  PerformAuthentication, postinit.c:272
	2017-08-03 21:01:33 GMT LOG:  00000: statement: SET default_transaction_read_only TO 'off'
	2017-08-03 21:01:33 GMT LOCATION:  exec_simple_query, postgres.c:935
	2017-08-03 21:01:33 GMT LOG:  00000: statement: SELECT upper(source), name, upper(setting) FROM pg_settings WHERE name = 'default_transaction_read_only'
	2017-08-03 21:01:33 GMT LOCATION:  exec_simple_query, postgres.c:935
	2017-08-03 21:01:33 GMT LOG:  00000: statement: create database gnumed_v20_copy template gnumed_v20
	2017-08-03 21:01:33 GMT LOCATION:  exec_simple_query, postgres.c:935
	2017-08-03 21:01:37 GMT LOG:  00000: duration: 3447.360 ms
	2017-08-03 21:01:37 GMT LOCATION:  exec_simple_query, postgres.c:1164
	2017-08-03 21:01:37 GMT LOG:  00000: disconnection: session time: 0:00:03.454 user=gm-dbo database=gnumed_v20 host=[local]
	2017-08-03 21:01:37 GMT LOCATION:  log_disconnections, postgres.c:4501

So, under some circumstances psycopg2 does send the 

	2017-08-03 21:01:33 GMT LOG:  00000: statement: SET default_transaction_read_only TO 'off'

while sometimes it does not, despite both times being in
autocommit=True and readonly=False when the "create database"
is sent.

Of course, the

	conn.autocommit = False
	conn.readonly = False							# <========== comment out for success
	conn.autocommit = True
	conn.readonly = False

seems redundant but that is the relevant sequence of events
condensed from a larger body of code. Redundant as it may
seem it should still work, no ?

I am not sure I fully grok what is happening...

Thanks for insights,
Karsten


On Wed, Aug 02, 2017 at 09:38:21PM +0200, Karsten Hilbert wrote:

> On Wed, Aug 02, 2017 at 03:10:15PM +0100, Daniele Varrazzo wrote:
> 
> > If you want to be absolutely sure about what the adapter does I
> > suggest you to enable statements log on the server and check what
> > statements are produced by psycopg. If you find any behaviour
> > inconsistent with what documented please let us know.
> 
> One thing I noticed is that it seems pycopg2 does not send a
> "set default_transaction_read_only to off" when
> 
> - a database had been created and ALTERed to permanently
>   be "default_transaction_read_only to ON"
> 
> - a transaction had been opened on a connection with
> 
> 		BEGIN ISOLATION LEVEL SERIALIZABLE READ WRITE
> 
>   in order to run various comments (such as setting
>   default client timezone)
> 
> - that transaction had been committed
> 
> - the connection is switched to autocommit=true
> 	(for running DROP DATABASE et al)
> 
> 		2017-08-02 19:18:13 GMT LOG:  00000: Verbindung empfangen: Host=[local]
> 		2017-08-02 19:18:13 GMT ORT:  BackendInitialize, postmaster.c:4135
> 		2017-08-02 19:18:13 GMT LOG:  00000: Verbindung autorisiert: Benutzer=postgres Datenbank=gnumed_v20
> 		2017-08-02 19:18:13 GMT ORT:  PerformAuthentication, postinit.c:272
> 		2017-08-02 19:18:13 GMT LOG:  00000: statement: BEGIN ISOLATION LEVEL SERIALIZABLE READ WRITE
> 		2017-08-02 19:18:13 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:13 GMT LOG:  00000: statement: set timezone to 'Europe/Madrid'
> 		2017-08-02 19:18:13 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:13 GMT LOG:  00000: statement: COMMIT
> 		2017-08-02 19:18:13 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:13 GMT LOG:  00000: statement: BEGIN ISOLATION LEVEL SERIALIZABLE READ WRITE
> 		2017-08-02 19:18:13 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:13 GMT LOG:  00000: statement: set lc_messages to 'C'
> 		2017-08-02 19:18:13 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:13 GMT LOG:  00000: statement: select md5(gm.concat_table_structure(20::integer)) as md5
> 		2017-08-02 19:18:13 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:14 GMT LOG:  00000: duration: 1156.407 ms
> 		2017-08-02 19:18:14 GMT LOCATION:  exec_simple_query, postgres.c:1164
> 		2017-08-02 19:18:14 GMT LOG:  00000: statement: SELECT datname FROM pg_database WHERE datname='gnumed_v21'
> 		2017-08-02 19:18:14 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:14 GMT LOG:  00000: statement: COMMIT
> 		2017-08-02 19:18:14 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:14 GMT LOG:  00000: statement: DROP DATABASE "gnumed_v21"
> 		2017-08-02 19:18:14 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:14 GMT ERROR:  25006: cannot execute DROP DATABASE in a read-only transaction
> 		2017-08-02 19:18:14 GMT LOCATION:  PreventCommandIfReadOnly, utility.c:236
> 		2017-08-02 19:18:14 GMT STATEMENT:  DROP DATABASE "gnumed_v21"
> 		2017-08-02 19:18:14 GMT LOG:  00000: statement: SET default_transaction_isolation TO DEFAULT
> 		2017-08-02 19:18:14 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:14 GMT LOG:  00000: statement: SET default_transaction_read_only TO DEFAULT
> 		2017-08-02 19:18:14 GMT LOCATION:  exec_simple_query, postgres.c:935
> 		2017-08-02 19:18:14 GMT LOG:  00000: disconnection: session time: 0:00:01.183 user=postgres database=gnumed_v20 host=[local]
> 		2017-08-02 19:18:14 GMT LOCATION:  log_disconnections, postgres.c:4501
> 
> The only other indirect proof I have for this is: if I insert
> a manual "set default_transaction_read_only to off" right
> before the "drop database ..." (but after having been
> switched to autocommit) it works as expected.
> 
> If the connection has NOT been used for any other
> transactions (that is, if it is switched to autocommit=true
> and then to readonly=off) it also works as expected -
> psycopg2 sends a "set default_transaction_read_only to off".
> 
> Karsten
> -- 
> GPG key ID E4071346 @ eu.pool.sks-keyservers.net
> E167 67FD A291 2BEA 73BD  4537 78B9 A9F9 E407 1346
> 
> 
> -- 
> Sent via psycopg mailing list (psycopg@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/psycopg

-- 
GPG key ID E4071346 @ eu.pool.sks-keyservers.net
E167 67FD A291 2BEA 73BD  4537 78B9 A9F9 E407 1346
В списке psycopg по дате отправления
От: Daniele Varrazzo
Дата:
От: Jim Nasby
Дата:
FAQ