Re: Why must AUTOCOMMIT be ON to do txn control in plpgsql procedure?

On 8/8/19 11:35 AM, Bryn Llewellyn wrote:
> Please try the following.
> 
> Stop PostgreSQL with this:
> 
> pg_ctl -D /usr/local/var/postgres stop
> 
> Edit the file "/usr/local/var/postgres/postgresql.conf” and add these 
> lines at the end:
> 
> log_statement = 'all'
> log_directory = 'log'
> logging_collector = on
> 
> Then start  PostgreSQL with this:
> 
> pg_ctl -D /usr/local/var/postgres start
> 
> Then, in one terminal window, find the latest log file with this:
> 
> ls -l /usr/local/var/postgres/log/postgresql-*.log
> 
> Then, in a second terminal window, start psql and do these tests. By all 
> means, add your own.
> 
> -- Test 1.
> \set AUTOCOMMIT ON
> insert into t(n) values(42);
> 
> I see _only_ the “insert” in the log—in other words, no “commit”. (And 
> no “BEGIN” for that matter.) If it were the case the psql sends the 
> commit after every statement when AUTOCOMMIT is ON, then I’d see this in 
> the log. Yet the effect of the “insert” has indeed been committed. You 
> can see this by issuing “rollback” (you get the "there is no transaction 
> in progress” warning). And a subsequent “select” confirms that the 
> “insert” was committed.

Yeah if you do:
    log_min_messages = debug5
you see it:

postgres-2019-08-08 13:54:26.842 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0

postgres-2019-08-08 13:54:26.842 PDT-0LOG:  statement: insert into t 
values (1);

postgres-2019-08-08 13:54:26.843 PDT-38496DEBUG:  CommitTransaction(1) 
name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 
38496/1/0 (used)

> 
> My interpretation is that AUTOCOMMIT is a server-side phenomenon (but, 
> as we shall see, the client does know that this mode has been set).

Yes it is:
https://www.postgresql.org/docs/11/sql-begin.html:
"BEGIN initiates a transaction block, that is, all statements after a 
BEGIN command will be executed in a single transaction until an explicit 
COMMIT or ROLLBACK is given. By default (without BEGIN), PostgreSQL 
executes transactions in “autocommit” mode, that is, each statement is 
executed in its own transaction and a commit is implicitly performed at 
the end of the statement (if execution was successful, otherwise a 
rollback is done)."


Seems the 7.2 --> 7.3 --> 7.4 server setting for 
autocommit(change/change back) planted the idea in my head that it was not:

https://www.postgresql.org/docs/7.4/release-7-4.html
"The server-side autocommit setting was removed and reimplemented in 
client applications and languages. Server-side autocommit was causing 
too many problems with languages and applications that wanted to control 
their own autocommit behavior, so autocommit was removed from the server 
and added to individual client APIs as appropriate."



> 
> -- Test 2.
> \set AUTOCOMMIT OFF
> insert into t(n) values(42);
> rollback;
> 
> I see this in the log:
> 
> …LOG:  statement: BEGIN
> …LOG:  statement: insert into t(n) values(42);
> …LOG:  statement: rollback;
> 
> (I also see this when I do the test using Python on psycopg2 after doing 
> “my_session.set_session(autocommit=False)”. The “rollback” doesn’t draw 
> a warning. And, indeed, the effect of my “insert” has been undone, as 
> has been shown by a subsequent “select”.)
> 
> -- Test 3.
> \set AUTOCOMMIT OFF
> start transaction;
> insert into t(n) values(42);
> rollback;
> 
> I see this in the log:
> 
> …LOG:  statement: start transaction;
> …LOG:  statement: insert into t(n) values(42);
> …LOG:  statement: rollback;
> 
> Same outcome as with Test 2. Test 2 and Test 3 are consistent with the 
> hypothesis that it’s the client that issues the “BEGIN” before your 
> first  SQL command after setting AUTOCOMMIT to OFF. But it doesn’t 
> _prove_ the hypothesis. However, experts on this list have said that 
> this is how it works. And this is consistent with the fact that, when 
> AUTOCOMMIT is ON, I don’t see this in the log:

As shown before that is done in /src/bin/psql/common.c:
if (transaction_status == PQTRANS_IDLE &&
                 !pset.autocommit &&
                 !command_no_begin(query))
         {
                 results = PQexec(pset.db, "BEGIN");
Same thing in psycopg2 code, see my link in previous post.

> 
> BEGIN;
> insert into t(n) values(42);
> COMMIT;
> 
> If AUTOCOMMIT were entirely a client-side phenomenon, then you _would_ 
> have to see this to get the defined semantics.
> 
> In summary, my hypothesis is that AUTOCOMMIT is a server side 
> phenomenon. But, because to set it with a call from the client, the 
> client does know what mode you’re in and adds its own BEGIN before the 
> first SQL command that follows setting AUTOCOMMIT to ON.

You mean OFF. As you have shown autocommit is the default and you either 
turn it off by AUTOCOMMIT OFF in psql or equivalent in other clients or 
by starting an explicit transaction with BEGIN;

> 
> Test 4 is more elaborate. Please run the attached setup_for_test_4.sql, 
> and then do this by hand. But do read the definition of "p2()" 
>   carefully first. Then do this:
> 
> -- Test 4.
> \set AUTOCOMMIT ON
> do $$ begin raise notice 'txid at top level before "p2()" ..... %', 
> txid_current(); end $$;
> call p2();
> do $$ begin raise notice 'txid at top level after "p1()" ...... %', 
> txid_current(); end $$;
> select n from t order by n;
> 
> This is the output:
> 
> NOTICE:  txid at top level before "p2()" ..... 9478
> NOTICE:  txid in "p2()" at start ............. 9479
> NOTICE:  txid in "p2()" after "set txn"....... 9480, level = repeatable read
> NOTICE:  txid in "p2()" after "set txn"....... 9481, level = serializable
> NOTICE:  txid at top level after "p1()" ...... 9482
>   n
> ----
>   42
> 
> And this is what the log shows:
> 
> …LOG:  statement: do $$ begin raise notice 'txid at top level before 
> "p2()" ..... %', txid_current(); end $$;
> …LOG:  statement: call p2();
> …LOG:  statement: do $$ begin raise notice 'txid at top level after 
> "p1()" ...... %', txid_current(); end $$;
> …LOG:  statement: select n from t order by n;

Run with debug5 and you will see:
postgres-2019-08-08 14:09:46.171 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.171 PDT-0LOG:  statement: do $$ begin raise 
notice 'txid at top level before "p2()" ..... %', txid_current(); end $$;
postgres-2019-08-08 14:09:46.172 PDT-38501NOTICE:  txid at top level 
before "p2()" ..... 38501
postgres-2019-08-08 14:09:46.172 PDT-38501CONTEXT:  PL/pgSQL function 
inline_code_block line 1 at RAISE
postgres-2019-08-08 14:09:46.172 PDT-38501STATEMENT:  do $$ begin raise 
notice 'txid at top level before "p2()" ..... %', txid_current(); end $$;
postgres-2019-08-08 14:09:46.172 PDT-38501DEBUG:  CommitTransaction(1) 
name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 
38501/1/0
postgres-2019-08-08 14:09:46.172 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.172 PDT-0LOG:  statement: call p2();
postgres-2019-08-08 14:09:46.172 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.172 PDT-0CONTEXT:  PL/pgSQL function p2() 
line 8 at ROLLBACK
postgres-2019-08-08 14:09:46.172 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.172 PDT-0CONTEXT:  PL/pgSQL function p2() 
line 13 at ROLLBACK
postgres-2019-08-08 14:09:46.172 PDT-38503DEBUG:  CommitTransaction(1) 
name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 
38503/1/1
postgres-2019-08-08 14:09:46.172 PDT-38503CONTEXT:  PL/pgSQL function 
p2() line 18 at COMMIT
postgres-2019-08-08 14:09:46.197 PDT-0DEBUG:  StartTransaction(1) name:
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.197 PDT-0CONTEXT:  PL/pgSQL function p2() 
line 18 at COMMIT
postgres-2019-08-08 14:09:46.197 PDT-0NOTICE:  isolation level #1: 
repeatable read
postgres-2019-08-08 14:09:46.197 PDT-0CONTEXT:  PL/pgSQL function p2() 
line 20 at RAISE
postgres-2019-08-08 14:09:46.197 PDT-0STATEMENT:  call p2();
postgres-2019-08-08 14:09:46.197 PDT-0NOTICE:  isolation level #2: 
serializable
postgres-2019-08-08 14:09:46.197 PDT-0CONTEXT:  PL/pgSQL function p2() 
line 21 at RAISE
postgres-2019-08-08 14:09:46.197 PDT-0STATEMENT:  call p2();
postgres-2019-08-08 14:09:46.197 PDT-0DEBUG:  CommitTransaction(1) name: 
unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.198 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.198 PDT-0LOG:  statement: do $$ begin raise 
notice 'txid at top level after "p1()" ...... %', txid_current(); end $$;
postgres-2019-08-08 14:09:46.199 PDT-38504NOTICE:  txid at top level 
after "p1()" ...... 38504
postgres-2019-08-08 14:09:46.199 PDT-38504CONTEXT:  PL/pgSQL function 
inline_code_block line 1 at RAISE
postgres-2019-08-08 14:09:46.199 PDT-38504STATEMENT:  do $$ begin raise 
notice 'txid at top level after "p1()" ...... %', txid_current(); end $$;
postgres-2019-08-08 14:09:46.199 PDT-38504DEBUG:  CommitTransaction(1) 
name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 
38504/1/0
postgres-2019-08-08 14:09:46.774 PDT-0DEBUG:  StartTransaction(1) name: 
unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
postgres-2019-08-08 14:09:46.774 PDT-0LOG:  statement: select n from t 
order by n;
postgres-2019-08-08 14:09:46.774 PDT-0DEBUG:  CommitTransaction(1) name: 
unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0

> 
> Notice that there’s no visible “BEGIN” between my first “do" block and 
> the “call”. And (again) no visible “COMMIT” after the “call" finishes. 
> But the txid values show that “call” did indeed start a new txt, the 
> “rollback” in the proc ended it so that "set transaction isolation 
> level” in the proc can (implicitly) start a new txn. And so on. All this 
> is consistent with the hypothesis that there is no such thing as a 
> “nested transaction”. Rather, there’s just a series of non-overlapping 
> ordinary txns. The BLOG POST 
> <https://www.2ndquadrant.com/en/blog/postgresql-11-server-side-procedures-part-1/> that 
> I quoted with my first post on this topic explains that this is intended.
> 
> This is consistent with the hypothesis that AUTOCOMMIT is indeed a 
> server-side phenomenon and that, during the execution of a procedure, 
> its usual effect is suspended—and is resumed when the procedure 
> execution ends.

No that is not the case as the debug5 information shows. The DO's are in 
their own transactions. Each step in your code runs as a separate 
transaction so 'call p2()' is running in its own transaction and all is 
well.

> 
> I’ve said several times that my goal is to set the isolation level from 
> inside a proc so that the proc can own the entire logic for concurrent 
> txns that might violate a multi-row data-rule.
> 
> And I’ve said several times that I discovered that starting my proc with 
> “rollback” allows this—and that I've

This is only a problem if you do 'call p2()' inside another transaction:

test=# \set AUTOCOMMIT ON
test=# do $$ begin raise notice 'txid at top level before "p2()" ..... 
%', txid_current(); end $$;
NOTICE:  txid at top level before "p2()" ..... 38519
DO
test=# BEGIN;
BEGIN
test=# call p2();
ERROR:  invalid transaction termination
CONTEXT:  PL/pgSQL function p2() line 8 at ROLLBACK
test=# ROLLBACK;
ROLLBACK
test=# do $$ begin raise notice 'txid at top level after "p1()" ...... 
%', txid_current(); end $$;
NOTICE:  txid at top level after "p1()" ...... 38520
DO
test=# select n from t order by n;
  n
---
(0 rows)


> 
>   found no other way to meet my goal. I don’t understand, therefore, why 
> some people (but not you, Daniel!) who’ve responded to my questions say 
> that starting my proc with “rollback” is pointless.
> 
> I tried, earlier, to say “case closed”. I’ll say it again now.
> 
> On 08-Aug-2019, at 06:53, Daniel Verite <daniel@manitou-mail.org 
> <mailto:daniel@manitou-mail.org>> wrote:
> 
> Bryn Llewellyn wrote:
> 
>> B.t.w., I’m guessing that the “begin” SQL command that you see in the log
>> that I mentioned is actually issued by (some) clients—at least psql and
>> Python-on-psycopg2—as an explicit call from the client. In other words, it
>> isn’t the server that generates this. Does anyone know for sure how this
>> works?
> 
> Well, that's the point of Autocommit, and moreover it does nothing
> else. Maybe you're still confused about this.
> 
> * Autocommit off = the client automatically adds a "BEGIN" when
> it thinks a transaction must be started on behalf of the user.
> 
> * Autocommit on = the client does nothing.
> 
> The fact that "off" implies doing something and "on" implies not
> interfering is counterintuitive, but that's how it is.Autocommit is
> for compatibility with other databases. If it was only for Postgres, I
> guesss either it wouldn't exist in the first place or it should be
> called "AutoStartTransactionBlock" or something like that, because
> that's just what it really does.
> 
> Anyway, the server only know whether a BEGIN has been issued.
> It never knows or cares whether it has been added implicitly or explicitly,
> which is why it can be quite confusing to reason about server-side
> differences in terms of Autocommit, as you do in some of your previous
> messages.
> 
> It should be stressed that Autocommit is not a parameter of the
> session between Postgres and the SQL client, but rather it's a
> parameter of the session between the user and their SQL client.
> So when you're hypothesizing that a plpgsql block in a procedure
> would look at this parameter or change it temporarily (your
> points #2 and #5 in your analysis of p2's execution), you should
> see that it's impossible, because on the server-side, this parameter
> just does not exist.
> 
> 
> Best regards,
> -- 
> Daniel Vérité
> PostgreSQL-powered mailer: http://www.manitou-mail.org
> Twitter: @DanielVerite
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com