From dc646b464cf7db8aa756f3bd107c51a8d513e51f Mon Sep 17 00:00:00 2001 From: Aaron Schulz Date: Tue, 20 Oct 2015 22:55:51 -0700 Subject: [PATCH] Protect WAN cache sets() against uncommitted data This generally only effects wikis with no slave DBs, but also matters if the master has non-zero LB load. If the master ends up being used for DB_SLAVE, care should be shown for cache-aside writes Interesting WAN cache events are now logged. Change-Id: I2cd8e84138263c13ea23beb9ab3d7562340e1fd3 --- includes/DefaultSettings.php | 3 ++- includes/db/DBConnRef.php | 4 +++ includes/db/Database.php | 16 ++++++++++-- includes/db/IDatabase.php | 6 +++++ includes/libs/objectcache/WANObjectCache.php | 26 +++++++++++++++++++- includes/objectcache/ObjectCache.php | 7 ++++-- 6 files changed, 56 insertions(+), 6 deletions(-) diff --git a/includes/DefaultSettings.php b/includes/DefaultSettings.php index 71fe83d419..22717cde15 100644 --- a/includes/DefaultSettings.php +++ b/includes/DefaultSettings.php @@ -2263,7 +2263,8 @@ $wgMainWANCache = false; * the value is an associative array of parameters. The "cacheId" parameter is * a cache identifier from $wgObjectCaches. The "relayerConfig" parameter is an * array used to construct an EventRelayer object. The "pool" parameter is a - * string that is used as a PubSub channel prefix. + * string that is used as a PubSub channel prefix. The "loggroup" parameter + * controls where log events are sent. * * @since 1.26 */ diff --git a/includes/db/DBConnRef.php b/includes/db/DBConnRef.php index 53e9a50bb4..5443eeb902 100644 --- a/includes/db/DBConnRef.php +++ b/includes/db/DBConnRef.php @@ -91,6 +91,10 @@ class DBConnRef implements IDatabase { return $this->__call( __FUNCTION__, func_get_args() ); } + public function writesPending() { + return $this->__call( __FUNCTION__, func_get_args() ); + } + public function writesOrCallbacksPending() { return $this->__call( __FUNCTION__, func_get_args() ); } diff --git a/includes/db/Database.php b/includes/db/Database.php index 2f135a4c5c..59f3d4de88 100644 --- a/includes/db/Database.php +++ b/includes/db/Database.php @@ -441,6 +441,14 @@ abstract class DatabaseBase implements IDatabase { return $this->mDoneWrites ?: false; } + /** + * @return bool Whether there is a transaction open with possible write queries + * @since 1.27 + */ + public function writesPending() { + return $this->mTrxLevel && $this->mTrxDoneWrites; + } + /** * Returns true if there is a transaction open with possible write * queries or transaction pre-commit/idle callbacks waiting on it to finish. @@ -3820,16 +3828,20 @@ abstract class DatabaseBase implements IDatabase { * * @param IDatabase $db1 * @param IDatabase ... - * @return array ('lag': highest lag, 'since': lowest estimate UNIX timestamp) + * @return array Map of values: + * - lag: highest lag of any of the DBs + * - since: oldest UNIX timestamp of any of the DB lag estimates + * - pending: whether any of the DBs have uncommitted changes * @since 1.27 */ public static function getCacheSetOptions( IDatabase $db1 ) { - $res = array( 'lag' => 0, 'since' => INF ); + $res = array( 'lag' => 0, 'since' => INF, 'pending' => false ); foreach ( func_get_args() as $db ) { /** @var IDatabase $db */ $status = $db->getSessionLagStatus(); $res['lag'] = max( $res['lag'], $status['lag'] ); $res['since'] = min( $res['since'], $status['since'] ); + $res['pending'] = $res['pending'] ?: $db->writesPending(); } return $res; diff --git a/includes/db/IDatabase.php b/includes/db/IDatabase.php index d11058307d..19eb12628b 100644 --- a/includes/db/IDatabase.php +++ b/includes/db/IDatabase.php @@ -159,6 +159,12 @@ interface IDatabase { */ public function lastDoneWrites(); + /** + * @return bool Whether there is a transaction open with possible write queries + * @since 1.27 + */ + public function writesPending(); + /** * Returns true if there is a transaction open with possible write * queries or transaction pre-commit/idle callbacks waiting on it to finish. diff --git a/includes/libs/objectcache/WANObjectCache.php b/includes/libs/objectcache/WANObjectCache.php index 39eb792935..0c7b7edcf0 100644 --- a/includes/libs/objectcache/WANObjectCache.php +++ b/includes/libs/objectcache/WANObjectCache.php @@ -20,6 +20,10 @@ * @author Aaron Schulz */ +use Psr\Log\LoggerAwareInterface; +use Psr\Log\LoggerInterface; +use Psr\Log\NullLogger; + /** * Multi-datacenter aware caching interface * @@ -60,7 +64,7 @@ * @ingroup Cache * @since 1.26 */ -class WANObjectCache { +class WANObjectCache implements LoggerAwareInterface { /** @var BagOStuff The local datacenter cache */ protected $cache; /** @var HashBagOStuff Script instance PHP cache */ @@ -69,6 +73,8 @@ class WANObjectCache { protected $pool; /** @var EventRelayer Bus that handles purge broadcasts */ protected $relayer; + /** @var LoggerInterface */ + protected $logger; /** @var int ERR_* constant for the "last error" registry */ protected $lastRelayError = self::ERR_NONE; @@ -125,12 +131,18 @@ class WANObjectCache { * - cache : BagOStuff object * - pool : pool name * - relayer : EventRelayer object + * - logger : LoggerInterface object */ public function __construct( array $params ) { $this->cache = $params['cache']; $this->pool = $params['pool']; $this->relayer = $params['relayer']; $this->procCache = new HashBagOStuff(); + $this->setLogger( isset( $params['logger'] ) ? $params['logger'] : new NullLogger() ); + } + + public function setLogger( LoggerInterface $logger ) { + $this->logger = $logger; } /** @@ -300,6 +312,10 @@ class WANObjectCache { * the current time the data was read or (if applicable) the time when * the snapshot-isolated transaction the data was read from started. * Default: 0 seconds + * - pending : Whether this data is possibly from an uncommitted write transaction. + * Generally, other threads should not see values from the future and + * they certainly should not see ones that ended up getting rolled back. + * Default: false * - lockTSE : if excessive possible snapshot lag is detected, * then stash the value into a temporary location * with this TTL. This is only useful if the reads @@ -312,9 +328,16 @@ class WANObjectCache { $age = isset( $opts['since'] ) ? max( 0, microtime( true ) - $opts['since'] ) : 0; $lag = isset( $opts['lag'] ) ? $opts['lag'] : 0; + if ( !empty( $opts['pending'] ) ) { + $this->logger->info( "Rejected set() for $key due to pending writes." ); + + return true; // no-op the write for being unsafe + } + if ( $lag > self::MAX_REPLICA_LAG ) { // Too much lag detected; lower TTL so it converges faster $ttl = $ttl ? min( $ttl, self::TTL_LAGGED ) : self::TTL_LAGGED; + $this->logger->warning( "Lowered set() TTL for $key due to replication lag." ); } if ( $age > self::MAX_SNAPSHOT_LAG ) { @@ -322,6 +345,7 @@ class WANObjectCache { $tempTTL = max( 1, (int)$lockTSE ); // set() expects seconds $this->cache->set( self::STASH_KEY_PREFIX . $key, $value, $tempTTL ); } + $this->logger->warning( "Rejected set() for $key due to snapshot lag." ); return true; // no-op the write for being unsafe } diff --git a/includes/objectcache/ObjectCache.php b/includes/objectcache/ObjectCache.php index 151bb065f9..56b5cbd0b8 100644 --- a/includes/objectcache/ObjectCache.php +++ b/includes/objectcache/ObjectCache.php @@ -167,8 +167,6 @@ class ObjectCache { if ( isset( $params['loggroup'] ) ) { $params['logger'] = LoggerFactory::getInstance( $params['loggroup'] ); } else { - // For backwards-compatability with custom parameters, lets not - // have all logging suddenly disappear $params['logger'] = LoggerFactory::getInstance( 'objectcache' ); } if ( !isset( $params['keyspace'] ) ) { @@ -290,6 +288,11 @@ class ObjectCache { $class = $params['relayerConfig']['class']; $params['relayer'] = new $class( $params['relayerConfig'] ); $params['cache'] = self::newFromId( $params['cacheId'] ); + if ( isset( $params['loggroup'] ) ) { + $params['logger'] = LoggerFactory::getInstance( $params['loggroup'] ); + } else { + $params['logger'] = LoggerFactory::getInstance( 'objectcache' ); + } $class = $params['class']; return new $class( $params ); -- 2.20.1