From 05a3ee2468a683d2a88ed8a5e7a8ace02a73bc45 Mon Sep 17 00:00:00 2001
From: Aaron Schulz <aschulz@wikimedia.org>
Date: Sun, 25 Oct 2015 13:42:21 -0700
Subject: [PATCH] Make WAN cache HOLDOFF_TTL smaller by combining db/snapshot
 lag

* In the common ~0 second lag case, transactions up to ~7 seconds
  long will have normal set() behavior (instead of just ~5 seconds).
* Like wise with ~0 second transactions tolerating ~7 seconds of
  lag (instead of just ~5).
* The lower hold-off time lets caching resume 3 seconds sooner.

Change-Id: I21e2a0a6915492cec422b6a6af5541937745c15b
---
 includes/libs/objectcache/WANObjectCache.php  | 37 +++++++++++--------
 .../libs/objectcache/WANObjectCacheTest.php   | 28 ++++++++++++++
 2 files changed, 49 insertions(+), 16 deletions(-)

diff --git a/includes/libs/objectcache/WANObjectCache.php b/includes/libs/objectcache/WANObjectCache.php
index 0c7b7edcf0..d9a8d71a73 100644
--- a/includes/libs/objectcache/WANObjectCache.php
+++ b/includes/libs/objectcache/WANObjectCache.php
@@ -81,12 +81,10 @@ class WANObjectCache implements LoggerAwareInterface {
 
 	/** Max time expected to pass between delete() and DB commit finishing */
 	const MAX_COMMIT_DELAY = 3;
-	/** Max replication lag before applying TTL_LAGGED to set() */
-	const MAX_REPLICA_LAG = 5;
-	/** Max time since snapshot transaction start to avoid no-op of set() */
-	const MAX_SNAPSHOT_LAG = 5;
+	/** Max replication+snapshot lag before applying TTL_LAGGED or disallowing set() */
+	const MAX_READ_LAG = 7;
 	/** Seconds to tombstone keys on delete() */
-	const HOLDOFF_TTL = 14; // MAX_COMMIT_DELAY + MAX_REPLICA_LAG + MAX_SNAPSHOT_LAG + 1
+	const HOLDOFF_TTL = 11; // MAX_COMMIT_DELAY + MAX_READ_LAG + 1
 
 	/** Seconds to keep dependency purge keys around */
 	const CHECK_KEY_TTL = 31536000; // 1 year
@@ -327,27 +325,34 @@ class WANObjectCache implements LoggerAwareInterface {
 		$lockTSE = isset( $opts['lockTSE'] ) ? $opts['lockTSE'] : self::TSE_NONE;
 		$age = isset( $opts['since'] ) ? max( 0, microtime( true ) - $opts['since'] ) : 0;
 		$lag = isset( $opts['lag'] ) ? $opts['lag'] : 0;
-
+		// Disallow set() if the source data is uncommitted as it might get rolled back
 		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 ) {
+		// Check if there's a risk of writing stale data after the purge tombstone expired
+		if ( ( $lag + $age ) > self::MAX_READ_LAG ) {
 			if ( $lockTSE >= 0 ) {
+				// Focus on avoiding stampedes; stash the value with a low TTL
 				$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." );
+			// Case A: any long-running transaction; ignore this set()
+			if ( $age > self::MAX_READ_LAG ) {
+				$this->logger->warning( "Rejected set() for $key due to snapshot lag." );
+
+				return true; // no-op the write for being unsafe
+			// Case B: replication lag is high; lower TTL instead of ignoring all set()s
+			} elseif ( $lag > self::MAX_READ_LAG ) {
+				$ttl = $ttl ? min( $ttl, self::TTL_LAGGED ) : self::TTL_LAGGED;
+				$this->logger->warning( "Lowered set() TTL for $key due to replication lag." );
+			// Case C: medium length request during medium lag; ignore this set()
+			} else {
+				$this->logger->warning( "Rejected set() for $key due to high read lag." );
 
-			return true; // no-op the write for being unsafe
+				return true; // no-op the write for being unsafe
+			}
 		}
 
 		$wrapped = $this->wrap( $value, $ttl );
diff --git a/tests/phpunit/includes/libs/objectcache/WANObjectCacheTest.php b/tests/phpunit/includes/libs/objectcache/WANObjectCacheTest.php
index c3702c5945..54393a7620 100644
--- a/tests/phpunit/includes/libs/objectcache/WANObjectCacheTest.php
+++ b/tests/phpunit/includes/libs/objectcache/WANObjectCacheTest.php
@@ -313,4 +313,32 @@ class WANObjectCacheTest extends MediaWikiTestCase {
 		$t6 = $this->cache->getCheckKeyTime( $key );
 		$this->assertEquals( $t5, $t6, 'Check key time did not change' );
 	}
+
+	public function testSetWithLag() {
+		$value = 1;
+
+		$key = wfRandomString();
+		$opts = array( 'lag' => 300, 'since' => microtime( true ) );
+		$this->cache->set( $key, $value, 30, $opts );
+		$this->assertEquals( $value, $this->cache->get( $key ), "Rep-lagged value written." );
+
+		$key = wfRandomString();
+		$opts = array( 'lag' => 0, 'since' => microtime( true ) - 300 );
+		$this->cache->set( $key, $value, 30, $opts );
+		$this->assertEquals( false, $this->cache->get( $key ), "Trx-lagged value not written." );
+
+		$key = wfRandomString();
+		$opts = array( 'lag' => 5, 'since' => microtime( true ) - 5 );
+		$this->cache->set( $key, $value, 30, $opts );
+		$this->assertEquals( false, $this->cache->get( $key ), "Lagged value not written." );
+	}
+
+	public function testWritePending() {
+		$value = 1;
+
+		$key = wfRandomString();
+		$opts = array( 'pending' => true );
+		$this->cache->set( $key, $value, 30, $opts );
+		$this->assertEquals( false, $this->cache->get( $key ), "Pending value not written." );
+	}
 }
-- 
2.20.1