rdbms: improve query logging logic in Database
[lhc/web/wiklou.git] / includes / libs / rdbms / database / Database.php
index 2739205..a55d682 100644 (file)
@@ -71,12 +71,13 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
        /** @var int New Database instance will already be connected when returned */
        const NEW_CONNECTED = 1;
 
-       /** @var string SQL query */
-       protected $lastQuery = '';
+       /** @var string The last SQL query attempted */
+       private $lastQuery = '';
        /** @var float|bool UNIX timestamp of last write query */
-       protected $lastWriteTime = false;
+       private $lastWriteTime = false;
        /** @var string|bool */
-       protected $phpError = false;
+       private $lastPhpError = false;
+
        /** @var string Server that this instance is currently connected to */
        protected $server;
        /** @var string User that this instance is currently connected under the name of */
@@ -104,7 +105,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
        /** @var callable Deprecation logging callback */
        protected $deprecationLogger;
 
-       /** @var resource|null Database connection */
+       /** @var object|resource|null Database connection */
        protected $conn = null;
        /** @var bool */
        protected $opened = false;
@@ -874,7 +875,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * Set a custom error handler for logging errors during database connection
         */
        protected function installErrorHandler() {
-               $this->phpError = false;
+               $this->lastPhpError = false;
                $this->htmlErrors = ini_set( 'html_errors', '0' );
                set_error_handler( [ $this, 'connectionErrorLogger' ] );
        }
@@ -897,8 +898,8 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * @return string|bool Last PHP error for this DB (typically connection errors)
         */
        protected function getLastPHPError() {
-               if ( $this->phpError ) {
-                       $error = preg_replace( '!\[<a.*</a>\]!', '', $this->phpError );
+               if ( $this->lastPhpError ) {
+                       $error = preg_replace( '!\[<a.*</a>\]!', '', $this->lastPhpError );
                        $error = preg_replace( '!^.*?:\s?(.*)$!', '$1', $error );
 
                        return $error;
@@ -915,7 +916,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * @param string $errstr
         */
        public function connectionErrorLogger( $errno, $errstr ) {
-               $this->phpError = $errstr;
+               $this->lastPhpError = $errstr;
        }
 
        /**
@@ -1032,7 +1033,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         */
        protected function assertIsWritableMaster() {
                if ( $this->getLBInfo( 'replica' ) === true ) {
-                       throw new DBUnexpectedError(
+                       throw new DBReadOnlyRoleError(
                                $this,
                                'Write operations are not allowed on replica database connections.'
                        );
@@ -1194,11 +1195,9 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
 
                $flags = (int)$flags; // b/c; this field used to be a bool
                $ignoreErrors = $this->hasFlags( $flags, self::QUERY_SILENCE_ERRORS );
-               $pseudoPermanent = $this->hasFlags( $flags, self::QUERY_PSEUDO_PERMANENT );
 
                $priorTransaction = $this->trxLevel;
                $priorWritesPending = $this->writesOrCallbacksPending();
-               $this->lastQuery = $sql;
 
                if ( $this->isWriteQuery( $sql ) ) {
                        # In theory, non-persistent writes are allowed in read-only mode, but due to things
@@ -1206,8 +1205,13 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                        $this->assertIsWritableMaster();
                        # Do not treat temporary table writes as "meaningful writes" that need committing.
                        # Profile them as reads. Integration tests can override this behavior via $flags.
+                       $pseudoPermanent = $this->hasFlags( $flags, self::QUERY_PSEUDO_PERMANENT );
                        $tableType = $this->registerTempTableWrite( $sql, $pseudoPermanent );
                        $isEffectiveWrite = ( $tableType !== self::TEMP_NORMAL );
+                       # DBConnRef uses QUERY_REPLICA_ROLE to enforce the replica role for raw SQL queries
+                       if ( $isEffectiveWrite && $this->hasFlags( $flags, self::QUERY_REPLICA_ROLE ) ) {
+                               throw new DBReadOnlyRoleError( $this, "Cannot write; target role is DB_REPLICA" );
+                       }
                } else {
                        $isEffectiveWrite = false;
                }
@@ -1286,7 +1290,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
        private function attemptQuery( $sql, $commentedSql, $isEffectiveWrite, $fname ) {
                $this->beginIfImplied( $sql, $fname );
 
-               # Keep track of whether the transaction has write queries pending
+               // Keep track of whether the transaction has write queries pending
                if ( $isEffectiveWrite ) {
                        $this->lastWriteTime = microtime( true );
                        if ( $this->trxLevel && !$this->trxDoneWrites ) {
@@ -1296,25 +1300,15 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                        }
                }
 
-               if ( $this->getFlag( self::DBO_DEBUG ) ) {
-                       $this->queryLogger->debug( "{$this->getDomainID()} {$commentedSql}" );
-               }
-
-               $isMaster = !is_null( $this->getLBInfo( 'master' ) );
-               # generalizeSQL() will probably cut down the query to reasonable
-               # logging size most of the time. The substr is really just a sanity check.
-               if ( $isMaster ) {
-                       $queryProf = 'query-m: ' . substr( self::generalizeSQL( $sql ), 0, 255 );
-               } else {
-                       $queryProf = 'query: ' . substr( self::generalizeSQL( $sql ), 0, 255 );
-               }
-
-               # Include query transaction state
-               $queryProf .= $this->trxShortId ? " [TRX#{$this->trxShortId}]" : "";
+               $prefix = !is_null( $this->getLBInfo( 'master' ) ) ? 'query-m: ' : 'query: ';
+               $generalizedSql = new GeneralizedSql( $sql, $this->trxShortId, $prefix );
 
                $startTime = microtime( true );
-               $ps = $this->profiler ? ( $this->profiler )( $queryProf ) : null;
+               $ps = $this->profiler
+                       ? ( $this->profiler )( $generalizedSql->stringify() )
+                       : null;
                $this->affectedRowCount = null;
+               $this->lastQuery = $sql;
                $ret = $this->doQuery( $commentedSql );
                $this->affectedRowCount = $this->affectedRows();
                unset( $ps ); // profile out (if set)
@@ -1333,16 +1327,24 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                }
 
                $this->trxProfiler->recordQueryCompletion(
-                       $queryProf,
+                       $generalizedSql,
                        $startTime,
                        $isEffectiveWrite,
                        $isEffectiveWrite ? $this->affectedRows() : $this->numRows( $ret )
                );
-               $this->queryLogger->debug( $sql, [
-                       'method' => $fname,
-                       'master' => $isMaster,
-                       'runtime' => $queryRuntime,
-               ] );
+
+               // Avoid the overhead of logging calls unless debug mode is enabled
+               if ( $this->getFlag( self::DBO_DEBUG ) ) {
+                       $this->queryLogger->debug(
+                               "{method} [{runtime}s]: $sql",
+                               [
+                                       'method' => $fname,
+                                       'db_host' => $this->getServer(),
+                                       'domain' => $this->getDomainID(),
+                                       'runtime' => round( $queryRuntime, 3 )
+                               ]
+                       );
+               }
 
                return $ret;
        }
@@ -1542,11 +1544,11 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * @param int $errno
         * @param string $sql
         * @param string $fname
-        * @param bool $ignoreErrors
+        * @param bool $ignore
         * @throws DBQueryError
         */
-       public function reportQueryError( $error, $errno, $sql, $fname, $ignoreErrors = false ) {
-               if ( $ignoreErrors ) {
+       public function reportQueryError( $error, $errno, $sql, $fname, $ignore = false ) {
+               if ( $ignore ) {
                        $this->queryLogger->debug( "SQL ERROR (ignored): $error\n" );
                } else {
                        $exception = $this->getQueryExceptionAndLog( $error, $errno, $sql, $fname );
@@ -1576,9 +1578,10 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                        ] )
                );
                $this->queryLogger->debug( "SQL ERROR: " . $error . "\n" );
-               $wasQueryTimeout = $this->wasQueryTimeout( $error, $errno );
-               if ( $wasQueryTimeout ) {
+               if ( $this->wasQueryTimeout( $error, $errno ) ) {
                        $e = new DBQueryTimeoutError( $this, $error, $errno, $sql, $fname );
+               } elseif ( $this->wasConnectionError( $errno ) ) {
+                       $e = new DBQueryDisconnectedError( $this, $error, $errno, $sql, $fname );
                } else {
                        $e = new DBQueryError( $this, $error, $errno, $sql, $fname );
                }
@@ -2032,36 +2035,6 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                return $this->selectRowCount( $table, '*', $conds, $fname, $options, $join_conds );
        }
 
-       /**
-        * Removes most variables from an SQL query and replaces them with X or N for numbers.
-        * It's only slightly flawed. Don't use for anything important.
-        *
-        * @param string $sql A SQL Query
-        *
-        * @return string
-        */
-       protected static function generalizeSQL( $sql ) {
-               # This does the same as the regexp below would do, but in such a way
-               # as to avoid crashing php on some large strings.
-               # $sql = preg_replace( "/'([^\\\\']|\\\\.)*'|\"([^\\\\\"]|\\\\.)*\"/", "'X'", $sql );
-
-               $sql = str_replace( "\\\\", '', $sql );
-               $sql = str_replace( "\\'", '', $sql );
-               $sql = str_replace( "\\\"", '', $sql );
-               $sql = preg_replace( "/'.*'/s", "'X'", $sql );
-               $sql = preg_replace( '/".*"/s', "'X'", $sql );
-
-               # All newlines, tabs, etc replaced by single space
-               $sql = preg_replace( '/\s+/', ' ', $sql );
-
-               # All numbers => N,
-               # except the ones surrounded by characters, e.g. l10n
-               $sql = preg_replace( '/-?\d+(,-?\d+)+/s', 'N,...,N', $sql );
-               $sql = preg_replace( '/(?<![a-zA-Z])-?\d+(?![a-zA-Z])/s', 'N', $sql );
-
-               return $sql;
-       }
-
        public function fieldExists( $table, $field, $fname = __METHOD__ ) {
                $info = $this->fieldInfo( $table, $field );
 
@@ -2709,8 +2682,8 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                }
 
                // We can't separate explicit JOIN clauses with ',', use ' ' for those
-               $implicitJoins = $ret ? implode( ',', $ret ) : "";
-               $explicitJoins = $retJOIN ? implode( ' ', $retJOIN ) : "";
+               $implicitJoins = implode( ',', $ret );
+               $explicitJoins = implode( ' ', $retJOIN );
 
                // Compile our final table clause
                return implode( ' ', [ $implicitJoins, $explicitJoins ] );
@@ -3187,34 +3160,16 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                $this->query( $sql, $fname );
        }
 
-       /**
-        * Construct a LIMIT query with optional offset. This is used for query
-        * pages. The SQL should be adjusted so that only the first $limit rows
-        * are returned. If $offset is provided as well, then the first $offset
-        * rows should be discarded, and the next $limit rows should be returned.
-        * If the result of the query is not ordered, then the rows to be returned
-        * are theoretically arbitrary.
-        *
-        * $sql is expected to be a SELECT, if that makes a difference.
-        *
-        * The version provided by default works in MySQL and SQLite. It will very
-        * likely need to be overridden for most other DBMSes.
-        *
-        * @param string $sql SQL query we will append the limit too
-        * @param int $limit The SQL limit
-        * @param int|bool $offset The SQL offset (default false)
-        * @throws DBUnexpectedError
-        * @return string
-        */
        public function limitResult( $sql, $limit, $offset = false ) {
                if ( !is_numeric( $limit ) ) {
                        throw new DBUnexpectedError( $this,
                                "Invalid non-numeric limit passed to limitResult()\n" );
                }
-
+               // This version works in MySQL and SQLite. It will very likely need to be
+               // overridden for most other RDBMS subclasses.
                return "$sql LIMIT "
-               . ( ( is_numeric( $offset ) && $offset != 0 ) ? "{$offset}," : "" )
-               . "{$limit} ";
+                       . ( ( is_numeric( $offset ) && $offset != 0 ) ? "{$offset}," : "" )
+                       . "{$limit} ";
        }
 
        public function unionSupportsOrderAndLimit() {
@@ -3580,6 +3535,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                                list( $phpCallback ) = $callback;
                                $this->clearFlag( self::DBO_TRX ); // make each query its own transaction
                                try {
+                                       // @phan-suppress-next-line PhanParamTooManyCallable
                                        call_user_func( $phpCallback, $trigger, $this );
                                } catch ( Exception $ex ) {
                                        call_user_func( $this->errorLogger, $ex );