Thread: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
Hello,

We're facing in our ESQL/C written application a situation where a
commit'ed INSERT into a table is rolled back. I have here the ESQL/C
logging of the problem:

...
[1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion , reserv ,
id, ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection sisis
 
[1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
[1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
                                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[1471] [12.05.2020 15:48:50:478]: ecpg_execute on line 1637: query: insert into swd_auftrag ( setnr , aufnum , katkey ,
userid, seqcount ) values ( $1  , $2  , $3  , $4  , $5  ); with 5 parameter(s) on connection sisis
 
[1471] [12.05.2020 15:48:50:478]: ecpg_process_output on line 1637: OK: INSERT 0 1
[1471] [12.05.2020 15:48:50:478]: ECPGtrans on line 1124: action "commit"; connection "sisis"
[1471] [12.05.2020 15:48:51:500]: ECPGtrans on line 6716: action "commit"; connection "sisis"
[1471] [12.05.2020 15:48:51:501]: ECPGtrans on line 1222: action "rollback"; connection "sisis"
                                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
...

The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
and a later rollback (last line) seems to roll it back, at least the row
isn't in the table.

Any ideas? The connection is not set to AUTOCOMMIT.

    matthias

-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Adrian Klaver
Date:
On 5/12/20 7:53 AM, Matthias Apitz wrote:
> 
> Hello,
> 
> We're facing in our ESQL/C written application a situation where a
> commit'ed INSERT into a table is rolled back. I have here the ESQL/C
> logging of the problem:
> 
> ...
> [1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion , reserv
,id , ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection sisis
 
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
> [1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
>                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> [1471] [12.05.2020 15:48:50:478]: ecpg_execute on line 1637: query: insert into swd_auftrag ( setnr , aufnum , katkey
,userid , seqcount ) values ( $1  , $2  , $3  , $4  , $5  ); with 5 parameter(s) on connection sisis
 
> [1471] [12.05.2020 15:48:50:478]: ecpg_process_output on line 1637: OK: INSERT 0 1
> [1471] [12.05.2020 15:48:50:478]: ECPGtrans on line 1124: action "commit"; connection "sisis"
> [1471] [12.05.2020 15:48:51:500]: ECPGtrans on line 6716: action "commit"; connection "sisis"
> [1471] [12.05.2020 15:48:51:501]: ECPGtrans on line 1222: action "rollback"; connection "sisis"
>                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> ...
> 
> The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
> and a later rollback (last line) seems to roll it back, at least the row
> isn't in the table.
> 
> Any ideas? The connection is not set to AUTOCOMMIT.

Hard to tell without seeing the code.
Some things I see:

1) ECPGtrans on line 6716: action "commit"; connection "sisis" occurs twice.

2) ECPGtrans on line 1222: action "rollback"; connection "sisis" Comes 
from a line that precedes the INSERT you are interested in. Is there 
some sort of nesting going on?

> 
>     matthias
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Tom Lane
Date:
Matthias Apitz <guru@unixarea.de> writes:
> We're facing in our ESQL/C written application a situation where a
> commit'ed INSERT into a table is rolled back.

Kind of hard to believe ... is there any sign of distress in the
postmaster log?

> I have here the ESQL/C
> logging of the problem:

> ...
> [1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion , reserv
,id , ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection sisis 
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
> [1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
>                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

It's striking that this log shows a server ack of the INSERT, but no server
ack of the COMMIT.  Maybe that's just an oversight in the ESQL/C logging
logic, but I wonder what's actually getting to the server.  You might try
enabling log_statement = all so you can get a trace of what the server
thinks is happening.

            regards, tom lane



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
To answer also the question of Adrian Klaver:

The database in question has ~400 tables and the ESQL/C application has
for each table its own ESQL/C source file. It would be possible but a
nightmare to share the code and it's better to discuss the problem based
on the ESQL/c log file or I have to write some small example code to
reproduce the problem. The line numbers are relative to those source
files (and it's a pitty that the name of the source file is not logged,
onle the line numbers).

El día Dienstag, Mai 12, 2020 a las 11:54:40 -0400, Tom Lane escribió:

> Matthias Apitz <guru@unixarea.de> writes:
> > We're facing in our ESQL/C written application a situation where a
> > commit'ed INSERT into a table is rolled back.
> 
> Kind of hard to believe ... is there any sign of distress in the
> postmaster log?

No. Nothing which points to this.

> 
> > I have here the ESQL/C
> > logging of the problem:
> 
> > ...
> > [1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion ,
reserv, id , ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection
sisis
> > [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
> > [1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
> >                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> 
> It's striking that this log shows a server ack of the INSERT, but no server
> ack of the COMMIT.  Maybe that's just an oversight in the ESQL/C logging
> logic, but I wonder what's actually getting to the server.  You might try

I looked into the source and the ECPGtrans ... is logged before its
execution in the source interfaces/ecpg/ecpglib/misc.c and after the 
execution only an error condition would be logged. As there is only the
line of the COMMIT w/o anything else, it seems to be executed fine.

> enabling log_statement = all so you can get a trace of what the server
> thinks is happening.

I will do so, but would have to find a time window for this to not be
swamped by the logs.

Thanks for your reply to both, Adiran and Tom.

    matthias

-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Adrian Klaver
Date:
On 5/12/20 12:14 PM, Matthias Apitz wrote:
> 
> To answer also the question of Adrian Klaver:
> 
> The database in question has ~400 tables and the ESQL/C application has
> for each table its own ESQL/C source file. It would be possible but a
> nightmare to share the code and it's better to discuss the problem based
> on the ESQL/c log file or I have to write some small example code to
> reproduce the problem. The line numbers are relative to those source
> files (and it's a pitty that the name of the source file is not logged,
> onle the line numbers).

Yeah, but there is a one:one mapping of table:source file and you know 
the table, so you should be able to find the source at the line number. 
Or am I missing something?

Also, from OP did:

insert into swd_auftrag ..

COMMIT?

> 
> El día Dienstag, Mai 12, 2020 a las 11:54:40 -0400, Tom Lane escribió:
> 
>> Matthias Apitz <guru@unixarea.de> writes:
>>> We're facing in our ESQL/C written application a situation where a
>>> commit'ed INSERT into a table is rolled back.
>>
>> Kind of hard to believe ... is there any sign of distress in the
>> postmaster log?
> 
> No. Nothing which points to this.
> 
>>
>>> I have here the ESQL/C
>>> logging of the problem:
>>
>>> ...
>>> [1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion ,
reserv, id , ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection
sisis
>>> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
>>> [1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
>>>                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>>
>> It's striking that this log shows a server ack of the INSERT, but no server
>> ack of the COMMIT.  Maybe that's just an oversight in the ESQL/C logging
>> logic, but I wonder what's actually getting to the server.  You might try
> 
> I looked into the source and the ECPGtrans ... is logged before its
> execution in the source interfaces/ecpg/ecpglib/misc.c and after the
> execution only an error condition would be logged. As there is only the
> line of the COMMIT w/o anything else, it seems to be executed fine.
> 
>> enabling log_statement = all so you can get a trace of what the server
>> thinks is happening.
> 
> I will do so, but would have to find a time window for this to not be
> swamped by the logs.
> 
> Thanks for your reply to both, Adiran and Tom.
> 
>     matthias
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
El día Dienstag, Mai 12, 2020 a las 12:30:17 -0700, Adrian Klaver escribió:

> On 5/12/20 12:14 PM, Matthias Apitz wrote:
> > 
> > To answer also the question of Adrian Klaver:
> > 
> > The database in question has ~400 tables and the ESQL/C application has
> > for each table its own ESQL/C source file. It would be possible but a
> > nightmare to share the code and it's better to discuss the problem based
> > on the ESQL/c log file or I have to write some small example code to
> > reproduce the problem. The line numbers are relative to those source
> > files (and it's a pitty that the name of the source file is not logged,
> > onle the line numbers).
> 
> Yeah, but there is a one:one mapping of table:source file and you know the
> table, so you should be able to find the source at the line number. Or am I
> missing something?

Yes. The table here is swd_daten, the corresponding .pgc file is
swd_daten.pgc.

And in the log the line logged is:

[1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1

What I wanted to have is:


[1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744 of swd_daten.pgc: OK: INSERT 0 1

i.e. have added the file name to the line number as "on line 1744 of
swd_daten.pgc" to not always have to think, hey in which table we're
with this at the moment.

> Also, from OP did:
> 
> insert into swd_auftrag ..
> 
> COMMIT?

This question (if it was a question) I don't understand.

    matthias
-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Tom Lane
Date:
Matthias Apitz <guru@unixarea.de> writes:
> And in the log the line logged is:
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
> What I wanted to have is:
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744 of swd_daten.pgc: OK: INSERT 0 1
> i.e. have added the file name to the line number as "on line 1744 of
> swd_daten.pgc" to not always have to think, hey in which table we're
> with this at the moment.

Not an unreasonable suggestion, but it'd be more likely to happen if
you send in a patch ;-).

            regards, tom lane



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Adrian Klaver
Date:
On 5/12/20 4:52 PM, Matthias Apitz wrote:
> El día Dienstag, Mai 12, 2020 a las 12:30:17 -0700, Adrian Klaver escribió:
> 
>> On 5/12/20 12:14 PM, Matthias Apitz wrote:
>>>
>>> To answer also the question of Adrian Klaver:
>>>
>>> The database in question has ~400 tables and the ESQL/C application has
>>> for each table its own ESQL/C source file. It would be possible but a
>>> nightmare to share the code and it's better to discuss the problem based
>>> on the ESQL/c log file or I have to write some small example code to
>>> reproduce the problem. The line numbers are relative to those source
>>> files (and it's a pitty that the name of the source file is not logged,
>>> onle the line numbers).
>>
>> Yeah, but there is a one:one mapping of table:source file and you know the
>> table, so you should be able to find the source at the line number. Or am I
>> missing something?
> 
> Yes. The table here is swd_daten, the corresponding .pgc file is
> swd_daten.pgc.
> 
> And in the log the line logged is:
> 
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1

So what is happening before, during and after that line?

> 
> What I wanted to have is:
> 
> 
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744 of swd_daten.pgc: OK: INSERT 0 1
> 
> i.e. have added the file name to the line number as "on line 1744 of
> swd_daten.pgc" to not always have to think, hey in which table we're
> with this at the moment.
> 
>> Also, from OP did:
>>
>> insert into swd_auftrag ..
>>
>> COMMIT?
> 
> This question (if it was a question) I don't understand.

 From your original message:

"The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
and a later rollback (last line) seems to roll it back, at least the row
isn't in the table."

It was not clear to me whether:

"[1471] [12.05.2020 15:48:50:478]: ecpg_execute on line 1637: query: 
insert into swd_auftrag ( setnr , aufnum , katkey , userid , seqcount ) 
values ( $1  , $2  , $3  , $4  , $5  ); with 5 parameter(s) on 
connection sisis
[1471] [12.05.2020 15:48:50:478]: ecpg_process_output on line 1637: OK: 
INSERT 0 1"

also COMMITT(ed) or not?

> 
>     matthias
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
El día Dienstag, Mai 12, 2020 a las 08:01:15 -0400, Tom Lane escribió:

> Matthias Apitz <guru@unixarea.de> writes:
> > And in the log the line logged is:
> > [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
> > What I wanted to have is:
> > [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744 of swd_daten.pgc: OK: INSERT 0 1
> > i.e. have added the file name to the line number as "on line 1744 of
> > swd_daten.pgc" to not always have to think, hey in which table we're
> > with this at the moment.
> 
> Not an unreasonable suggestion, but it'd be more likely to happen if
> you send in a patch ;-).

I was already thinking somemonths ago in a change (and patch proposal).
The problem is, that the generated C-code for an ESQL/C statement looks
today like this:

{ ECPGdo(__LINE__, 0, 0, NULL, 0, ECPGst_normal, "insert into swd_daten ( katkey , aktion , reserv , id , ansetzung ,
nettodaten) values ( $1  , $2  , $3  , $4  , $5  , $6  )",
 
        ECPGt_long,&(new_value),(long)1,(long)1,sizeof(long),
        ECPGt_NO_INDICATOR, NULL , 0L, 0L, 0L,
        ECPGt_short,&(hrec_swd_daten.aktion),(long)1,(long)1,sizeof(short),
        ECPGt_NO_INDICATOR, NULL , 0L, 0L, 0L,
        ECPGt_char,(hrec_swd_daten.reserv),(long)2,(long)1,(2)*sizeof(char),
        ECPGt_NO_INDICATOR, NULL , 0L, 0L, 0L,
        ...
        ECPGt_char,(hrec_swd_daten.nettodaten),(long)SWD_DATEN_BUF_MAX,(long)1,(SWD_DATEN_BUF_MAX)*sizeof(char),
        ECPGt_NO_INDICATOR, NULL , 0L, 0L, 0L, ECPGt_EOIT, ECPGt_EORT);
#line 1745 "swd_daten.pgc"

if (sqlca.sqlcode == ECPG_NOT_FOUND) posSqlNotFound ( );
#line 1745 "swd_daten.pgc"

if (sqlca.sqlwarn[0] == 'W') posSqlWarning ( );
#line 1745 "swd_daten.pgc"

if (sqlca.sqlcode < 0) posSqlError ( );}

and should be expanded to:

{ ECPGdo(__LINE__, __FILE__, 0, 0, NULL, 0, ECPGst_normal, "insert ...

as the first argument to ECPGdo() is of type int we can not do a hack
like "__LINE__:"__FILE__ (i.e. concatenating line number and filename
into one string. We have to change the call interface function ECPGdo()
and add a string argument. This would make fail all older compiled
applications when the new shared lib having this call is installed.

Here I'm stuck with the idea.

    matthias

-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
El día Dienstag, Mai 12, 2020 a las 05:17:33 -0700, Adrian Klaver escribió:

> > > insert into swd_auftrag ..
> > > 
> > > COMMIT?
> > 
> > This question (if it was a question) I don't understand.
> 
> From your original message:
> 
> "The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
> and a later rollback (last line) seems to roll it back, at least the row
> isn't in the table."
> 
> It was not clear to me whether:
> 
> "[1471] [12.05.2020 15:48:50:478]: ecpg_execute on line 1637: query: insert
> into swd_auftrag ( setnr , aufnum , katkey , userid , seqcount ) values ( $1
> , $2  , $3  , $4  , $5  ); with 5 parameter(s) on connection sisis
> [1471] [12.05.2020 15:48:50:478]: ecpg_process_output on line 1637: OK:
> INSERT 0 1"
> 
> also COMMITT(ed) or not?

As I said in the original post of this thread:

[1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion , reserv ,
id, ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection sisis
 
[1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
[1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
...

i.e. the COMMIT is done in the same connection(!) right after the
INSERT. There is no other ESQL/C call logged (and done) between.

There is only no ACK from the ESQL/C layer about the COMMIT of
ECPGtrans, but this is a fault in the ESQL/C layer code, because the
ECPGtrans is logged before executing it and afterward if it's done OK no
message is generated.

    matthias


-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
I finally can reproduce the issue with a small ESQL/C written program
for that purpose. I could attach here the source, but even seeing its
printouts, all is perhaps clear:

the pgm does an INSERT, after this the row is there and can be seen
with SELECT; than I CLOSE a non existing cursor, which rolls back
the INSERTed data:

./embedded                                                            
tstint: 11073
INSERT done
SELECT done
SELECT: tstint: 11073 tstchar25: [hello]
CLOSE "foo_bar" done
SQL error: cursor "foo_bar" does not exist on line 57
SQL error: current transaction is aborted, commands ignored until end of transaction block on line 61
SELECT done
SELECT: tstint: 0 tstchar25: []
COMMIT done
SELECT done
SELECT: tstint: 0 tstchar25: []
ROLLBACK done
SELECT done
SELECT: tstint: 0 tstchar25: []

i.e. not the ROLLBACK removes the data, but the CLOSE of non existing
CURSOR. 

We have in our huge application server and its DB-layer places where we close
in advance a CURSOR to be sure that its CREATE will not cause any
problem because it is existing. Until yesterday we thought that the
raised -400 error, like

[1471] [12.05.2020 15:48:50:477]: ecpg_check_PQresult on line 939: bad response - ERROR:  cursor "adm_partab_seq" does
notexist
 
[1471] [12.05.2020 15:48:50:477]: raising sqlstate 34000 (sqlcode -400): cursor "adm_partab_seq" does not exist on line
939

could be overcome with the COMMIT without loosing the inserted data.

Main question: How can we ask the PostgreSQL server if a CURSOR 'foo_bar' 
(still) does exist or not?

Thanks

    matthias

-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Ravi Krishna
Date:
> the pgm does an INSERT, after this the row is there and can be seen
> with SELECT; than I CLOSE a non existing cursor, which rolls back
> the INSERTed data:


I have not done coding in ESQL/C in a long time, but shouldn't that be 
expected as any error should trigger a rollback.





Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Tom Lane
Date:
Matthias Apitz <guru@unixarea.de> writes:
> El día Dienstag, Mai 12, 2020 a las 08:01:15 -0400, Tom Lane escribió:
>> Not an unreasonable suggestion, but it'd be more likely to happen if
>> you send in a patch ;-).

> as the first argument to ECPGdo() is of type int we can not do a hack
> like "__LINE__:"__FILE__ (i.e. concatenating line number and filename
> into one string. We have to change the call interface function ECPGdo()
> and add a string argument.

Yeah, now that you mention that, this was discussed before.  We cannot
change the signature of ECPGdo as that would break existing client
binaries.  We could leave it alone (and unused by newer compilations)
if we add a new entry point, though.  "ECPGnewdo()", anybody?

            regards, tom lane



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Adrian Klaver
Date:
On 5/12/20 10:34 PM, Matthias Apitz wrote:
> El día Dienstag, Mai 12, 2020 a las 05:17:33 -0700, Adrian Klaver escribió:
> 
>>>> insert into swd_auftrag ..
>>>>
>>>> COMMIT?
>>>
>>> This question (if it was a question) I don't understand.
>>
>>  From your original message:
>>
>> "The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
>> and a later rollback (last line) seems to roll it back, at least the row
>> isn't in the table."
>>
>> It was not clear to me whether:
>>
>> "[1471] [12.05.2020 15:48:50:478]: ecpg_execute on line 1637: query: insert
>> into swd_auftrag ( setnr , aufnum , katkey , userid , seqcount ) values ( $1
>> , $2  , $3  , $4  , $5  ); with 5 parameter(s) on connection sisis
>> [1471] [12.05.2020 15:48:50:478]: ecpg_process_output on line 1637: OK:
>> INSERT 0 1"
>>
>> also COMMITT(ed) or not?
> 
> As I said in the original post of this thread:
> 
> [1471] [12.05.2020 15:48:50:476]: ecpg_execute on line 1744: query: insert into swd_daten ( katkey , aktion , reserv
,id , ansetzung , nettodaten ) values ( $1  , $2  , $3  , $4  , $5  , $6  ); with 6 parameter(s) on connection sisis
 
> [1471] [12.05.2020 15:48:50:476]: ecpg_process_output on line 1744: OK: INSERT 0 1
> [1471] [12.05.2020 15:48:50:477]: ECPGtrans on line 6716: action "commit"; connection "sisis"
> ...
> 
> i.e. the COMMIT is done in the same connection(!) right after the
> INSERT. There is no other ESQL/C call logged (and done) between.
> 
> There is only no ACK from the ESQL/C layer about the COMMIT of
> ECPGtrans, but this is a fault in the ESQL/C layer code, because the
> ECPGtrans is logged before executing it and afterward if it's done OK no
> message is generated.


In your original post you had:

"We're facing in our ESQL/C written application a situation where a
commit'ed INSERT into a table is rolled back. I have here the ESQL/C
logging of the problem:"
...

"The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
and a later rollback (last line) seems to roll it back, at least the row
isn't in the table.

Any ideas? The connection is not set to AUTOCOMMIT."

You then included a sequence of log messages that ended with a 
"rollback". Within that sequence was the INSERT to swd_auftrag. It 
seemed reasonable to ask whether that INSERT rolled back also. That is 
if the intent of this thread is to figure out why the INSERT was rolled 
back. If the thread has changed to fixing ESQL/C logging then ignore the 
above.

> 
>     matthias
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Matthias Apitz
Date:
El día Mittwoch, Mai 13, 2020 a las 08:15:40 -0700, Adrian Klaver escribió:

> In your original post you had:
> 
> "We're facing in our ESQL/C written application a situation where a
> commit'ed INSERT into a table is rolled back. I have here the ESQL/C
> logging of the problem:"
> ...
> 
> "The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
> and a later rollback (last line) seems to roll it back, at least the row
> isn't in the table.
> 
> Any ideas? The connection is not set to AUTOCOMMIT."
> 
> You then included a sequence of log messages that ended with a "rollback".
> Within that sequence was the INSERT to swd_auftrag. It seemed reasonable to
> ask whether that INSERT rolled back also. That is if the intent of this
> thread is to figure out why the INSERT was rolled back. If the thread has
> changed to fixing ESQL/C logging then ignore the above.

The intention of my original post was to understand why the INSERT was
rolled back. I do know this now: because I overlooked that the cancel of
the transaction was done after the INSERT by CLOSE of a non open CURSOR.

We're fixing this now already by checking in pg_cursors if the CURSOR is
still open before issue the CLOSE. I don't know how expensive this is,
but it seems that there is no other option to check this.

The side step about fixing ESQL/C logging should be handled in another
thread.

Thanks all for your help

    matthias

-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Re: ESQL/C: a ROLLBACK rolls back a COMMITED transaction

From
Adrian Klaver
Date:
On 5/13/20 11:16 AM, Matthias Apitz wrote:
> El día Mittwoch, Mai 13, 2020 a las 08:15:40 -0700, Adrian Klaver escribió:
> 
>> In your original post you had:
>>
>> "We're facing in our ESQL/C written application a situation where a
>> commit'ed INSERT into a table is rolled back. I have here the ESQL/C
>> logging of the problem:"
>> ...
>>
>> "The INSERT of 1 row into table swd_daten was OK and commit'ed (marked line)
>> and a later rollback (last line) seems to roll it back, at least the row
>> isn't in the table.
>>
>> Any ideas? The connection is not set to AUTOCOMMIT."
>>
>> You then included a sequence of log messages that ended with a "rollback".
>> Within that sequence was the INSERT to swd_auftrag. It seemed reasonable to
>> ask whether that INSERT rolled back also. That is if the intent of this
>> thread is to figure out why the INSERT was rolled back. If the thread has
>> changed to fixing ESQL/C logging then ignore the above.
> 
> The intention of my original post was to understand why the INSERT was
> rolled back. I do know this now: because I overlooked that the cancel of
> the transaction was done after the INSERT by CLOSE of a non open CURSOR.

Huh, this message:

https://www.postgresql.org/message-id/20200513101301.GC26063%40sh4-5.1blu.de

got delayed in the ether somewhere. It showed up recently, so now I see 
the issue.

> 
> We're fixing this now already by checking in pg_cursors if the CURSOR is
> still open before issue the CLOSE. I don't know how expensive this is,
> but it seems that there is no other option to check this.
> 
> The side step about fixing ESQL/C logging should be handled in another
> thread.
> 
> Thanks all for your help
> 
>     matthias
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com