rdbms: Issue a deprecation warning if errors are ignored

I532bc5201 added code to put the Database into an error state on error,
to prevent callers from catching and ignoring exceptions without rolling
back. But to avoid breaking everything relying on the ability to do so,
it didn't set the error state for certain types of errors.

To allow those broken callers to be cleaned up, log a deprecation
warning when we detect that someone has indeed ignored one of these
errors.

Bug: T189999
Change-Id: Ib7aca59639f30959e106fd4f1a1209e28bad2857

diff --git a/includes/libs/rdbms/database/Database.php b/includes/libs/rdbms/database/Database.php
index c924e4e..5b259bd 100644 (file)
--- a/includes/libs/rdbms/database/Database.php
+++ b/includes/libs/rdbms/database/Database.php
@@ -151,6 +151,11 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * @var Exception|null The last error that caused the status to become STATUS_TRX_ERROR
         */
        protected $trxStatusCause;
+       /**
+        * @var array|null If wasKnownStatementRollbackError() prevented trxStatus from being set,
+        *  the relevant details are stored here.
+        */
+       protected $trxStatusIgnoredCause;
        /**
         * Either 1 if a transaction is active or 0 otherwise.
         * The other Trx fields may not be meaningfull if this is 0.
@@ -1148,21 +1153,29 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                }
 
                if ( $ret === false ) {
-                       if ( $this->trxLevel && !$this->wasKnownStatementRollbackError() ) {
-                               # Either the query was aborted or all queries after BEGIN where aborted.
-                               if ( $this->explicitTrxActive() || $priorWritesPending ) {
-                                       # In the first case, the only options going forward are (a) ROLLBACK, or
-                                       # (b) ROLLBACK TO SAVEPOINT (if one was set). If the later case, the only
-                                       # option is ROLLBACK, since the snapshots would have been released.
-                                       $this->trxStatus = self::STATUS_TRX_ERROR;
-                                       $this->trxStatusCause =
-                                               $this->makeQueryException( $lastError, $lastErrno, $sql, $fname );
-                                       $tempIgnore = false; // cannot recover
+                       if ( $this->trxLevel ) {
+                               if ( !$this->wasKnownStatementRollbackError() ) {
+                                       # Either the query was aborted or all queries after BEGIN where aborted.
+                                       if ( $this->explicitTrxActive() || $priorWritesPending ) {
+                                               # In the first case, the only options going forward are (a) ROLLBACK, or
+                                               # (b) ROLLBACK TO SAVEPOINT (if one was set). If the later case, the only
+                                               # option is ROLLBACK, since the snapshots would have been released.
+                                               $this->trxStatus = self::STATUS_TRX_ERROR;
+                                               $this->trxStatusCause =
+                                                       $this->makeQueryException( $lastError, $lastErrno, $sql, $fname );
+                                               $tempIgnore = false; // cannot recover
+                                       } else {
+                                               # Nothing prior was there to lose from the transaction,
+                                               # so just roll it back.
+                                               $this->doRollback( __METHOD__ . " ($fname)" );
+                                               $this->trxStatus = self::STATUS_TRX_OK;
+                                       }
+                                       $this->trxStatusIgnoredCause = null;
                                } else {
-                                       # Nothing prior was there to lose from the transaction,
-                                       # so just roll it back.
-                                       $this->doRollback( __METHOD__ . " ($fname)" );
-                                       $this->trxStatus = self::STATUS_TRX_OK;
+                                       # We're ignoring an error that caused just the current query to be aborted.
+                                       # But log the cause so we can log a deprecation notice if a
+                                       # caller actually does ignore it.
+                                       $this->trxStatusIgnoredCause = [ $lastError, $lastErrno, $fname ];
                                }
                        }
 
@@ -1273,16 +1286,24 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * @throws DBTransactionStateError
         */
        private function assertTransactionStatus( $sql, $fname ) {
-               if (
-                       $this->trxStatus < self::STATUS_TRX_OK &&
-                       $this->getQueryVerb( $sql ) !== 'ROLLBACK' // transaction/savepoint
-               ) {
+               if ( $this->getQueryVerb( $sql ) === 'ROLLBACK' ) { // transaction/savepoint
+                       return;
+               }
+
+               if ( $this->trxStatus < self::STATUS_TRX_OK ) {
                        throw new DBTransactionStateError(
                                $this,
                                "Cannot execute query from $fname while transaction status is ERROR. ",
                                [],
                                $this->trxStatusCause
                        );
+               } elseif ( $this->trxStatus === self::STATUS_TRX_OK && $this->trxStatusIgnoredCause ) {
+                       list( $iLastError, $iLastErrno, $iFname ) = $this->trxStatusIgnoredCause;
+                       call_user_func( $this->deprecationLogger,
+                               "Caller from $fname ignored an error originally raised from $iFname: " .
+                               "[$iLastErrno] $iLastError"
+                       );
+                       $this->trxStatusIgnoredCause = null;
                }
        }
 
@@ -3472,6 +3493,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                } elseif ( $savepointId !== 'n/a' ) {
                        $this->doRollbackToSavepoint( $savepointId, $fname );
                        $this->trxStatus = self::STATUS_TRX_OK; // no exception; recovered
+                       $this->trxStatusIgnoredCause = null;
                }
 
                $this->affectedRowCount = 0; // for the sake of consistency
@@ -3514,6 +3536,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
 
                $this->doBegin( $fname );
                $this->trxStatus = self::STATUS_TRX_OK;
+               $this->trxStatusIgnoredCause = null;
                $this->trxAtomicCounter = 0;
                $this->trxTimestamp = microtime( true );
                $this->trxFname = $fname;

diff --git a/tests/phpunit/includes/db/DatabaseTestHelper.php b/tests/phpunit/includes/db/DatabaseTestHelper.php
index 36254f7..e9fc34f 100644 (file)
--- a/tests/phpunit/includes/db/DatabaseTestHelper.php
+++ b/tests/phpunit/includes/db/DatabaseTestHelper.php
@@ -53,6 +53,9 @@ class DatabaseTestHelper extends Database {
                $this->errorLogger = function ( Exception $e ) {
                        wfWarn( get_class( $e ) . ": {$e->getMessage()}" );
                };
+               $this->deprecationLogger = function ( $msg ) {
+                       wfWarn( $msg );
+               };
                $this->currentDomain = DatabaseDomain::newUnspecified();
                $this->open( 'localhost', 'testuser', 'password', 'testdb' );
        }

diff --git a/tests/phpunit/includes/libs/rdbms/database/DatabaseSQLTest.php b/tests/phpunit/includes/libs/rdbms/database/DatabaseSQLTest.php
index a57dce1..665e953 100644 (file)
--- a/tests/phpunit/includes/libs/rdbms/database/DatabaseSQLTest.php
+++ b/tests/phpunit/includes/libs/rdbms/database/DatabaseSQLTest.php
@@ -1546,7 +1546,7 @@ class DatabaseSQLTest extends PHPUnit\Framework\TestCase {
         * @covers \Wikimedia\Rdbms\Database::query
         */
        public function testImplicitTransactionRollback() {
-               $doError = function ( $wasKnown = true ) {
+               $doError = function () {
                        $this->database->forceNextQueryError( 666, 'Evilness' );
                        try {
                                $this->database->delete( 'error', '1', __CLASS__ . '::SomeCaller' );
@@ -1560,7 +1560,7 @@ class DatabaseSQLTest extends PHPUnit\Framework\TestCase {
 
                // Implicit transaction gets silently rolled back
                $this->database->begin( __METHOD__, Database::TRANSACTION_INTERNAL );
-               call_user_func( $doError, false );
+               call_user_func( $doError );
                $this->database->delete( 'x', [ 'field' => 1 ], __METHOD__ );
                $this->database->commit( __METHOD__, Database::FLUSHING_INTERNAL );
                // phpcs:ignore
@@ -1569,7 +1569,7 @@ class DatabaseSQLTest extends PHPUnit\Framework\TestCase {
                // ... unless there were prior writes
                $this->database->begin( __METHOD__, Database::TRANSACTION_INTERNAL );
                $this->database->delete( 'x', [ 'field' => 1 ], __METHOD__ );
-               call_user_func( $doError, false );
+               call_user_func( $doError );
                try {
                        $this->database->delete( 'x', [ 'field' => 1 ], __METHOD__ );
                        $this->fail( 'Expected exception not thrown' );
@@ -1580,6 +1580,71 @@ class DatabaseSQLTest extends PHPUnit\Framework\TestCase {
                $this->assertLastSql( 'BEGIN; DELETE FROM x WHERE field = \'1\'; DELETE FROM error WHERE 1; ROLLBACK' );
        }
 
+       /**
+        * @covers \Wikimedia\Rdbms\Database::query
+        */
+       public function testTransactionStatementRollbackIgnoring() {
+               $wrapper = TestingAccessWrapper::newFromObject( $this->database );
+               $warning = [];
+               $wrapper->deprecationLogger = function ( $msg ) use ( &$warning ) {
+                       $warning[] = $msg;
+               };
+
+               $doError = function () {
+                       $this->database->forceNextQueryError( 666, 'Evilness', [
+                               'wasKnownStatementRollbackError' => true,
+                       ] );
+                       try {
+                               $this->database->delete( 'error', '1', __CLASS__ . '::SomeCaller' );
+                               $this->fail( 'Expected exception not thrown' );
+                       } catch ( DBError $e ) {
+                               $this->assertSame( 666, $e->errno );
+                       }
+               };
+               $expectWarning = 'Caller from ' . __METHOD__ .
+                       ' ignored an error originally raised from ' . __CLASS__ . '::SomeCaller: [666] Evilness';
+
+               // Rollback doesn't raise a warning
+               $warning = [];
+               $this->database->startAtomic( __METHOD__ );
+               call_user_func( $doError );
+               $this->database->rollback( __METHOD__ );
+               $this->database->delete( 'x', [ 'field' => 1 ], __METHOD__ );
+               $this->assertSame( [], $warning );
+               // phpcs:ignore
+               $this->assertLastSql( 'BEGIN; DELETE FROM error WHERE 1; ROLLBACK; DELETE FROM x WHERE field = \'1\'' );
+
+               // cancelAtomic() doesn't raise a warning
+               $warning = [];
+               $this->database->begin( __METHOD__ );
+               $this->database->startAtomic( __METHOD__, Database::ATOMIC_CANCELABLE );
+               call_user_func( $doError );
+               $this->database->cancelAtomic( __METHOD__ );
+               $this->database->delete( 'x', [ 'field' => 1 ], __METHOD__ );
+               $this->database->commit( __METHOD__ );
+               $this->assertSame( [], $warning );
+               // phpcs:ignore
+               $this->assertLastSql( 'BEGIN; SAVEPOINT wikimedia_rdbms_atomic1; DELETE FROM error WHERE 1; ROLLBACK TO SAVEPOINT wikimedia_rdbms_atomic1; DELETE FROM x WHERE field = \'1\'; COMMIT' );
+
+               // Commit does raise a warning
+               $warning = [];
+               $this->database->begin( __METHOD__ );
+               call_user_func( $doError );
+               $this->database->commit( __METHOD__ );
+               $this->assertSame( [ $expectWarning ], $warning );
+               $this->assertLastSql( 'BEGIN; DELETE FROM error WHERE 1; COMMIT' );
+
+               // Deprecation only gets raised once
+               $warning = [];
+               $this->database->begin( __METHOD__ );
+               call_user_func( $doError );
+               $this->database->delete( 'x', [ 'field' => 1 ], __METHOD__ );
+               $this->database->commit( __METHOD__ );
+               $this->assertSame( [ $expectWarning ], $warning );
+               // phpcs:ignore
+               $this->assertLastSql( 'BEGIN; DELETE FROM error WHERE 1; DELETE FROM x WHERE field = \'1\'; COMMIT' );
+       }
+
        /**
         * @covers \Wikimedia\Rdbms\Database::close
         */