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
