From 19d6e3343bf0903c0c1a8593ba020495c4795293 Mon Sep 17 00:00:00 2001 From: Aaron Schulz Date: Tue, 1 May 2018 11:21:13 -0700 Subject: [PATCH] rdbms: set cpPosIndex to null in ChronologyProtector::shutdown on failure This already happens on lock acquisition failure but not on write failure. If the write failed, then there is not point timing out on the next request after waiting "waitForPosStoreTimeout" seconds. Also raise the initPositions() logging for missing positions to WARNING and improve the wait loop log entries in that method. Change-Id: Id738eb6f85c91dd05fadd2e6c3f19ae3204e2575 --- includes/libs/rdbms/ChronologyProtector.php | 25 ++++++++++++++++----- 1 file changed, 19 insertions(+), 6 deletions(-) diff --git a/includes/libs/rdbms/ChronologyProtector.php b/includes/libs/rdbms/ChronologyProtector.php index e11528659d..90e697ec16 100644 --- a/includes/libs/rdbms/ChronologyProtector.php +++ b/includes/libs/rdbms/ChronologyProtector.php @@ -212,10 +212,10 @@ class ChronologyProtector implements LoggerAwareInterface { $store->unlock( $this->key ); } else { $ok = false; - $cpIndex = null; // nothing saved } if ( !$ok ) { + $cpIndex = null; // nothing saved $bouncedPositions = $this->shutdownPositions; // Raced out too many times or stash is down $this->logger->warning( __METHOD__ . ": failed to save master pos for " . @@ -269,14 +269,16 @@ class ChronologyProtector implements LoggerAwareInterface { // already be expired and thus treated as non-existing, maintaining correctness. if ( $this->waitForPosIndex > 0 ) { $data = null; + $indexReached = null; // highest index reached in the position store $loop = new WaitConditionLoop( - function () use ( &$data ) { + function () use ( &$data, &$indexReached ) { $data = $this->store->get( $this->key ); if ( !is_array( $data ) ) { return WaitConditionLoop::CONDITION_CONTINUE; // not found yet } elseif ( !isset( $data['writeIndex'] ) ) { return WaitConditionLoop::CONDITION_REACHED; // b/c } + $indexReached = max( $data['writeIndex'], $indexReached ); return ( $data['writeIndex'] >= $this->waitForPosIndex ) ? WaitConditionLoop::CONDITION_REACHED @@ -288,11 +290,22 @@ class ChronologyProtector implements LoggerAwareInterface { $waitedMs = $loop->getLastWaitTime() * 1e3; if ( $result == $loop::CONDITION_REACHED ) { - $msg = "expected and found pos index {$this->waitForPosIndex} ({$waitedMs}ms)"; - $this->logger->debug( $msg ); + $this->logger->debug( + __METHOD__ . ": expected and found position index.", + [ + 'cpPosIndex' => $this->waitForPosIndex, + 'waitTimeMs' => $waitedMs + ] + ); } else { - $msg = "expected but missed pos index {$this->waitForPosIndex} ({$waitedMs}ms)"; - $this->logger->info( $msg ); + $this->logger->warning( + __METHOD__ . ": expected but failed to find position index.", + [ + 'cpPosIndex' => $this->waitForPosIndex, + 'indexReached' => $indexReached, + 'waitTimeMs' => $waitedMs + ] + ); } } else { $data = $this->store->get( $this->key ); -- 2.20.1