From 5819ded0ed228e0de105000d92da26531c07785a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=C5=81ukasz=20Bajsarowicz?= Date: Fri, 19 Jul 2019 11:33:26 +0200 Subject: [PATCH] Add Cron Jobs names to New Relic transactions --- .../Observer/ProcessCronQueueObserver.php | 54 ++++++--- .../Model/NewRelicWrapper.php | 19 +++- .../Plugin/CommandPlugin.php | 30 ++++- .../NewRelicReporting/Plugin/StatPlugin.php | 105 ++++++++++++++++++ .../Test/Unit/Plugin/CommandPluginTest.php | 105 ++++++++++++++++++ .../Test/Unit/Plugin/StatPluginTest.php | 97 ++++++++++++++++ app/code/Magento/NewRelicReporting/etc/di.xml | 12 +- 7 files changed, 400 insertions(+), 22 deletions(-) create mode 100644 app/code/Magento/NewRelicReporting/Plugin/StatPlugin.php create mode 100644 app/code/Magento/NewRelicReporting/Test/Unit/Plugin/CommandPluginTest.php create mode 100644 app/code/Magento/NewRelicReporting/Test/Unit/Plugin/StatPluginTest.php diff --git a/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php b/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php index 5c8aa1dc78abd..053ba43c1c20e 100644 --- a/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php +++ b/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php @@ -3,9 +3,11 @@ * Copyright © Magento, Inc. All rights reserved. * See COPYING.txt for license details. */ + /** * Handling cron jobs */ + namespace Magento\Cron\Observer; use Magento\Cron\Model\Schedule; @@ -69,6 +71,11 @@ class ProcessCronQueueObserver implements ObserverInterface */ const LOCK_PREFIX = 'CRON_GROUP_'; + /** + * Cron Job name pattern for Profiling + */ + const CRON_TIMERID = 'job %s'; + /** * @var \Magento\Cron\Model\ResourceModel\Schedule\Collection */ @@ -311,7 +318,7 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, $schedule->setExecutedAt(strftime('%Y-%m-%d %H:%M:%S', $this->dateTime->gmtTimestamp()))->save(); - $this->startProfiling(); + $this->startProfiling($jobCode); try { $this->logger->info(sprintf('Cron Job %s is run', $jobCode)); //phpcs:ignore Magento2.Functions.DiscouragedFunction @@ -323,7 +330,7 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, 'Cron Job %s has an error: %s. Statistics: %s', $jobCode, $e->getMessage(), - $this->getProfilingStat() + $this->getProfilingStat($jobCode) ) ); if (!$e instanceof \Exception) { @@ -335,7 +342,7 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, } throw $e; } finally { - $this->stopProfiling(); + $this->stopProfiling($jobCode); } $schedule->setStatus( @@ -351,7 +358,7 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, sprintf( 'Cron Job %s is successfully finished. Statistics: %s', $jobCode, - $this->getProfilingStat() + $this->getProfilingStat($jobCode) ) ); } @@ -359,32 +366,47 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, /** * Starts profiling * + * @param string $jobName * @return void */ - private function startProfiling() + private function startProfiling(string $jobName = '') { $this->statProfiler->clear(); - $this->statProfiler->start('job', microtime(true), memory_get_usage(true), memory_get_usage()); + $this->statProfiler->start( + sprintf(self::CRON_TIMERID, $jobName), + microtime(true), + memory_get_usage(true), + memory_get_usage() + ); } /** * Stops profiling * + * @param string $jobName * @return void */ - private function stopProfiling() + private function stopProfiling(string $jobName = '') { - $this->statProfiler->stop('job', microtime(true), memory_get_usage(true), memory_get_usage()); + $this->statProfiler->stop( + sprintf(self::CRON_TIMERID, $jobName), + microtime(true), + memory_get_usage(true), + memory_get_usage() + ); } /** * Retrieves statistics in the JSON format * + * @param string $jobName * @return string */ - private function getProfilingStat() + private function getProfilingStat(string $jobName): string { - $stat = $this->statProfiler->get('job'); + $stat = $this->statProfiler->get( + sprintf(self::CRON_TIMERID, $jobName) + ); unset($stat[Stat::START]); return json_encode($stat); } @@ -418,7 +440,9 @@ private function getNonExitedSchedules($groupId) 'status', [ 'in' => [ - Schedule::STATUS_PENDING, Schedule::STATUS_RUNNING, Schedule::STATUS_SUCCESS + Schedule::STATUS_PENDING, + Schedule::STATUS_RUNNING, + Schedule::STATUS_SUCCESS ] ] ); @@ -478,10 +502,10 @@ private function generateSchedules($groupId) /** * Generate jobs for config information * - * @param array $jobs - * @param array $exists - * @param string $groupId - * @return void + * @param array $jobs + * @param array $exists + * @param string $groupId + * @return void */ protected function _generateJobs($jobs, $exists, $groupId) { diff --git a/app/code/Magento/NewRelicReporting/Model/NewRelicWrapper.php b/app/code/Magento/NewRelicReporting/Model/NewRelicWrapper.php index bce42b4e90074..fa7f2f1090629 100644 --- a/app/code/Magento/NewRelicReporting/Model/NewRelicWrapper.php +++ b/app/code/Magento/NewRelicReporting/Model/NewRelicWrapper.php @@ -5,6 +5,8 @@ */ namespace Magento\NewRelicReporting\Model; +use Exception; + /** * Wrapper for New Relic functions * @@ -31,10 +33,10 @@ public function addCustomParameter($param, $value) /** * Wrapper for 'newrelic_notice_error' function * - * @param \Exception $exception + * @param Exception $exception * @return void */ - public function reportError($exception) + public function reportError(Exception $exception) { if ($this->isExtensionInstalled()) { newrelic_notice_error($exception->getMessage(), $exception); @@ -67,6 +69,19 @@ public function setTransactionName(string $transactionName): void } } + /** + * Wrapper for 'newrelic_end_transaction' + * + * @param bool $ignore + * @return void + */ + public function endTransaction($ignore = false) + { + if ($this->isExtensionInstalled()) { + newrelic_end_transaction($ignore); + } + } + /** * Checks whether newrelic-php5 agent is installed * diff --git a/app/code/Magento/NewRelicReporting/Plugin/CommandPlugin.php b/app/code/Magento/NewRelicReporting/Plugin/CommandPlugin.php index 04ad3d0504d34..d21f972da57c6 100644 --- a/app/code/Magento/NewRelicReporting/Plugin/CommandPlugin.php +++ b/app/code/Magento/NewRelicReporting/Plugin/CommandPlugin.php @@ -25,16 +25,24 @@ class CommandPlugin */ private $newRelicWrapper; + /** + * @var string[] + */ + private $skipCommands; + /** * @param Config $config * @param NewRelicWrapper $newRelicWrapper + * @param array $skipCommands */ public function __construct( Config $config, - NewRelicWrapper $newRelicWrapper + NewRelicWrapper $newRelicWrapper, + array $skipCommands = [] ) { $this->config = $config; $this->newRelicWrapper = $newRelicWrapper; + $this->skipCommands = $skipCommands; } /** @@ -46,10 +54,24 @@ public function __construct( */ public function beforeRun(Command $command, ...$args) { - $this->newRelicWrapper->setTransactionName( - sprintf('CLI %s', $command->getName()) - ); + if (!$this->isCommandSkipped($command)) { + $this->newRelicWrapper->setTransactionName( + sprintf('CLI %s', $command->getName()) + ); + } return $args; } + + /** + * Determines whether the Command is declared to be skipped + * + * @param Command $command + * @return bool + */ + private function isCommandSkipped(Command $command): bool + { + $commandName = $command->getName(); + return isset($this->skipCommands[$commandName]) && $this->skipCommands[$commandName] === true; + } } diff --git a/app/code/Magento/NewRelicReporting/Plugin/StatPlugin.php b/app/code/Magento/NewRelicReporting/Plugin/StatPlugin.php new file mode 100644 index 0000000000000..30dddfe11910a --- /dev/null +++ b/app/code/Magento/NewRelicReporting/Plugin/StatPlugin.php @@ -0,0 +1,105 @@ +config = $config; + $this->newRelicWrapper = $newRelicWrapper; + $this->logger = $logger; + } + + /** + * Before running original profiler, register NewRelic transaction + * + * @param Stat $schedule + * @param array $args + * @return array + * @see \Magento\Cron\Observer\ProcessCronQueueObserver::startProfiling + * + * @SuppressWarnings(PHPMD.UnusedFormalParameter) + */ + public function beforeStart(Stat $schedule, ...$args): array + { + $timerName = current($args); + + if ($this->isCronJob($timerName)) { + $this->newRelicWrapper->setTransactionName( + sprintf('Cron %s', $timerName) + ); + } + + return $args; + } + + /** + * Before stopping original profiler, close NewRelic transaction + * + * @param Stat $schedule + * @param array $args + * @return array + * + * @SuppressWarnings(PHPMD.UnusedFormalParameter) + */ + public function beforeStop(Stat $schedule, ...$args): array + { + $timerName = current($args); + + if ($this->isCronJob($timerName)) { + $this->newRelicWrapper->endTransaction(); + } + + return $args; + } + + /** + * Determines whether provided name is Cron Job + * + * @param string $timerName + * @return bool + */ + private function isCronJob(string $timerName): bool + { + return 0 === strpos($timerName, static::TIMER_NAME_CRON_PREFIX); + } +} diff --git a/app/code/Magento/NewRelicReporting/Test/Unit/Plugin/CommandPluginTest.php b/app/code/Magento/NewRelicReporting/Test/Unit/Plugin/CommandPluginTest.php new file mode 100644 index 0000000000000..f75997a6302bb --- /dev/null +++ b/app/code/Magento/NewRelicReporting/Test/Unit/Plugin/CommandPluginTest.php @@ -0,0 +1,105 @@ +newRelicWrapperMock = $this->getMockBuilder(NewRelicWrapper::class) + ->disableOriginalConstructor() + ->setMethods(['setTransactionName']) + ->getMock(); + + $this->objectManager = new ObjectManager($this); + } + + /** + * When Command name is not in the list of skipped, handle New Relic transaction + */ + public function testNewRelicTransactionSetForNonSkippedCommand() + { + $nonSkippedCommand = $this->getCommandMock(self::STUB_NON_SKIPPED_COMMAND_NAME); + + $this->newRelicWrapperMock->expects($this->once()) + ->method('setTransactionName') + ->with(sprintf('CLI %s', self::STUB_NON_SKIPPED_COMMAND_NAME)); + + $commandPlugin = $this->getCommandPlugin([self::STUB_SKIPPED_COMMAND_NAME => true]); + $commandPlugin->beforeRun($nonSkippedCommand); + } + + /** + * When Command name is set to be skipped, do not let run New Relic transaction + */ + public function testNewRelicTransactionOmmitForSkippedCommand() + { + $skippedCommand = $this->getCommandMock(self::STUB_SKIPPED_COMMAND_NAME); + + $this->newRelicWrapperMock->expects($this->never()) + ->method('setTransactionName'); + + $commandPlugin = $this->getCommandPlugin([self::STUB_SKIPPED_COMMAND_NAME => true]); + $commandPlugin->beforeRun($skippedCommand); + } + + /** + * @param string $commandName + * @return Command|MockObject + */ + private function getCommandMock(string $commandName): Command + { + $commandMock = $this->getMockBuilder(Command::class) + ->disableOriginalConstructor() + ->setMethods(['getName']) + ->getMock(); + + $commandMock->method('getName') + ->willReturn($commandName); + + return $commandMock; + } + + /** + * @param string[] $skippedCommands + * @return CommandPlugin + */ + private function getCommandPlugin(array $skippedCommands): CommandPlugin + { + /** @var CommandPlugin $commandPlugin */ + $commandPlugin = $this->objectManager->getObject(CommandPlugin::class, [ + 'skipCommands' => $skippedCommands, + 'newRelicWrapper' => $this->newRelicWrapperMock + ]); + + return $commandPlugin; + } +} diff --git a/app/code/Magento/NewRelicReporting/Test/Unit/Plugin/StatPluginTest.php b/app/code/Magento/NewRelicReporting/Test/Unit/Plugin/StatPluginTest.php new file mode 100644 index 0000000000000..163f9a69992ed --- /dev/null +++ b/app/code/Magento/NewRelicReporting/Test/Unit/Plugin/StatPluginTest.php @@ -0,0 +1,97 @@ +statPlugin = $objectManager->getObject(StatPlugin::class, [ + 'newRelicWrapper' => $this->getNewRelicWrapperMock() + ]); + + $this->statMock = $this->getMockBuilder(Stat::class)->disableOriginalConstructor()->getMock(); + } + + /** + * Expects that NewRelic wrapper will never be called + */ + public function testNewRelicTransactionNameIsNotSetIfNotCronjobPattern() + { + $this->newRelicWrapperMock + ->expects($this->never()) + ->method('setTransactionName'); + $this->newRelicWrapperMock + ->expects($this->never()) + ->method('endTransaction'); + + $this->statPlugin->beforeStart($this->statMock, self::STAT_NAME_NOT_CRON_JOB); + $this->statPlugin->beforeStop($this->statMock, self::STAT_NAME_NOT_CRON_JOB); + } + + /** + * NewRelic Wrapper is called when Task name fits Cron Job pattern + */ + public function testNewRelicTransactionNameIsSetForCronjobNamePattern() + { + $this->newRelicWrapperMock + ->expects($this->once()) + ->method('setTransactionName'); + $this->newRelicWrapperMock + ->expects($this->once()) + ->method('endTransaction'); + + $this->statPlugin->beforeStart($this->statMock, self::STAT_NAME_CRON_JOB); + $this->statPlugin->beforeStop($this->statMock, self::STAT_NAME_CRON_JOB); + } + + /** + * @return NewRelicWrapper + */ + private function getNewRelicWrapperMock(): NewRelicWrapper + { + if (null === $this->newRelicWrapperMock) { + $this->newRelicWrapperMock = $this->getMockBuilder(NewRelicWrapper::class) + ->disableOriginalConstructor() + ->setMethods(['setTransactionName', 'endTransaction']) + ->getMock(); + } + + return $this->newRelicWrapperMock; + } +} diff --git a/app/code/Magento/NewRelicReporting/etc/di.xml b/app/code/Magento/NewRelicReporting/etc/di.xml index 15516f6df89be..cd8b0f46087a4 100644 --- a/app/code/Magento/NewRelicReporting/etc/di.xml +++ b/app/code/Magento/NewRelicReporting/etc/di.xml @@ -41,6 +41,16 @@ - + + + + + + + + + true + +