Code Coverage |
||||||||||
Lines |
Functions and Methods |
Classes and Traits |
||||||||
| Total | |
71.72% |
71 / 99 |
|
35.29% |
6 / 17 |
CRAP | |
0.00% |
0 / 1 |
| ElasticsearchIntermediary | |
71.72% |
71 / 99 |
|
35.29% |
6 / 17 |
76.20 | |
0.00% |
0 / 1 |
| __construct | |
85.71% |
6 / 7 |
|
0.00% |
0 / 1 |
2.01 | |||
| setResultPages | |
66.67% |
2 / 3 |
|
0.00% |
0 / 1 |
2.15 | |||
| getQueryTypesUsed | |
0.00% |
0 / 3 |
|
0.00% |
0 / 1 |
6 | |||
| hasQueryLogs | |
0.00% |
0 / 3 |
|
0.00% |
0 / 1 |
6 | |||
| start | |
75.00% |
3 / 4 |
|
0.00% |
0 / 1 |
2.06 | |||
| success | |
100.00% |
2 / 2 |
|
100.00% |
1 / 1 |
1 | |||
| successViaCache | |
0.00% |
0 / 3 |
|
0.00% |
0 / 1 |
6 | |||
| failure | |
88.24% |
15 / 17 |
|
0.00% |
0 / 1 |
2.01 | |||
| getSearchMetrics | |
100.00% |
1 / 1 |
|
100.00% |
1 / 1 |
1 | |||
| finishRequest | |
100.00% |
17 / 17 |
|
100.00% |
1 / 1 |
3 | |||
| appendLastLogPayload | |
0.00% |
0 / 3 |
|
0.00% |
0 / 1 |
6 | |||
| startNewLog | |
100.00% |
3 / 3 |
|
100.00% |
1 / 1 |
1 | |||
| newLog | n/a |
0 / 0 |
n/a |
0 / 0 |
0 | |||||
| getTimeout | |
100.00% |
7 / 7 |
|
100.00% |
1 / 1 |
3 | |||
| getClientTimeout | |
85.71% |
6 / 7 |
|
0.00% |
0 / 1 |
3.03 | |||
| appendMetrics | |
100.00% |
1 / 1 |
|
100.00% |
1 / 1 |
1 | |||
| isMSearchResultSetOK | |
0.00% |
0 / 2 |
|
0.00% |
0 / 1 |
6 | |||
| runMSearch | |
50.00% |
8 / 16 |
|
0.00% |
0 / 1 |
19.12 | |||
| 1 | <?php |
| 2 | |
| 3 | namespace CirrusSearch; |
| 4 | |
| 5 | use CirrusSearch\Search\SearchMetricsProvider; |
| 6 | use Elastica\Exception\ExceptionInterface; |
| 7 | use Elastica\Exception\ResponseException; |
| 8 | use Elastica\Exception\RuntimeException; |
| 9 | use Elastica\Multi\ResultSet as MultiResultSet; |
| 10 | use Elastica\Multi\Search; |
| 11 | use ISearchResultSet; |
| 12 | use MediaWiki\Logger\LoggerFactory; |
| 13 | use MediaWiki\User\UserIdentity; |
| 14 | use RequestContext; |
| 15 | use Status; |
| 16 | use Wikimedia\Assert\Assert; |
| 17 | |
| 18 | /** |
| 19 | * Base class with useful functions for communicating with Elasticsearch. |
| 20 | * |
| 21 | * This program is free software; you can redistribute it and/or modify |
| 22 | * it under the terms of the GNU General Public License as published by |
| 23 | * the Free Software Foundation; either version 2 of the License, or |
| 24 | * (at your option) any later version. |
| 25 | * |
| 26 | * This program is distributed in the hope that it will be useful, |
| 27 | * but WITHOUT ANY WARRANTY; without even the implied warranty of |
| 28 | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
| 29 | * GNU General Public License for more details. |
| 30 | * |
| 31 | * You should have received a copy of the GNU General Public License along |
| 32 | * with this program; if not, write to the Free Software Foundation, Inc., |
| 33 | * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. |
| 34 | * http://www.gnu.org/copyleft/gpl.html |
| 35 | */ |
| 36 | abstract class ElasticsearchIntermediary { |
| 37 | /** |
| 38 | * @var Connection |
| 39 | */ |
| 40 | protected $connection; |
| 41 | |
| 42 | /** |
| 43 | * @var UserIdentity|null user for which we're performing this search or null in |
| 44 | * the case of requests kicked off by jobs |
| 45 | */ |
| 46 | protected $user; |
| 47 | |
| 48 | /** |
| 49 | * @var RequestLog|null Log for in-progress search request |
| 50 | */ |
| 51 | protected $currentRequestLog = null; |
| 52 | |
| 53 | /** |
| 54 | * @var int how many millis a request through this intermediary needs to |
| 55 | * take before it counts as slow. 0 means none count as slow. |
| 56 | */ |
| 57 | private $slowMillis; |
| 58 | |
| 59 | /** |
| 60 | * @var array Metrics about a completed search |
| 61 | */ |
| 62 | private $searchMetrics = []; |
| 63 | |
| 64 | /** |
| 65 | * @var int artificial extra backend latency in micro seconds |
| 66 | */ |
| 67 | private $extraBackendLatency; |
| 68 | |
| 69 | /** |
| 70 | * @var RequestLogger |
| 71 | */ |
| 72 | protected static $requestLogger; |
| 73 | |
| 74 | /** |
| 75 | * @param Connection $connection |
| 76 | * @param UserIdentity|null $user user for which this search is being performed. |
| 77 | * Attached to slow request logs. Note that null isn't for anonymous users |
| 78 | * - those are still User objects and should be provided if possible. Null |
| 79 | * is for when the action is being performed in some context where the user |
| 80 | * that caused it isn't available. Like when an action is being performed |
| 81 | * during a job. |
| 82 | * @param float|null $slowSeconds how many seconds a request through this |
| 83 | * intermediary needs to take before it counts as slow. 0 means none count |
| 84 | * as slow. Defaults to CirrusSearchSlowSearch config option. |
| 85 | * @param int $extraBackendLatency artificial backend latency. |
| 86 | */ |
| 87 | protected function __construct( Connection $connection, UserIdentity $user = null, $slowSeconds = null, $extraBackendLatency = 0 ) { |
| 88 | $this->connection = $connection; |
| 89 | $this->user = $user ?? RequestContext::getMain()->getUser(); |
| 90 | $this->slowMillis = (int)( 1000 * ( $slowSeconds ?? $connection->getConfig()->get( 'CirrusSearchSlowSearch' ) ) ); |
| 91 | $this->extraBackendLatency = $extraBackendLatency; |
| 92 | if ( self::$requestLogger === null ) { |
| 93 | self::$requestLogger = new RequestLogger; |
| 94 | } |
| 95 | // This isn't explicitly used, but we need to make sure it is |
| 96 | // instantiated so it has the opportunity to override global |
| 97 | // configuration for test buckets. |
| 98 | UserTestingStatus::getInstance(); |
| 99 | } |
| 100 | |
| 101 | /** |
| 102 | * This is set externally because we don't have complete control, from the |
| 103 | * SearchEngine interface, of what is actually sent to the user. Instead hooks |
| 104 | * receive the final results that will be sent to the user and set them here. |
| 105 | * |
| 106 | * Accepts two result sets because some places (Special:Search) perform multiple |
| 107 | * searches. This can be called multiple times, but only that last call wins. For |
| 108 | * API's that is correct, for Special:Search a hook catches the final results and |
| 109 | * sets them here. |
| 110 | * |
| 111 | * @param ISearchResultSet[] $matches |
| 112 | */ |
| 113 | public static function setResultPages( array $matches ) { |
| 114 | if ( self::$requestLogger === null ) { |
| 115 | // This could happen if Cirrus is not the active engine, |
| 116 | // but the hook is still loaded. In this case, do nothing. |
| 117 | return; |
| 118 | } else { |
| 119 | self::$requestLogger->setResultPages( $matches ); |
| 120 | } |
| 121 | } |
| 122 | |
| 123 | /** |
| 124 | * Report the types of queries that were issued |
| 125 | * within the current request. |
| 126 | * |
| 127 | * @return string[] |
| 128 | */ |
| 129 | public static function getQueryTypesUsed() { |
| 130 | if ( self::$requestLogger === null ) { |
| 131 | // This can happen when, for example, completion search is |
| 132 | // triggered against NS_SPECIAL, where searching is done strictly |
| 133 | // in PHP and never actually creates a SearchEngine. |
| 134 | return []; |
| 135 | } else { |
| 136 | return self::$requestLogger->getQueryTypesUsed(); |
| 137 | } |
| 138 | } |
| 139 | |
| 140 | /** |
| 141 | * @return bool True when query logs have been generated by the |
| 142 | * current php execution. |
| 143 | */ |
| 144 | public static function hasQueryLogs() { |
| 145 | if ( self::$requestLogger === null ) { |
| 146 | return false; |
| 147 | } |
| 148 | return self::$requestLogger->hasQueryLogs(); |
| 149 | } |
| 150 | |
| 151 | /** |
| 152 | * Mark the start of a request to Elasticsearch. Public so it can be |
| 153 | * called from pool counter methods. |
| 154 | * |
| 155 | * @param RequestLog $log |
| 156 | */ |
| 157 | public function start( RequestLog $log ) { |
| 158 | $this->currentRequestLog = $log; |
| 159 | $log->start(); |
| 160 | if ( $this->extraBackendLatency ) { |
| 161 | usleep( $this->extraBackendLatency ); |
| 162 | } |
| 163 | } |
| 164 | |
| 165 | /** |
| 166 | * Log a successful request and return the provided result in a good |
| 167 | * Status. If you don't need the status just ignore the return. Public so |
| 168 | * it can be called from pool counter methods. |
| 169 | * |
| 170 | * @param mixed|null $result result of the request. defaults to null in case |
| 171 | * the request doesn't have a result |
| 172 | * @param Connection|null $connection The connection the succesful |
| 173 | * request was performed against. Will use $this->connection when not |
| 174 | * provided. |
| 175 | * @return Status wrapping $result |
| 176 | */ |
| 177 | public function success( $result = null, Connection $connection = null ) { |
| 178 | $this->finishRequest( $connection ?? $this->connection ); |
| 179 | return Status::newGood( $result ); |
| 180 | } |
| 181 | |
| 182 | /** |
| 183 | * Log a successful request when the response comes from a cache outside |
| 184 | * elasticsearch. This is a combination of self::start() and self::success(). |
| 185 | * |
| 186 | * @param RequestLog $log |
| 187 | */ |
| 188 | public function successViaCache( RequestLog $log ) { |
| 189 | if ( $this->extraBackendLatency ) { |
| 190 | usleep( $this->extraBackendLatency ); |
| 191 | } |
| 192 | self::$requestLogger->addRequest( $log ); |
| 193 | } |
| 194 | |
| 195 | /** |
| 196 | * Log a failure and return an appropriate status. Public so it can be |
| 197 | * called from pool counter methods. |
| 198 | * |
| 199 | * @param ExceptionInterface|null $exception if the request failed |
| 200 | * @param Connection|null $connection The connection that the failed |
| 201 | * request was performed against. Will use $this->connection when not |
| 202 | * provided. |
| 203 | * @return Status representing a backend failure |
| 204 | */ |
| 205 | public function failure( ExceptionInterface $exception = null, Connection $connection = null ) { |
| 206 | $connection ??= $this->connection; |
| 207 | $log = $this->finishRequest( $connection ); |
| 208 | if ( $log === null ) { |
| 209 | // Request was never started, likely trying to close a request |
| 210 | // a second time. If so that was already logged by finishRequest. |
| 211 | $context = []; |
| 212 | $logType = 'not_started'; |
| 213 | } else { |
| 214 | $context = $log->getLogVariables(); |
| 215 | $logType = $log->getDescription(); |
| 216 | } |
| 217 | list( $status, $message ) = ElasticaErrorHandler::extractMessageAndStatus( $exception ); |
| 218 | // This could be multiple MB if the failure is coming from an update |
| 219 | // script, as the whole update script is returned in the error |
| 220 | // including the parameters. Truncate to a reasonable level so |
| 221 | // downstream log processing doesn't truncate them (and then fail to |
| 222 | // parse the truncated json). Take the first 4k to leave plenty of room for |
| 223 | // whatever else. |
| 224 | $context['error_message'] = mb_substr( $message, 0, 4096 ); |
| 225 | |
| 226 | $stats = Util::getStatsDataFactory(); |
| 227 | $type = ElasticaErrorHandler::classifyError( $exception ); |
| 228 | $clusterName = $connection->getClusterName(); |
| 229 | $context['cirrussearch_error_type'] = $type; |
| 230 | |
| 231 | $stats->increment( "CirrusSearch.$clusterName.backend_failure.$type" ); |
| 232 | |
| 233 | LoggerFactory::getInstance( 'CirrusSearch' )->warning( |
| 234 | "Search backend error during {$logType} after {tookMs}: {error_message}", |
| 235 | $context |
| 236 | ); |
| 237 | return $status; |
| 238 | } |
| 239 | |
| 240 | /** |
| 241 | * Get the search metrics we have |
| 242 | * @return array |
| 243 | */ |
| 244 | public function getSearchMetrics() { |
| 245 | return $this->searchMetrics; |
| 246 | } |
| 247 | |
| 248 | /** |
| 249 | * Log the completion of a request to Elasticsearch. |
| 250 | * |
| 251 | * @param Connection $connection |
| 252 | * @return RequestLog|null The log for the finished request, or null if no |
| 253 | * request was started. |
| 254 | */ |
| 255 | private function finishRequest( Connection $connection ) { |
| 256 | if ( !$this->currentRequestLog ) { |
| 257 | LoggerFactory::getInstance( 'CirrusSearch' )->warning( |
| 258 | 'finishRequest called without staring a request' |
| 259 | ); |
| 260 | return null; |
| 261 | } |
| 262 | $log = $this->currentRequestLog; |
| 263 | $this->currentRequestLog = null; |
| 264 | |
| 265 | $log->finish(); |
| 266 | $tookMs = $log->getTookMs(); |
| 267 | $clusterName = $connection->getClusterName(); |
| 268 | $stats = Util::getStatsDataFactory(); |
| 269 | $stats->timing( "CirrusSearch.$clusterName.requestTime", $tookMs ); |
| 270 | $this->searchMetrics['wgCirrusTookMs'] = $tookMs; |
| 271 | self::$requestLogger->addRequest( $log, $this->user, $this->slowMillis ); |
| 272 | $type = $log->getQueryType(); |
| 273 | $stats->timing( "CirrusSearch.$clusterName.requestTimeMs.$type", $tookMs ); |
| 274 | if ( $log->getElasticTookMs() ) { |
| 275 | $this->searchMetrics['wgCirrusElasticTime'] = $log->getElasticTookMs(); |
| 276 | } |
| 277 | |
| 278 | return $log; |
| 279 | } |
| 280 | |
| 281 | /** |
| 282 | * @param string $key |
| 283 | * @param string $value |
| 284 | */ |
| 285 | public static function appendLastLogPayload( $key, $value ) { |
| 286 | if ( self::$requestLogger !== null ) { |
| 287 | // Guard only for unit tests that heavily mock classes |
| 288 | self::$requestLogger->appendLastLogPayload( $key, $value ); |
| 289 | } else { |
| 290 | Assert::invariant( defined( 'MW_PHPUNIT_TEST' ), |
| 291 | 'appendLastLogPayload must only be called after self::$requestLogger has been set ' . |
| 292 | 'or during unit tests' ); |
| 293 | } |
| 294 | } |
| 295 | |
| 296 | /** |
| 297 | * @param string $description A psr-3 compliant string describing the request |
| 298 | * @param string $queryType The type of search being performed such as |
| 299 | * fulltext, get, etc. |
| 300 | * @param array $extra A map of additional request-specific data |
| 301 | * @return RequestLog |
| 302 | */ |
| 303 | protected function startNewLog( $description, $queryType, array $extra = [] ) { |
| 304 | $log = $this->newLog( $description, $queryType, $extra ); |
| 305 | $this->start( $log ); |
| 306 | |
| 307 | return $log; |
| 308 | } |
| 309 | |
| 310 | /** |
| 311 | * @param string $description A psr-3 compliant string describing the request |
| 312 | * @param string $queryType The type of search being performed such as |
| 313 | * fulltext, get, etc. |
| 314 | * @param array $extra A map of additional request-specific data |
| 315 | * @return RequestLog |
| 316 | */ |
| 317 | abstract protected function newLog( $description, $queryType, array $extra = [] ); |
| 318 | |
| 319 | /** |
| 320 | * @param string $searchType |
| 321 | * @return string search retrieval timeout |
| 322 | */ |
| 323 | protected function getTimeout( $searchType = 'default' ) { |
| 324 | $timeout = $this->connection->getConfig()->getElement( 'CirrusSearchSearchShardTimeout', $searchType ); |
| 325 | if ( $timeout !== null ) { |
| 326 | return $timeout; |
| 327 | } |
| 328 | $timeout = $this->connection->getConfig()->getElement( 'CirrusSearchSearchShardTimeout', 'default' ); |
| 329 | if ( $timeout !== null ) { |
| 330 | return $timeout; |
| 331 | } |
| 332 | throw new \ConfigException( "wgCirrusSearchSearchShardTimeout should have at least a 'default' entry configured" ); |
| 333 | } |
| 334 | |
| 335 | /** |
| 336 | * @param string $searchType |
| 337 | * @return int the client side timeout |
| 338 | */ |
| 339 | protected function getClientTimeout( $searchType = 'default' ) { |
| 340 | $timeout = $this->connection->getConfig()->getElement( 'CirrusSearchClientSideSearchTimeout', $searchType ); |
| 341 | if ( $timeout !== null ) { |
| 342 | return $timeout; |
| 343 | } |
| 344 | $timeout = $this->connection->getConfig()->getElement( 'CirrusSearchClientSideSearchTimeout', 'default' ); |
| 345 | if ( $timeout !== null ) { |
| 346 | return $timeout; |
| 347 | } |
| 348 | throw new \ConfigException( "wgCirrusSearchClientSideSearchTimeout should have at least a 'default' entry configured" ); |
| 349 | } |
| 350 | |
| 351 | /** |
| 352 | * @param SearchMetricsProvider $provider |
| 353 | */ |
| 354 | protected function appendMetrics( SearchMetricsProvider $provider ) { |
| 355 | $this->searchMetrics += $provider->getMetrics(); |
| 356 | } |
| 357 | |
| 358 | /** |
| 359 | * check validity of the multisearch response |
| 360 | * |
| 361 | * @param MultiResultSet $multiResultSet |
| 362 | * @return bool |
| 363 | */ |
| 364 | public static function isMSearchResultSetOK( MultiResultSet $multiResultSet ): bool { |
| 365 | return !$multiResultSet->hasError() && |
| 366 | // Catches HTTP errors (ex: 5xx) not reported |
| 367 | // by hasError() |
| 368 | $multiResultSet->getResponse()->isOk(); |
| 369 | } |
| 370 | |
| 371 | /** |
| 372 | * @param Search $search |
| 373 | * @param RequestLog $log |
| 374 | * @param Connection|null $connection |
| 375 | * @param callable|null $resultsTransformer that accepts a Multi/ResultSets |
| 376 | * @return Status |
| 377 | */ |
| 378 | protected function runMSearch( |
| 379 | Search $search, |
| 380 | RequestLog $log, |
| 381 | Connection $connection = null, |
| 382 | callable $resultsTransformer = null |
| 383 | ): Status { |
| 384 | $connection = $connection ?: $this->connection; |
| 385 | $this->start( $log ); |
| 386 | try { |
| 387 | $multiResultSet = $search->search(); |
| 388 | $lastRequest = $connection->getClient()->getLastRequest(); |
| 389 | if ( !$multiResultSet->getResponse()->isOk() ) { |
| 390 | // bad response from server. Should elastica be throwing an exception for this? |
| 391 | if ( $lastRequest !== null ) { |
| 392 | return $this->failure( new ResponseException( $lastRequest, $multiResultSet->getResponse() ), $connection ); |
| 393 | } else { |
| 394 | return $this->failure( new RuntimeException( "Client::getLastRequest() should not be null" ), $connection ); |
| 395 | } |
| 396 | } |
| 397 | foreach ( $multiResultSet->getResultSets() as $resultSet ) { |
| 398 | if ( $resultSet->getResponse()->hasError() ) { |
| 399 | if ( $lastRequest !== null ) { |
| 400 | return $this->failure( new ResponseException( $lastRequest, $resultSet->getResponse() ), $connection ); |
| 401 | } else { |
| 402 | return $this->failure( new RuntimeException( "Client::getLastRequest() should not be null" ), $connection ); |
| 403 | } |
| 404 | } |
| 405 | } |
| 406 | |
| 407 | return $this->success( $resultsTransformer !== null ? $resultsTransformer( $multiResultSet ) : $multiResultSet, $connection ); |
| 408 | } catch ( ExceptionInterface $e ) { |
| 409 | return $this->failure( $e, $connection ); |
| 410 | } |
| 411 | } |
| 412 | } |