jenkins-bot has submitted this change and it was merged. ( https://gerrit.wikimedia.org/r/373561 )
Change subject: Add runtime metrics to statsd ...................................................................... Add runtime metrics to statsd Metrics per edit: - Execution time of all filters - Number of filters executed - Number of conditions executed Due to the current structure of abuse filter there was not a clean way to include filter actions and abuselog creation as part of the runtime metrics. Bug: T161059 Change-Id: I6208b620453863133c6623aa419775f63c7d3eb1 --- M AbuseFilter.php M extension.json M includes/AbuseFilter.class.php 3 files changed, 49 insertions(+), 4 deletions(-) Approvals: MaxSem: Looks good to me, approved jenkins-bot: Verified diff --git a/AbuseFilter.php b/AbuseFilter.php index 4a06b06..7f13eaf 100644 --- a/AbuseFilter.php +++ b/AbuseFilter.php @@ -117,3 +117,8 @@ * Whether to record the average time taken and average number of conditions used by each filter. */ $wgAbuseFilterProfile = false; + +/** + * Whether to record runtime metrics for all filters combined. + */ +$wgAbuseFilterRuntimeProfile = false; diff --git a/extension.json b/extension.json index f8d3abc..a043b6c 100644 --- a/extension.json +++ b/extension.json @@ -248,7 +248,8 @@ "_merge_strategy": "array_plus" }, "AbuseFilterLogIPMaxAge": 7776000, - "AbuseFilterProfile": false + "AbuseFilterProfile": false, + "AbuseFilterRuntimeProfile": false }, "load_composer_autoloader": true, "manifest_version": 1 diff --git a/includes/AbuseFilter.class.php b/includes/AbuseFilter.class.php index 4b1418f..e72c7c5 100644 --- a/includes/AbuseFilter.class.php +++ b/includes/AbuseFilter.class.php @@ -878,7 +878,7 @@ public static function filterAction( $vars, $title, $group = 'default', $user = null, $mode = 'execute' ) { - global $wgUser, $wgTitle, $wgRequest; + global $wgUser, $wgTitle, $wgRequest, $wgAbuseFilterRuntimeProfile; $context = RequestContext::getMain(); $oldContextTitle = $context->getTitle(); @@ -905,6 +905,10 @@ $cache = ObjectCache::getLocalClusterInstance(); $stashKey = self::getStashKey( $cache, $vars, $group ); $isForEdit = ( $vars->getVar( 'action' )->toString() === 'edit' ); + + if ( $wgAbuseFilterRuntimeProfile ) { + $startTime = microtime( true ); + } $filter_matched = false; if ( $mode === 'execute' && $isForEdit ) { @@ -933,6 +937,13 @@ if ( $mode === 'stash' ) { // Save the filter stash result and do nothing further $cacheData = [ 'matches' => $filter_matched, 'tags' => self::$tagsToSet ]; + + // Add runtime metrics in cache for later use + if ( $wgAbuseFilterRuntimeProfile ) { + $cacheData['condCount'] = self::$condCount; + $cacheData['runtime'] = ( microtime( true ) - $startTime ) * 1000; + } + $cache->set( $stashKey, $cacheData, $cache::TTL_MINUTE ); $logger->debug( __METHOD__ . ": cache store for '$title' (key $stashKey)." ); $statsd->increment( 'abusefilter.check-stash.store' ); @@ -942,13 +953,24 @@ $matched_filters = array_keys( array_filter( $filter_matched ) ); + // Save runtime metrics only on edits + if ( $wgAbuseFilterRuntimeProfile && $mode === 'execute' && $isForEdit ) { + if ( $cacheData ) { + $runtime = $cacheData['runtime']; + $condCount = $cacheData['condCount']; + } else { + $runtime = ( microtime( true ) - $startTime ) * 1000; + $condCount = self::$condCount; + } + + self::recordRuntimeProfilingResult( count( $matched_filters ), $condCount, $runtime ); + } + if ( count( $matched_filters ) == 0 ) { $status = Status::newGood(); } else { $status = self::executeFilterActions( $matched_filters, $title, $vars ); - $actions_taken = $status->getValue(); - $action = $vars->getVar( 'ACTION' )->toString(); // If $wgUser isn't safe to load (e.g. a failure during @@ -980,6 +1002,7 @@ if ( $wgTitle !== $oldWgTitle ) { $wgTitle = $oldWgTitle; } + if ( $context->getTitle() !== $oldContextTitle && $oldContextTitle instanceof Title ) { $context->setTitle( $oldContextTitle ); } @@ -1746,6 +1769,22 @@ } /** + * Record runtime profiling data + * + * @param int $totalFilters + * @param int $totalConditions + * @param float $runtime + */ + private static function recordRuntimeProfilingResult( $totalFilters, $totalConditions, $runtime ) { + $keyPrefix = 'abusefilter.runtime-profile.' . wfWikiID() . '.'; + + $statsd = MediaWikiServices::getInstance()->getStatsdDataFactory(); + $statsd->timing( $keyPrefix . 'runtime', $runtime ); + $statsd->timing( $keyPrefix . 'total_filters', $totalFilters ); + $statsd->timing( $keyPrefix . 'total_conditions', $totalConditions ); + } + + /** * @param string $group The filter's group (as defined in $wgAbuseFilterValidGroups) * @param string[] $filters * @param int $total -- To view, visit https://gerrit.wikimedia.org/r/373561 To unsubscribe, visit https://gerrit.wikimedia.org/r/settings Gerrit-MessageType: merged Gerrit-Change-Id: I6208b620453863133c6623aa419775f63c7d3eb1 Gerrit-PatchSet: 3 Gerrit-Project: mediawiki/extensions/AbuseFilter Gerrit-Branch: master Gerrit-Owner: Dmaza <dm...@wikimedia.org> Gerrit-Reviewer: Dmaza <dm...@wikimedia.org> Gerrit-Reviewer: Jackmcbarn <jackmcb...@gmail.com> Gerrit-Reviewer: Kaldari <rkald...@wikimedia.org> Gerrit-Reviewer: MaxSem <maxsem.w...@gmail.com> Gerrit-Reviewer: jenkins-bot <> _______________________________________________ MediaWiki-commits mailing list MediaWiki-commits@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits