ID: 49985
Comment by: ben dot pineau at gmail dot com
Reported By: ben dot pineau at gmail dot com
Status: Open
Bug Type: PDO related
Operating System: Linux
PHP Version: 5.2.11
New Comment:
Look at the PostgreSQL logs above (running the provided test case
with log_statement='all' and log_min_messages='INFO'), keeping
in mind that:
- PostgreSQL automatically abort transactions when something fails.
- PostgreSQL does maintains prepared statements outside transaction
context. Prepared statements survive a rollback/abort, and last
for the duration of the current database session.
- It seems that when executed in another function/context than
PDO::beginTransaction, PDO tries to DEALLOCATE right after the
first transaction failure (vs. after the next BEGIN statement
when in same context).
Therefore we have the following flow:
BEGIN;
-- PDO successfully prepare the statement
PREPARE prep_statement_1 AS ...;
-- We execute a bogus statement that cause pg to automatically
-- abort the current transaction. PDO raise a proper exception
EXECUTE prep_statement_1;
-- This fails because we're in aborted transaction;
-- The prepared statement is thus left allocated.
DEALLOCATE prep_statement_1;
ROLLBACK;
-- And then we loop with
BEGIN;
-- This prep statement already exists (PDO failed to clean it)
-- so this fails and pg automatically abort this new transaction.
PREPARE prep_statement_1 AS ...;
-- Given the above failure, PDO tries again to clean up the
-- prepared stmt which will fail again.
-- Hence PDO raising a "current transaction is aborted" exception.
DEALLOCATE prep_statement_1;
ROLLBACK;
Surprisingly, when we call prepare() inline like this:
try {
$cnx->beginTransaction();
$stmt = $cnx->prepare($sql);
$stmt->execute();
instead of that :
function qexec(&$pdo, $sql) {
$stmt = $pdo->prepare($sql);
$stmt->execute();
}
try {
$cnx->beginTransaction();
qexec($cnx, $sql);
we do get a different (and preferable) behaviour:
BEGIN -> PREPARE -> EXECUTE -> ROLLBACK
-> BEGIN -> DEALLOCATE -> PREPARE -> EXECUTE -> ROLLBACK
-> BEGIN -> DEALLOCATE -> PREPARE -> EXECUTE -> ROLLBACK -> ...
vs.
BEGIN -> PREPARE -> EXECUTE -> DEALLOCATE -> ROLLBACK
-> BEGIN -> PREPARE (-> EXECUTE) -> DEALLOCATE -> ROLLBACK
-> BEGIN -> PREPARE (-> EXECUTE) -> DEALLOCATE -> ROLLBACK -> ...
Granted, preparing the same exact statement in loop (rather than
once then using varying parameters) is dumb, but...
PostgreSQL logs from the provided test case:
Oct 24 15:29:15 dev postgres[26864]: [5-1] LOG: statement: BEGIN
Oct 24 15:29:15 dev postgres[26864]: [6-1] LOG: execute
pdo_pgsql_stmt_01ef7698: INSERT INTO test (a) VALUES (1)
Oct 24 15:29:15 dev postgres[26864]: [7-1] ERROR: duplicate key value
violates unique constraint "test_pkey"
Oct 24 15:29:15 dev postgres[26864]: [7-2] STATEMENT: INSERT INTO test
(a) VALUES (1)
Oct 24 15:29:15 dev postgres[26864]: [8-1] LOG: statement: DEALLOCATE
pdo_pgsql_stmt_01ef7698
Oct 24 15:29:15 dev postgres[26864]: [9-1] ERROR: current transaction
is aborted, commands ignored until end of transaction block
Oct 24 15:29:15 dev postgres[26864]: [9-2] STATEMENT: DEALLOCATE
pdo_pgsql_stmt_01ef7698
Oct 24 15:29:15 dev postgres[26864]: [10-1] LOG: statement: ROLLBACK
Oct 24 15:29:15 dev postgres[26864]: [11-1] LOG: statement: BEGIN
Oct 24 15:29:15 dev postgres[26864]: [12-1] ERROR: prepared statement
"pdo_pgsql_stmt_01ef7698" already exists
Oct 24 15:29:15 dev postgres[26864]: [12-2] STATEMENT: INSERT INTO
test (a) VALUES (1)
Oct 24 15:29:15 dev postgres[26864]: [13-1] LOG: statement: DEALLOCATE
pdo_pgsql_stmt_01ef7698
Oct 24 15:29:15 dev postgres[26864]: [14-1] ERROR: current transaction
is aborted, commands ignored until end of transaction block
Oct 24 15:29:15 dev postgres[26864]: [14-2] STATEMENT: DEALLOCATE
pdo_pgsql_stmt_01ef7698
Oct 24 15:29:15 dev postgres[26864]: [15-1] ERROR: current transaction
is aborted, commands ignored until end of transaction block
Oct 24 15:29:15 dev postgres[26864]: [15-2] STATEMENT: INSERT INTO
test (a) VALUES (1)
Oct 24 15:29:15 dev postgres[26864]: [16-1] LOG: statement: ROLLBACK
Oct 24 15:29:15 dev postgres[26864]: [17-1] LOG: statement: BEGIN
Oct 24 15:29:15 dev postgres[26864]: [18-1] ERROR: prepared statement
"pdo_pgsql_stmt_01ef7698" already exists
Oct 24 15:29:15 dev postgres[26864]: [18-2] STATEMENT: INSERT INTO
test (a) VALUES (1)
Oct 24 15:29:15 dev postgres[26864]: [19-1] LOG: statement: DEALLOCATE
pdo_pgsql_stmt_01ef7698
Oct 24 15:29:15 dev postgres[26864]: [20-1] ERROR: current transaction
is aborted, commands ignored until end of transaction block
Oct 24 15:29:15 dev postgres[26864]: [20-2] STATEMENT: DEALLOCATE
pdo_pgsql_stmt_01ef7698
Oct 24 15:29:15 dev postgres[26864]: [21-1] ERROR: current transaction
is aborted, commands ignored until end of transaction block
Oct 24 15:29:15 dev postgres[26864]: [21-2] STATEMENT: INSERT INTO
test (a) VALUES (1)
Oct 24 15:29:15 dev postgres[26864]: [22-1] LOG: statement: ROLLBACK
Previous Comments:
------------------------------------------------------------------------
[2009-10-24 12:47:50] ben dot pineau at gmail dot com
Description:
------------
When prepar()ing a statement in a separate function, pdo_pgsql behaves
as if we hadn't rollbacked and started a new transaction.
But no such problem when either :
- we use another pdo driver (tested with sqlite)
- prepare() call is inlined in the same code block as beginTransaction
(rather than in a distinct function)
- the function contains a straigth "query()" instead of prepare() +
execute()
Reproduced with both php-5.2.6 and php-5.2.11, PostgreSQL 8.3.8.
Reproduce code:
---------------
/*
* CREATE TABLE test (a SERIAL PRIMARY KEY);
* INSERT INTO test VALUES (1);
*/
$cnx = new PDO('pgsql:dbname=testbase;host=localhost', 'postgres','');
$cnx->setAttribute(PDO::ATTR_ERRMODE, PDO::ERRMODE_EXCEPTION);
$sql = "INSERT INTO test (a) VALUES (1)";
function prepare_and_exec_query(&$pdo, $sql)
{
$stmt = $pdo->prepare($sql);
$stmt->execute();
}
for ($i = 0; $i < 3; $i++) {
try {
$cnx->beginTransaction();
prepare_and_exec_query($cnx, $sql);
$cnx->commit();
} catch (Exception $e) {
echo "Error: " . $e->getMessage() . "\n";
if (true === $cnx->rollback()) echo "rollbacked ok\n";
}
}
Expected result:
----------------
Error: SQLSTATE[23505]: Unique violation: 7 ERROR: duplicate key value
violates unique constraint "test_pkey"
rollbacked ok
Error: SQLSTATE[23505]: Unique violation: 7 ERROR: duplicate key value
violates unique constraint "test_pkey"
rollbacked ok
Error: SQLSTATE[23505]: Unique violation: 7 ERROR: duplicate key value
violates unique constraint "test_pkey"
rollbacked ok
Actual result:
--------------
Error: SQLSTATE[23505]: Unique violation: 7 ERROR: duplicate key value
violates unique constraint "test_pkey"
rollbacked ok
Error: SQLSTATE[25P02]: In failed sql transaction: 7 ERROR: current
transaction is aborted, commands ignored until end of transaction block
rollbacked ok
Error: SQLSTATE[25P02]: In failed sql transaction: 7 ERROR: current
transaction is aborted, commands ignored until end of transaction block
rollbacked ok
------------------------------------------------------------------------
--
Edit this bug report at http://bugs.php.net/?id=49985&edit=1
