jenkins-bot has submitted this change and it was merged. ( https://gerrit.wikimedia.org/r/390342 )
Change subject: Added DonationsStats class to DonationQueueConsumer. ...................................................................... Added DonationsStats class to DonationQueueConsumer. Exported stats are scraped by Prometheus and then available to be graphed within Grafana. For full details of changes, read comment on phab ticket here: https://phabricator.wikimedia.org/T179173#3769446 Change-Id: Id5977cb3f2d3e8846d83ddf422c6569be75ea1e9 --- M composer.json M composer.lock M sites/all/modules/queue2civicrm/DonationQueueConsumer.php A sites/all/modules/queue2civicrm/DonationStats.php M sites/all/modules/queue2civicrm/queue2civicrm.info M sites/all/modules/queue2civicrm/queue2civicrm.module A sites/all/modules/queue2civicrm/tests/phpunit/DonationStatsTest.php 7 files changed, 502 insertions(+), 30 deletions(-) Approvals: jenkins-bot: Verified Ejegg: Looks good to me, approved diff --git a/composer.json b/composer.json index 72a398e..81456c6 100644 --- a/composer.json +++ b/composer.json @@ -25,7 +25,8 @@ "phpseclib/phpseclib": "~2.0", "predis/predis": "1.*", "twig/twig": "1.*", - "wikimedia/composer-merge-plugin": "^1.4" + "wikimedia/composer-merge-plugin": "^1.4", + "jackgleeson/stats-collector": "dev-master" }, "repositories": [ { diff --git a/composer.lock b/composer.lock index 9336700..09d405c 100644 --- a/composer.lock +++ b/composer.lock @@ -4,7 +4,7 @@ "Read more about it at https://getcomposer.org/doc/01-basic-usage.md#composer-lock-the-lock-file";, "This file is @generated automatically" ], - "content-hash": "32a4c6d1dba52d233ae8892c1908badf", + "content-hash": "f5b1e547c9865d17802925641c804265", "packages": [ { "name": "addshore/psr-6-mediawiki-bagostuff-adapter", @@ -88,7 +88,7 @@ "payment", "payments" ], - "time": "2016-02-17T00:44:20+00:00" + "time": "2016-02-17T00:53:20+00:00" }, { "name": "clio/clio", @@ -351,6 +351,65 @@ "description": "Powerful command-line option toolkit", "homepage": "http://github.com/c9s/GetOptionKit";, "time": "2017-06-30T14:54:48+00:00" + }, + { + "name": "dflydev/dot-access-data", + "version": "v1.1.0", + "source": { + "type": "git", + "url": "https://github.com/dflydev/dflydev-dot-access-data.git";, + "reference": "3fbd874921ab2c041e899d044585a2ab9795df8a" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/dflydev/dflydev-dot-access-data/zipball/3fbd874921ab2c041e899d044585a2ab9795df8a";, + "reference": "3fbd874921ab2c041e899d044585a2ab9795df8a", + "shasum": "" + }, + "require": { + "php": ">=5.3.2" + }, + "type": "library", + "extra": { + "branch-alias": { + "dev-master": "1.0-dev" + } + }, + "autoload": { + "psr-0": { + "Dflydev\\DotAccessData": "src" + } + }, + "notification-url": "https://packagist.org/downloads/";, + "license": [ + "MIT" + ], + "authors": [ + { + "name": "Dragonfly Development Inc.", + "email": "[email protected]", + "homepage": "http://dflydev.com"; + }, + { + "name": "Beau Simensen", + "email": "[email protected]", + "homepage": "http://beausimensen.com"; + }, + { + "name": "Carlos Frutos", + "email": "[email protected]", + "homepage": "https://github.com/cfrutos"; + } + ], + "description": "Given a deep data structure, access data by dot notation.", + "homepage": "https://github.com/dflydev/dflydev-dot-access-data";, + "keywords": [ + "access", + "data", + "dot", + "notation" + ], + "time": "2017-01-20T21:14:22+00:00" }, { "name": "geoip2/geoip2", @@ -627,6 +686,46 @@ "password" ], "time": "2014-11-20T16:49:30+00:00" + }, + { + "name": "jackgleeson/stats-collector", + "version": "dev-master", + "source": { + "type": "git", + "url": "https://github.com/jackgleeson/stats-collector.git";, + "reference": "1c792bbeac77d4781fbb788f341b601636696df5" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/jackgleeson/stats-collector/zipball/1c792bbeac77d4781fbb788f341b601636696df5";, + "reference": "1c792bbeac77d4781fbb788f341b601636696df5", + "shasum": "" + }, + "require": { + "dflydev/dot-access-data": "^1.1" + }, + "require-dev": { + "phpunit/phpunit": "^6.4" + }, + "type": "library", + "autoload": { + "psr-4": { + "Statistics\\": "src/", + "Samples\\": "samples/" + } + }, + "notification-url": "https://packagist.org/downloads/";, + "license": [ + "MIT" + ], + "authors": [ + { + "name": "Jack Gleeson", + "email": "[email protected]" + } + ], + "description": "Utility to help record, analyse and export statistics across any PHP process e.g. http request, batch jobs or cli-scrpts", + "time": "2017-11-22T13:56:02+00:00" }, { "name": "league/csv", @@ -2087,7 +2186,7 @@ "GPL-2.0" ], "description": "Wikimedia Foundation payment processing library", - "time": "2017-11-16 16:31:29" + "time": "2017-11-16T16:31:29+00:00" }, { "name": "wikimedia/omnimail-silverpop", @@ -3783,6 +3882,7 @@ "stability-flags": { "amzn/login-and-pay-with-amazon-sdk-php": 20, "wikimedia/donation-interface": 20, + "jackgleeson/stats-collector": 20, "wikimedia/omnimail-silverpop": 20, "mrmarkfrench/silverpop-php-connector": 20, "omnimail/omnimail": 20 diff --git a/sites/all/modules/queue2civicrm/DonationQueueConsumer.php b/sites/all/modules/queue2civicrm/DonationQueueConsumer.php index 3108d8c..56e744b 100644 --- a/sites/all/modules/queue2civicrm/DonationQueueConsumer.php +++ b/sites/all/modules/queue2civicrm/DonationQueueConsumer.php @@ -1,10 +1,9 @@ <?php namespace queue2civicrm; -use Queue2civicrmTrxnCounter; use SmashPig\Core\DataStores\PendingDatabase; -use SmashPig\Core\UtcDate; use wmf_common\TransactionalWmfQueueConsumer; use WmfException; +use DonationStats; class DonationQueueConsumer extends TransactionalWmfQueueConsumer { @@ -68,12 +67,9 @@ _queue2civicrm_log( $log ); } - $age = UtcDate::getUtcTimestamp() - UtcDate::getUtcTimestamp( $contribution['receive_date'] ); - - // keep count of the transactions - $counter = Queue2civicrmTrxnCounter::instance(); - $counter->increment( $message['gateway'] ); - $counter->addAgeMeasurement( $message['gateway'], $age ); + // record donations stats + $DonationStats = new DonationStats(); + $DonationStats->recordDonationStats( $message, $contribution ); // Delete any pending db entries with matching gateway and order_id PendingDatabase::get()->deleteMessage( $message ); diff --git a/sites/all/modules/queue2civicrm/DonationStats.php b/sites/all/modules/queue2civicrm/DonationStats.php new file mode 100644 index 0000000..1e930f4 --- /dev/null +++ b/sites/all/modules/queue2civicrm/DonationStats.php @@ -0,0 +1,209 @@ +<?php + +use Statistics\Collector\Collector; +use Statistics\Exporter\Prometheus as PrometheusStatsExporter; +use SmashPig\Core\UtcDate; + +/** + * Class DonationStats + * + * Handles donation stats recording & exporting using Stats Collector + * + * @see Collector + */ +class DonationStats { + + /** + * Default output filename for Prometheus .prom file + * + * @var string + */ + public $prometheusOutputFileName = "donations"; + + /** + * Custom Prometheus output file path. Default export behaviour is to use drupal global + * variable 'metrics_reporting_prometheus_path' unless this value is set. + * + * @var string + */ + public $prometheusOutputFilePath; + + /** + * @var Statistics\Collector\Collector + */ + public $statsCollector; + + public function __construct() { + $this->statsCollector = Collector::getInstance(); + // set the root namespace for all donation related stats + $this->statsCollector->ns("donations"); + } + + /** + * Record donation stats: + * 1) Number of donations by gateway + * 2) Number of overall donations + * 3) Time between gateway transaction time and civiCRM import time (now) + * 4) Gateway specific moving average of (3) + * 5) Overall moving average of (3) + * 6) Time between donation message enqueued time and civiCRM import time (now) + * 7) Gateway specific moving average of (6) + * 8) Overall moving average of (6) + * + * @param array $message + * @param array $contribution + */ + public function recordDonationStats($message, $contribution) { + $paymentGateway = $message['gateway']; + $gatewayTransactionTime = $contribution['receive_date']; + + // donation counter + $this->recordGatewayDonation($paymentGateway); + $this->recordOverallDonations(); + + // difference between gateway transaction time to civiCRM save time + $this->recordGatewayTransactionAge($paymentGateway, $gatewayTransactionTime); + $this->recordAverageGatewayTransactionAge($paymentGateway); + $this->recordOverallAverageGatewayTransactionAge(); + + // difference between message enqueued time to civiCRM save time + if (isset($message['source_enqueued_time'])) { + $messageEnqueuedTime = $message['source_enqueued_time']; + $this->recordMessageEnqueuedAge($paymentGateway, $messageEnqueuedTime); + $this->recordAverageGatewayMessageEnqueuedAge($paymentGateway); + $this->recordOverallAverageMessageEnqueuedAge(); + } + } + + /** + * Get overall average gateway transaction age at end of queue consumer batch run + * + * @return float|int + */ + public function getOverallAverageGatewayTransactionAge() { + return $this->statsCollector->get("overall.average.transaction_age"); + } + + /** + * Get overall average message age at end of queue consumer batch run + * + * @return float|int + */ + public function getOverallAverageMessageEnqueuedAge() { + return $this->statsCollector->get("overall.average.enqueued_age"); + } + + /** + * Export recorded stats to an output format to then be consumed upstream. + * + * Currently we only export to Prometheus. + */ + public function export() { + $this->exportToPrometheus(); + } + + /** + * Export stats data to a Prometheus .prom out file using the + * PrometheusStatsExporter exporter. + * + * @see PrometheusStatsExporter + */ + protected function exportToPrometheus() { + // get the output file name and file path + if (isset($this->prometheusOutputFilePath)) { + $path = $this->prometheusOutputFilePath; + } else { + $path = variable_get( + 'metrics_reporting_prometheus_path', '/var/spool/prometheus' + ); + } + $filename = $this->prometheusOutputFileName; + + // instantiate a Stats Collector Prometheus specific exporter and pass it the current + // instance of $statsCollector to then export all stats to {$path}/{$filename}.prom + $prometheusStatsExporter = new PrometheusStatsExporter($filename, $path); + $prometheusStatsExporter->export($this->statsCollector); + } + + /** + * Record a stat to count/increment the number of gateway specific donations + * + * @param string $paymentGateway + */ + protected function recordGatewayDonation($paymentGateway) { + $this->statsCollector->inc("gateway.{$paymentGateway}", 1); + } + + /** + * Set/update the current total count of all donations during this queue consumer run + */ + protected function recordOverallDonations() { + $this->statsCollector->clobber("overall.donations", $this->statsCollector->sum("gateway.*")); + } + + /** + * Record a stat for the difference between gateway transaction time to civiCRM save time + * + * @param string $paymentGateway + * @param $gatewayTransactionTime + */ + protected function recordGatewayTransactionAge($paymentGateway, $gatewayTransactionTime) { + // work out time between gateway's official transaction time and now + $gatewayReceivedAge = UtcDate::getUtcTimestamp() - UtcDate::getUtcTimestamp($gatewayTransactionTime); + $this->statsCollector->add("transaction_age.{$paymentGateway}", $gatewayReceivedAge); + } + + /** + * Set/update the current moving average of gateway transaction age + * + * @param string $paymentGateway + */ + protected function recordAverageGatewayTransactionAge($paymentGateway) { + $this->statsCollector->clobber("average.transaction_age.{$paymentGateway}", + $this->statsCollector->avg("transaction_age.{$paymentGateway}") + ); + } + + /** + * Set/update the overall current moving average for all payment gateway transaction ages + */ + protected function recordOverallAverageGatewayTransactionAge() { + $this->statsCollector->clobber("overall.average.transaction_age", + $this->statsCollector->avg("transaction_age.*") + ); + } + + /** + * Record a stat for the difference between message enqueued time to civiCRM save time + * + * @param string $paymentGateway + * @param $messageEnqueuedTime + */ + protected function recordMessageEnqueuedAge($paymentGateway, $messageEnqueuedTime) { + // work out time between the message enqueued time and now if 'source_enqueued_time' is set + $enqueuedAge = UtcDate::getUtcTimestamp() - $messageEnqueuedTime; + $this->statsCollector->add("enqueued_age.{$paymentGateway}", $enqueuedAge); + } + + /** + * Set/update the current moving average of gateway enqueued message ages + * + * @param string $paymentGateway + */ + protected function recordAverageGatewayMessageEnqueuedAge($paymentGateway) { + $this->statsCollector->clobber("average.enqueued_age.{$paymentGateway}", + $this->statsCollector->avg("enqueued_age.{$paymentGateway}") + ); + } + + /** + * Set/update the current moving average of enqueued message ages + */ + protected function recordOverallAverageMessageEnqueuedAge() { + $this->statsCollector->clobber("overall.average.enqueued_age", + $this->statsCollector->avg("enqueued_age.*") + ); + } + + +} \ No newline at end of file diff --git a/sites/all/modules/queue2civicrm/queue2civicrm.info b/sites/all/modules/queue2civicrm/queue2civicrm.info index 7363dd8..8bdf637 100644 --- a/sites/all/modules/queue2civicrm/queue2civicrm.info +++ b/sites/all/modules/queue2civicrm/queue2civicrm.info @@ -6,6 +6,7 @@ dependencies[] = wmf_civicrm package = queue2civicrm files[] = Queue2civicrmTrxnCounter.php +files[] = DonationStats.php files[] = DonationQueueConsumer.php files[] = tests/includes/Message.php files[] = tests/includes/TestingSmashPigDbQueueConfiguration.php diff --git a/sites/all/modules/queue2civicrm/queue2civicrm.module b/sites/all/modules/queue2civicrm/queue2civicrm.module index c15367e..cd2bf69 100644 --- a/sites/all/modules/queue2civicrm/queue2civicrm.module +++ b/sites/all/modules/queue2civicrm/queue2civicrm.module @@ -9,7 +9,7 @@ */ function queue2civicrm_menu() { $items = array(); - + $items['admin/config/queue2civicrm'] = array( 'title' => 'Queue to CiviCRM', 'access arguments' => array('administer queue2civicrm'), @@ -102,7 +102,7 @@ '#required' => TRUE, '#default_value' => variable_get('queue2civicrm_batch_time', 90), ); - + return system_settings_form($form); } @@ -137,7 +137,7 @@ /** * this may some day supersede the process counts handled above... - * + * * Note that this might be a little whack. At least, it feels a little sloppy. * We might consider specifying the names of gateways to keep track of, rather than auto-generate * the gateways to keep track of during queue consumption. With the latter (current) method, @@ -146,24 +146,17 @@ * * TODO: metrics stuff should be a hook */ - $counter = Queue2civicrmTrxnCounter::instance(); - $metrics = array(); - foreach ( $counter->get_trxn_counts() as $gateway => $count ) { - $metrics["${gateway}_donations"] = $count; - } - $metrics['total_donations'] = $counter->get_count_total(); - module_invoke( 'metrics_reporting', 'report_metrics', 'queue2civicrm', $metrics ); - $ageMetrics = array(); - foreach ( $counter->get_average_ages() as $gateway => $age ) { - $ageMetrics["${gateway}_message_age"] = $age; - } - module_invoke( 'metrics_reporting', 'report_metrics', 'donation_message_age', $ageMetrics ); + + $DonationStats = new DonationStats(); + $DonationStats->export(); if ($processed > 0) { watchdog('queue2civicrm', 'Successfully processed ' . $processed . ' contribution(s).'); - watchdog('queue2civicrm', 'Average message age: ' . $ageMetrics['overall_message_age'] . ' seconds.'); - } - else { + watchdog('queue2civicrm', + 'Average Transaction age: ' . $DonationStats->getOverallAverageGatewayTransactionAge() . ' seconds.'); + watchdog('queue2civicrm', + 'Average Message Enqueued age: ' . $DonationStats->getOverallAverageMessageEnqueuedAge() . ' seconds.'); + } else { watchdog('queue2civicrm', 'No contributions processed.'); } } diff --git a/sites/all/modules/queue2civicrm/tests/phpunit/DonationStatsTest.php b/sites/all/modules/queue2civicrm/tests/phpunit/DonationStatsTest.php new file mode 100644 index 0000000..c4a2f83 --- /dev/null +++ b/sites/all/modules/queue2civicrm/tests/phpunit/DonationStatsTest.php @@ -0,0 +1,172 @@ +<?php + +/** + * The tests for the testOverallAverage*() methods are admittedly a little confusing due to the + * DonationStats API not allowing access to individual stat values once recorded. + * + * However! fear not because even though testing averages to confirm individual records appears + * counter-intuitive, we are only adding a single donation per test meaning the averages will be + * identical be the individual values used per test because `avg(1) == 1` + * + * @group Queue2Civicrm + * @group DonationStats + */ +class DonationStatsTest extends BaseWmfDrupalPhpUnitTestCase { + + protected $statsFilename; + + protected $statsFilePath; + + protected $statsFileExtension; + + public function setUp() { + parent::setUp(); + $this->setupStatsCollector(); + } + + public function testOverallAverageGatewayTransactionAgeRecorded() { + $message = [ + 'gateway' => "ACME_PAYMENTS", + ]; + $contribution = [ + //simulate a transaction date 1 hour earlier from now() + 'receive_date' => \SmashPig\Core\UtcDate::getUtcDatabaseString('-1 hour'), + ]; + + $DonationStats = new DonationStats(); + $DonationStats->recordDonationStats($message, $contribution); + $OverallAverageGatewayTransactionAge = $DonationStats->getOverallAverageGatewayTransactionAge(); + + //compare recorded stats data with expected age in seconds (3600 seconds = 1 hour) + $this->assertEquals(3600, $OverallAverageGatewayTransactionAge); + } + + public function testOverallAverageMessageEnqueuedAgeRecordedWhenPresent() { + $message = [ + 'gateway' => "ACME_PAYMENTS", + // populating 'source_enqueued_time' with a timestamp one hour earlier from now() + 'source_enqueued_time' => \SmashPig\Core\UtcDate::getUtcTimestamp('-1 hour'), + ]; + $contribution = [ + 'receive_date' => \SmashPig\Core\UtcDate::getUtcDatabaseString('-1 hour'), + ]; + + $DonationStats = new DonationStats(); + $DonationStats->recordDonationStats($message, $contribution); + $OverallAverageMessageEnqueuedAge = $DonationStats->getOverallAverageMessageEnqueuedAge(); + + //compare written stats data with expected age in seconds (3600 seconds = 1 hour) + $this->assertEquals(3600, $OverallAverageMessageEnqueuedAge); + } + + public function testOverallAverageMessageEnqueuedAgeNotRecordedWhenNotPresent() { + $message = [ + 'gateway' => "ACME_PAYMENTS", + // omitting 'source_enqueued_time' + ]; + $contribution = [ + 'receive_date' => \SmashPig\Core\UtcDate::getUtcDatabaseString(), + ]; + + $DonationStats = new DonationStats(); + $DonationStats->recordDonationStats($message, $contribution); + $OverallAverageMessageEnqueuedAge = $DonationStats->getOverallAverageMessageEnqueuedAge(); + + $this->assertNull($OverallAverageMessageEnqueuedAge); + } + + public function testExportingStatsToFile() { + $this->setUpStatsOutFileProperties(); + $message = [ + 'gateway' => "ACME_PAYMENTS", + ]; + $contribution = [ + 'receive_date' => \SmashPig\Core\UtcDate::getUtcDatabaseString(), + ]; + + // test output file does not currently exist + $this->assertFileNotExists($this->statsFilePath . $this->statsFilename . $this->statsFileExtension); + + $DonationStats = new DonationStats(); + $DonationStats->recordDonationStats($message, $contribution); + $DonationStats->prometheusOutputFileName = $this->statsFilename; + $DonationStats->prometheusOutputFilePath = rtrim($this->statsFilePath, '/'); + $DonationStats->export(); + + //test output file has been created + $this->assertFileExists($this->statsFilePath . $this->statsFilename . $this->statsFileExtension); + + // clean up + $this->removeStatsOutFile(); + } + + public function testExportedStatsValues() { + $this->setUpStatsOutFileProperties(); + $message = [ + 'gateway' => "ACME_PAYMENTS", + ]; + $contribution = [ + //simulate a transaction date 1 hour earlier from now() + 'receive_date' => \SmashPig\Core\UtcDate::getUtcDatabaseString('-1 hour'), + ]; + + $DonationStats = new DonationStats(); + $DonationStats->recordDonationStats($message, $contribution); + $DonationStats->prometheusOutputFileName = $this->statsFilename; + $DonationStats->prometheusOutputFilePath = rtrim($this->statsFilePath, '/'); + $DonationStats->export(); + + $expectedStats = [ + 'donations_gateway_ACME_PAYMENTS' => 1, + 'donations_overall_donations' => 1, + 'donations_overall_average_transaction_age' => 3600, // should be -1 hour from now (3600 secs) + 'donations_average_transaction_age_ACME_PAYMENTS' => 3600, + 'donations_transaction_age_ACME_PAYMENTS' => 3600, + ]; + + $statsFileFullPath = $this->statsFilePath . $this->statsFilename . $this->statsFileExtension; + $statsWrittenAssocArray = []; + $statsWritten = rtrim(file_get_contents($statsFileFullPath)); // remove trailing \n + $statsWrittenLinesArray = explode("\n", $statsWritten); + foreach ($statsWrittenLinesArray as $statsLine) { + list($name, $value) = explode(' ', $statsLine); + $statsWrittenAssocArray[$name] = $value; + } + + //compare written stats data with expected + $this->assertEquals($expectedStats, $statsWrittenAssocArray); + + // clean up + $this->removeStatsOutFile(); + } + + public function tearDown() { + parent::tearDown(); + } + + private function setUpStatsOutFileProperties() { + $this->statsFilename = "test_stats"; + $this->statsFilePath = CRM_Utils_File::tempdir(); + $this->statsFileExtension = '.prom'; + } + + private function removeStatsOutFile() { + unlink($this->statsFilePath . $this->statsFilename . $this->statsFileExtension); + rmdir($this->statsFilePath); + } + + /** + * Stats Collector singleton (used internally by DonationStats) needs resetting before each test. + * + * DonationQueueTest indirectly records stats when calling + * DonationQueueConsumer::processMessage() so we clear all instances before each run to test + * from a known starting point. + * + * @see DonationQueueTest + */ + private function setupStatsCollector() { + \Statistics\Collector\Collector::tearDown(TRUE); + } + + +} -- To view, visit https://gerrit.wikimedia.org/r/390342 To unsubscribe, visit https://gerrit.wikimedia.org/r/settings Gerrit-MessageType: merged Gerrit-Change-Id: Id5977cb3f2d3e8846d83ddf422c6569be75ea1e9 Gerrit-PatchSet: 13 Gerrit-Project: wikimedia/fundraising/crm Gerrit-Branch: master Gerrit-Owner: Jgleeson <[email protected]> Gerrit-Reviewer: AndyRussG <[email protected]> Gerrit-Reviewer: Cdentinger <[email protected]> Gerrit-Reviewer: Eileen <[email protected]> Gerrit-Reviewer: Ejegg <[email protected]> Gerrit-Reviewer: Katie Horn <[email protected]> Gerrit-Reviewer: Mepps <[email protected]> Gerrit-Reviewer: XenoRyet <[email protected]> Gerrit-Reviewer: jenkins-bot <> _______________________________________________ MediaWiki-commits mailing list [email protected] https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits
