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:
About the difference when running prepare+execute in a separate
function: we just get the same stmt pointer address in this case
(vs. a different pointer address when running everything in the
same context). Thus stmt_name remains identical among successive
calls, stmt_name being just set as
spprintf(&S->stmt_name, 0, "pdo_pgsql_stmt_%08x", (unsigned int)stmt);
This explains why prepare() fails in the first case and succeed
in the other.
Anyway, here is a patch (against PHP_5_2 svn branch's head as of now)
using savepoints around PQprepare attempts so we DEALLOCATE + retry
without silently killing the current transaction, if/when the first
prepare fails with code 42P05.
Savepoints support started with pg 8.0 and I didn't ifdefed/autoconf
checked for this (will do if you ask); the patch will probably be
mangled by the bugrackers autowrapping (if so, please find a copy
at http://zouh.org/ben/various/pgsql_statement.c.diff
).
Index: pgsql_statement.c
===================================================================
--- pgsql_statement.c (revision 289910)
+++ pgsql_statement.c (working copy)
@@ -134,6 +134,14 @@
/* using a prepared statement */
if (!S->is_prepared) {
+ /* don't break the whole current transaction
when the first
+ * prepare tentative fails (happens when the
prepared statement
+ * already exists). ignore those SAVEPOINT
queries results because
+ * we don't care (may be outside
transaction?).
+ */
+ char buf[100]; /* stmt_name ==
"pdo_pgsql_cursor_%08x" */
+ snprintf(buf, sizeof(buf), "SAVEPOINT %s",
S->stmt_name);
+ PQexec(H->server, buf);
stmt_retry:
/* we deferred the prepare until now, because
we didn't
* know anything about the parameter types; now
we do */
@@ -153,12 +161,14 @@
/* 42P05 means that the
prepared statement already existed. this can happen if you use
* a connection pooling
software line pgpool which doesn't close the db-connection once
* php disconnects. if php dies
(no chance to run RSHUTDOWN) during execution it has no
- * chance to DEALLOCATE the
prepared statements it has created. so, if we hit a 42P05 we
- * deallocate it and retry ONCE
(thies 2005.12.15)
+ * chance to DEALLOCATE the
prepared statements it has created. Also happens if we tried
+ * to DEALLOCATE the same
statement name in an aborted transaction. so, if we hit a 42P05
+ * we deallocate it and retry
ONCE (thies 2005.12.15)
*/
if (!strcmp(sqlstate, "42P05"))
{
- char buf[100]; /*
stmt_name == "pdo_pgsql_cursor_%08x" */
PGresult *res;
+ snprintf(buf,
sizeof(buf), "ROLLBACK TO SAVEPOINT %s", S->stmt_name);
+ PQexec(H->server,
buf);
snprintf(buf,
sizeof(buf), "DEALLOCATE %s", S->stmt_name);
res = PQexec(H->server,
buf);
if (res) {
@@ -166,11 +176,15 @@
}
goto stmt_retry;
} else {
+ snprintf(buf,
sizeof(buf), "RELEASE SAVEPOINT %s", S->stmt_name);
+ PQexec(H->server,
buf);
pdo_pgsql_error_stmt(stmt, status, sqlstate);
return 0;
}
}
}
+ snprintf(buf, sizeof(buf), "RELEASE SAVEPOINT
%s", S->stmt_name);
+ PQexec(H->server, buf);
}
S->result = PQexecPrepared(H->server, S->stmt_name,
stmt->bound_params ?
Previous Comments:
------------------------------------------------------------------------
[2009-10-24 15:17:30] ben dot pineau at gmail dot com
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
------------------------------------------------------------------------
[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