objectStash = $objectStash; $options->assertRequiredOptions( self::CONSTRUCTOR_OPTIONS ); $this->options = $options; $this->localWikiID = $localWikiID; $this->statsd = $statsd; $this->logger = $logger; } /** * @param int|string $filter */ public function resetFilterProfile( $filter ) : void { $profileKey = $this->filterProfileKey( $filter ); $this->objectStash->delete( $profileKey ); } /** * Retrieve per-filter statistics. * * @param string|int $filter * @return array */ public function getFilterProfile( $filter ) : array { $profile = $this->objectStash->get( $this->filterProfileKey( $filter ) ); if ( $profile !== false ) { $curCount = $profile['count']; $curTotalTime = $profile['total-time']; $curTotalConds = $profile['total-cond']; } else { return [ 0, 0, 0, 0 ]; } // Return in milliseconds, rounded to 2dp $avgTime = round( $curTotalTime / $curCount, 2 ); $avgCond = round( $curTotalConds / $curCount, 1 ); return [ $curCount, $profile['matches'], $avgTime, $avgCond ]; } /** * Retrieve per-group statistics * @param string $group * @return array|false * @phan-return array{total:int,overflow:int,matches:int}|false */ public function getGroupProfile( string $group ) { return $this->objectStash->get( $this->filterProfileGroupKey( $group ) ); } /** * Record per-filter profiling data * * @param int $filter * @param float $time Time taken, in milliseconds * @param int $conds * @param bool $matched */ private function recordProfilingResult( int $filter, float $time, int $conds, bool $matched ) : void { // Defer updates to avoid massive (~1 second) edit time increases DeferredUpdates::addCallableUpdate( function () use ( $filter, $time, $conds, $matched ) { $profileKey = $this->filterProfileKey( $filter ); $profile = $this->objectStash->get( $profileKey ); if ( $profile !== false ) { // Number of observed executions of this filter $profile['count']++; if ( $matched ) { // Number of observed matches of this filter $profile['matches']++; } // Total time spent on this filter from all observed executions $profile['total-time'] += $time; // Total number of conditions for this filter from all executions $profile['total-cond'] += $conds; } else { $profile = [ 'count' => 1, 'matches' => (int)$matched, 'total-time' => $time, 'total-cond' => $conds ]; } // Note: It is important that all key information be stored together in a single // memcache entry to avoid race conditions where competing Apache instances // partially overwrite the stats. $this->objectStash->set( $profileKey, $profile, 3600 ); } ); } /** * Check if profiling data for all filters is lesser than the limit. If not, delete it and * also delete per-filter profiling for all filters. Note that we don't need to reset it for * disabled filters too, as their profiling data will be reset upon re-enabling anyway. * * @param string $group * @param array $allFilters */ public function checkResetProfiling( string $group, array $allFilters ) : void { $profileKey = $this->filterProfileGroupKey( $group ); $profile = $this->objectStash->get( $profileKey ); $total = $profile['total'] ?? 0; if ( $total > $this->options->get( 'AbuseFilterProfileActionsCap' ) ) { $this->objectStash->delete( $profileKey ); foreach ( $allFilters as $filter ) { $this->resetFilterProfile( $filter ); } } } /** * Update global statistics * * @param string $group * @param int $condsUsed The amount of used conditions * @param float $totalTime Time taken, in milliseconds * @param bool $anyMatch Whether at least one filter matched the action */ public function recordStats( string $group, int $condsUsed, float $totalTime, bool $anyMatch ) : void { $profileKey = $this->filterProfileGroupKey( $group ); // Note: All related data is stored in a single memcache entry and updated via merge() // to avoid race conditions where partial updates on competing instances corrupt the data. $this->objectStash->merge( $profileKey, function ( $cache, $key, $profile ) use ( $condsUsed, $totalTime, $anyMatch ) { if ( $profile === false ) { $profile = [ // Total number of actions observed 'total' => 0, // Number of actions ending by exceeding condition limit 'overflow' => 0, // Total time of execution of all observed actions 'total-time' => 0, // Total number of conditions from all observed actions 'total-cond' => 0, // Total number of filters matched 'matches' => 0 ]; } $profile['total']++; $profile['total-time'] += $totalTime; $profile['total-cond'] += $condsUsed; // Increment overflow counter, if our condition limit overflowed if ( $condsUsed > $this->options->get( 'AbuseFilterConditionLimit' ) ) { $profile['overflow']++; } // Increment counter by 1 if there was at least one match if ( $anyMatch ) { $profile['matches']++; } return $profile; }, self::STATS_STORAGE_PERIOD ); } /** * Record runtime profiling data for all filters together * * @param int $totalFilters * @param int $totalConditions * @param float $runtime */ public function recordRuntimeProfilingResult( int $totalFilters, int $totalConditions, float $runtime ) : void { $keyPrefix = 'abusefilter.runtime-profile.' . $this->localWikiID . '.'; $this->statsd->timing( $keyPrefix . 'runtime', $runtime ); $this->statsd->timing( $keyPrefix . 'total_filters', $totalFilters ); $this->statsd->timing( $keyPrefix . 'total_conditions', $totalConditions ); } /** * Record per-filter profiling, for all filters * * @param Title $title * @param array $data Profiling data, as stored in $this->profilingData * @phan-param array $data */ public function recordPerFilterProfiling( Title $title, array $data ) : void { foreach ( $data as $filterName => $params ) { list( $filterID, $global ) = AbuseFilter::splitGlobalName( $filterName ); if ( !$global ) { // @todo Maybe add a parameter to recordProfilingResult to record global filters // data separately (in the foreign wiki) $this->recordProfilingResult( $filterID, $params['time'], $params['conds'], $params['result'] ); } if ( $params['time'] > $this->options->get( 'AbuseFilterSlowFilterRuntimeLimit' ) ) { $this->recordSlowFilter( $title, $filterName, $params['time'], $params['conds'], $params['result'] ); } } } /** * Logs slow filter's runtime data for later analysis * * @param Title $title * @param string $filterId * @param float $runtime * @param int $totalConditions * @param bool $matched */ private function recordSlowFilter( Title $title, string $filterId, float $runtime, int $totalConditions, bool $matched ) : void { $this->logger->info( 'Edit filter {filter_id} on {wiki} is taking longer than expected', [ 'wiki' => $this->localWikiID, 'filter_id' => $filterId, 'title' => $title->getPrefixedText(), 'runtime' => $runtime, 'matched' => $matched, 'total_conditions' => $totalConditions ] ); } /** * Get the memcache access key used to store per-filter profiling data. * * @param string|int $filter * @return string */ private function filterProfileKey( $filter ) : string { return $this->objectStash->makeKey( 'abusefilter-profile', 'v3', $filter ); } /** * Memcache access key used to store overall profiling data for rule groups * * @param string $group * @return string */ private function filterProfileGroupKey( string $group ) : string { return $this->objectStash->makeKey( 'abusefilter-profile', 'group', $group ); } }