| Subject: | Apparent transaction state corruption leads to silent failures |
I expect the following two pieces of code to give the same result. One is SQL, fed directly to
Postgres using the psql command-line tool, and the other is Perl code using DBI.
In the code, note that I'm intentionally sending statements that I know will fail. This seems
to be necessary to reproduce the bug.
First, the SQL:
DROP TABLE t1;
DROP TABLE t2;
CREATE TABLE t2
(
id INT PRIMARY KEY
);
CREATE TABLE t1
(
id INT PRIMARY KEY,
t2_id INT REFERENCES t2 (id) INITIALLY DEFERRED
);
BEGIN;
INSERT INTO t2 (id) VALUES (1);
INSERT INTO t1 (id, t2_id) VALUES (1, 1);
COMMIT;
BEGIN;
INSERT INTO t1 (id, t2_id) VALUES (2, 1);
INSERT INTO t1 (id, t2_id) VALUES (3, 2);
COMMIT;
BEGIN;
INSERT INTO t1 (id, t2_id) VALUES (2, 1);
ROLLBACK;
SELECT * FROM t1;
The final SELECT should find only one row:
id | t2_id
----+-------
1 | 1
It works as expected. Now the Perl code:
use DBI;
my $dbh = DBI->connect('dbi:Pg:dbname=test', 'postgres', '...',
{ PrintError => 1, RaiseError => 0 });
$dbh->do('CREATE TABLE t2
(
id INT PRIMARY KEY
)');
$dbh->do('CREATE TABLE t1
(
id INT PRIMARY KEY,
t2_id INT REFERENCES t2 (id) INITIALLY DEFERRED
)');
$dbh->do('DELETE FROM t1');
$dbh->do('DELETE FROM t2');
$dbh->begin_work;
$dbh->do('INSERT INTO t2 (id) VALUES (1)');
$dbh->do('INSERT INTO t1 (id, t2_id) VALUES (1, 1)');
$dbh->commit;
$dbh->begin_work;
$dbh->do('INSERT INTO t1 (id, t2_id) VALUES (2, 1)');
$dbh->do('INSERT INTO t1 (id, t2_id) VALUES (3, 2)');
$dbh->commit;
$dbh->begin_work;
$dbh->do('INSERT INTO t1 (id, t2_id) VALUES (2, 1)');
$dbh->rollback; # XXX: This doesn't seem to work
my $sth = $dbh->prepare('SELECT * FROM t1');
$sth->execute;
while(my $row = $sth->fetchrow_hashref)
{
print "$row->{'id'}, $row->{'t2_id'}\n";
}
$dbh->do('DROP TABLE t1');
$dbh->do('DROP TABLE t2');
$dbh->disconnect;
Unfortunately, it prints this:
1, 1
2, 1
Basically, the call to rollback() appears to fail. The row inserted is not rolled back but
remains visible. In fact, if you remove the DROP TABLE statements from the end of the Perl
script, row id 2 in the t1 table stays in the database even after the script exits.
The calls to begin_work() and rollback() around the final insert both give affirmative return
values, but actually do nothing. Here's that code extracted, but with fatal errors attached:
$dbh->begin_work or die "Could not begin work\n";
$dbh->do('INSERT INTO t1 (id, t2_id) VALUES (2, 1)');
$dbh->rollback or die "Could not roll back\n";
It sails right through that code without dying, but it doesn't actually begin and then roll back
a transaction. Here's the DBI trace of that section of code:
-> begin_work for DBD::Pg::db (DBI::db=HASH(0x1833704)~0x1869bf0)
1 -> FETCH for DBD::Pg::db (DBI::db=HASH(0x1869bf0)~INNER 'AutoCommit')
dbdpg: dbd_db_FETCH (AutoCommit) dbh=25449128
1 <- FETCH= 1 at /usr/local/lib/perl5/site_perl/5.8.8/darwin-2level/DBI.pm
line 1655 via new.pl line 34
1 -> STORE for DBD::Pg::db (DBI::db=HASH(0x1869bf0)~INNER 'AutoCommit' 0)
dbdpg: dbd_db_STORE (AutoCommit) (0)
1 <- STORE= 1 at /usr/local/lib/perl5/site_perl/5.8.8/darwin-2level/DBI.pm
line 1657 via new.pl line 34
1 -> STORE for DBD::Pg::db (DBI::db=HASH(0x1869bf0)~INNER 'BegunWork' 1)
dbdpg: dbd_db_STORE (BegunWork) (1)
STORE DBI::db=HASH(0x1869bf0) 'BegunWork' => 1
1 <- STORE= 1 at /usr/local/lib/perl5/site_perl/5.8.8/darwin-2level/DBI.pm
line 1658 via new.pl line 34
<- begin_work= 1 at new.pl line 34
-> do for DBD::Pg::db (DBI::db=HASH(0x1833704)~0x1869bf0 'INSERT INTO t1
(id, t2_id) VALUES (2, 1)')
dbdpg: pg_quickexec (INSERT INTO t1 (id, t2_id) VALUES (2, 1))
dbdpg: _sqlstate
<- do= 1 at new.pl line 36
-> rollback for DBD::Pg::db (DBI::db=HASH(0x1833704)~0x1869bf0)
dbdpg: dbd_db_rollback (AutoCommit is 0) (BegunWork is 1)
dbdpg: dbd_db_txn_status
dbdpg: Warning: invalid done_begin turned off
<- rollback= 1 at new.pl line 38
Martin J. Evans had this to say:
---
I've never used Postgres under Perl but that:
Show quoted text
> dbdpg: Warning: invalid done_begin turned off
> <- rollback= 1 at new.pl line 38
looked suspicious. From the Postgres code:
if (PQTRANS_IDLE == tstatus) { /* Not in a transact
if (imp_dbh->done_begin) {
/* We think we ARE in a tranaction but we really are
not */
- if (dbis->debug >= 1) { PerlIO_printf(DBILOGFP,
"Warning: invalid done_begin turned off\n"); }
+ if (dbis->debug >= 3) { PerlIO_printf(DBILOGFP,
"Warning: invalid done_begin turned off\n"); }
imp_dbh->done_begin = 0;ion */
I draw your attention to the comment "We think we ARE in a tranaction but we really are not".
The above code seemed to end up being put in an ifdef PG74 later and then even later in a
ifdef PGLIBVERSION >= 70400. So, I'd suggest it may be Postgres library version related.
---
I'm using Pg 8.1.3, Perl 5.8.8, DBI 1.50, and DBD::Pg 1.47.