diff --git a/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php b/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php index 6b0c405167af7..93d86e3c48c9b 100644 --- a/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php +++ b/app/code/Magento/Cron/Observer/ProcessCronQueueObserver.php @@ -13,6 +13,8 @@ use Magento\Framework\Console\Cli; use Magento\Framework\Event\ObserverInterface; use \Magento\Cron\Model\Schedule; +use Magento\Framework\Profiler\Driver\Standard\Stat; +use Magento\Framework\Profiler\Driver\Standard\StatFactory; /** * @SuppressWarnings(PHPMD.CouplingBetweenObjects) @@ -56,6 +58,16 @@ class ProcessCronQueueObserver implements ObserverInterface */ const SECONDS_IN_MINUTE = 60; + /** + * How long to wait for cron group to become unlocked + */ + const LOCK_TIMEOUT = 5; + + /** + * Static lock prefix for cron group locking + */ + const LOCK_PREFIX = 'CRON_GROUP_'; + /** * @var \Magento\Cron\Model\ResourceModel\Schedule\Collection */ @@ -116,15 +128,20 @@ class ProcessCronQueueObserver implements ObserverInterface */ private $state; + /** + * @var \Magento\Framework\Lock\LockManagerInterface + */ + private $lockManager; + /** * @var array */ private $invalid = []; /** - * @var array + * @var Stat */ - private $jobs; + private $statProfiler; /** * @param \Magento\Framework\ObjectManagerInterface $objectManager @@ -138,6 +155,7 @@ class ProcessCronQueueObserver implements ObserverInterface * @param \Magento\Framework\Process\PhpExecutableFinderFactory $phpExecutableFinderFactory * @param \Psr\Log\LoggerInterface $logger * @param \Magento\Framework\App\State $state + * @param StatFactory $statFactory * @SuppressWarnings(PHPMD.ExcessiveParameterList) */ public function __construct( @@ -151,7 +169,9 @@ public function __construct( \Magento\Framework\Stdlib\DateTime\DateTime $dateTime, \Magento\Framework\Process\PhpExecutableFinderFactory $phpExecutableFinderFactory, \Psr\Log\LoggerInterface $logger, - \Magento\Framework\App\State $state + \Magento\Framework\App\State $state, + StatFactory $statFactory, + \Magento\Framework\Lock\LockManagerInterface $lockManager ) { $this->_objectManager = $objectManager; $this->_scheduleFactory = $scheduleFactory; @@ -164,6 +184,8 @@ public function __construct( $this->phpExecutableFinder = $phpExecutableFinderFactory->create(); $this->logger = $logger; $this->state = $state; + $this->statProfiler = $statFactory->create(); + $this->lockManager = $lockManager; } /** @@ -179,27 +201,26 @@ public function __construct( */ public function execute(\Magento\Framework\Event\Observer $observer) { - $pendingJobs = $this->_getPendingSchedules(); + $currentTime = $this->dateTime->gmtTimestamp(); $jobGroupsRoot = $this->_config->getJobs(); + // sort jobs groups to start from used in separated process + uksort( + $jobGroupsRoot, + function ($a, $b) { + return $this->getCronGroupConfigurationValue($b, 'use_separate_process') + - $this->getCronGroupConfigurationValue($a, 'use_separate_process'); + } + ); $phpPath = $this->phpExecutableFinder->find() ?: 'php'; foreach ($jobGroupsRoot as $groupId => $jobsRoot) { - $this->_cleanup($groupId); - $this->_generate($groupId); - if ($this->_request->getParam('group') !== null - && $this->_request->getParam('group') !== '\'' . ($groupId) . '\'' - && $this->_request->getParam('group') !== $groupId - ) { + if (!$this->isGroupInFilter($groupId)) { continue; } - if (($this->_request->getParam(self::STANDALONE_PROCESS_STARTED) !== '1') && ( - $this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/use_separate_process', - \Magento\Store\Model\ScopeInterface::SCOPE_STORE - ) == 1 - ) + if ($this->_request->getParam(self::STANDALONE_PROCESS_STARTED) !== '1' + && $this->getCronGroupConfigurationValue($groupId, 'use_separate_process') == 1 ) { $this->_shell->execute( $phpPath . ' %s cron:run --group=' . $groupId . ' --' . Cli::INPUT_KEY_BOOTSTRAP . '=' @@ -211,42 +232,43 @@ public function execute(\Magento\Framework\Event\Observer $observer) continue; } - /** @var \Magento\Cron\Model\Schedule $schedule */ - foreach ($pendingJobs as $schedule) { - $jobConfig = isset($jobsRoot[$schedule->getJobCode()]) ? $jobsRoot[$schedule->getJobCode()] : null; - if (!$jobConfig) { - continue; + $this->lockGroup( + $groupId, + function ($groupId) use ($currentTime, $jobsRoot) { + $this->cleanupJobs($groupId, $currentTime); + $this->generateSchedules($groupId); + $this->processPendingJobs($groupId, $jobsRoot, $currentTime); } + ); + } + } - $scheduledTime = strtotime($schedule->getScheduledAt()); - if ($scheduledTime > $currentTime) { - continue; - } + /** + * Lock group + * + * It should be taken by standalone (child) process, not by the parent process. + * + * @param int $groupId + * @param callable $callback + * + * @return void + */ + private function lockGroup($groupId, callable $callback) + { - try { - if ($schedule->tryLockJob()) { - $this->_runJob($scheduledTime, $currentTime, $jobConfig, $schedule, $groupId); - } - } catch (\Exception $e) { - $schedule->setMessages($e->getMessage()); - if ($schedule->getStatus() === Schedule::STATUS_ERROR) { - $this->logger->critical($e); - } - if ($schedule->getStatus() === Schedule::STATUS_MISSED - && $this->state->getMode() === State::MODE_DEVELOPER - ) { - $this->logger->info( - sprintf( - "%s Schedule Id: %s Job Code: %s", - $schedule->getMessages(), - $schedule->getScheduleId(), - $schedule->getJobCode() - ) - ); - } - } - $schedule->save(); - } + if (!$this->lockManager->lock(self::LOCK_PREFIX . $groupId, self::LOCK_TIMEOUT)) { + $this->logger->warning( + sprintf( + "Could not acquire lock for cron group: %s, skipping run", + $groupId + ) + ); + return; + } + try { + $callback($groupId); + } finally { + $this->lockManager->unlock(self::LOCK_PREFIX . $groupId); } } @@ -263,14 +285,12 @@ public function execute(\Magento\Framework\Event\Observer $observer) */ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, $groupId) { - $scheduleLifetime = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_SCHEDULE_LIFETIME, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE - ); + $jobCode = $schedule->getJobCode(); + $scheduleLifetime = $this->getCronGroupConfigurationValue($groupId, self::XML_PATH_SCHEDULE_LIFETIME); $scheduleLifetime = $scheduleLifetime * self::SECONDS_IN_MINUTE; if ($scheduledTime < $currentTime - $scheduleLifetime) { $schedule->setStatus(Schedule::STATUS_MISSED); - throw new \Exception('Too late for the schedule'); + throw new \Exception(sprintf('Cron Job %s is missed at %s', $jobCode, $schedule->getScheduledAt())); } if (!isset($jobConfig['instance'], $jobConfig['method'])) { @@ -288,10 +308,18 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, $schedule->setExecutedAt(strftime('%Y-%m-%d %H:%M:%S', $this->dateTime->gmtTimestamp()))->save(); + $this->startProfiling(); try { + $this->logger->info(sprintf('Cron Job %s is run', $jobCode)); call_user_func_array($callback, [$schedule]); } catch (\Throwable $e) { $schedule->setStatus(Schedule::STATUS_ERROR); + $this->logger->error(sprintf( + 'Cron Job %s has an error: %s. Statistics: %s', + $jobCode, + $e->getMessage(), + $this->getProfilingStat() + )); if (!$e instanceof \Exception) { $e = new \RuntimeException( 'Error when running a cron job', @@ -300,12 +328,53 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, ); } throw $e; + } finally { + $this->stopProfiling(); } $schedule->setStatus(Schedule::STATUS_SUCCESS)->setFinishedAt(strftime( '%Y-%m-%d %H:%M:%S', $this->dateTime->gmtTimestamp() )); + + $this->logger->info(sprintf( + 'Cron Job %s is successfully finished. Statistics: %s', + $jobCode, + $this->getProfilingStat() + )); + } + + /** + * Starts profiling + * + * @return void + */ + private function startProfiling() + { + $this->statProfiler->clear(); + $this->statProfiler->start('job', microtime(true), memory_get_usage(true), memory_get_usage()); + } + + /** + * Stops profiling + * + * @return void + */ + private function stopProfiling() + { + $this->statProfiler->stop('job', microtime(true), memory_get_usage(true), memory_get_usage()); + } + + /** + * Retrieves statistics in the JSON format + * + * @return string + */ + private function getProfilingStat() + { + $stat = $this->statProfiler->get('job'); + unset($stat[Stat::START]); + return json_encode($stat); } /** @@ -313,15 +382,13 @@ protected function _runJob($scheduledTime, $currentTime, $jobConfig, $schedule, * * @return \Magento\Cron\Model\ResourceModel\Schedule\Collection */ - protected function _getPendingSchedules() + private function getPendingSchedules($groupId) { - if (!$this->_pendingSchedules) { - $this->_pendingSchedules = $this->_scheduleFactory->create()->getCollection()->addFieldToFilter( - 'status', - Schedule::STATUS_PENDING - )->load(); - } - return $this->_pendingSchedules; + $jobs = $this->_config->getJobs(); + $pendingJobs = $this->_scheduleFactory->create()->getCollection(); + $pendingJobs->addFieldToFilter('status', Schedule::STATUS_PENDING); + $pendingJobs->addFieldToFilter('job_code', ['in' => array_keys($jobs[$groupId])]); + return $pendingJobs; } /** @@ -330,22 +397,32 @@ protected function _getPendingSchedules() * @param string $groupId * @return $this */ - protected function _generate($groupId) + private function generateSchedules($groupId) { /** * check if schedule generation is needed */ $lastRun = (int)$this->_cache->load(self::CACHE_KEY_LAST_SCHEDULE_GENERATE_AT . $groupId); - $rawSchedulePeriod = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_SCHEDULE_GENERATE_EVERY, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE + $rawSchedulePeriod = (int)$this->getCronGroupConfigurationValue( + $groupId, + self::XML_PATH_SCHEDULE_GENERATE_EVERY ); $schedulePeriod = $rawSchedulePeriod * self::SECONDS_IN_MINUTE; if ($lastRun > $this->dateTime->gmtTimestamp() - $schedulePeriod) { return $this; } - $schedules = $this->_getPendingSchedules(); + /** + * save time schedules generation was ran with no expiration + */ + $this->_cache->save( + $this->dateTime->gmtTimestamp(), + self::CACHE_KEY_LAST_SCHEDULE_GENERATE_AT . $groupId, + ['crontab'], + null + ); + + $schedules = $this->getPendingSchedules($groupId); $exists = []; /** @var Schedule $schedule */ foreach ($schedules as $schedule) { @@ -355,21 +432,11 @@ protected function _generate($groupId) /** * generate global crontab jobs */ - $jobs = $this->getJobs(); + $jobs = $this->_config->getJobs(); $this->invalid = []; $this->_generateJobs($jobs[$groupId], $exists, $groupId); $this->cleanupScheduleMismatches(); - /** - * save time schedules generation was ran with no expiration - */ - $this->_cache->save( - $this->dateTime->gmtTimestamp(), - self::CACHE_KEY_LAST_SCHEDULE_GENERATE_AT . $groupId, - ['crontab'], - null - ); - return $this; } @@ -379,7 +446,7 @@ protected function _generate($groupId) * @param array $jobs * @param array $exists * @param string $groupId - * @return $this + * @return void */ protected function _generateJobs($jobs, $exists, $groupId) { @@ -392,77 +459,60 @@ protected function _generateJobs($jobs, $exists, $groupId) $timeInterval = $this->getScheduleTimeInterval($groupId); $this->saveSchedule($jobCode, $cronExpression, $timeInterval, $exists); } - return $this; } /** * Clean expired jobs * - * @param string $groupId - * @return $this + * @param $groupId + * @param $currentTime + * @return void */ - protected function _cleanup($groupId) + private function cleanupJobs($groupId, $currentTime) { - $this->cleanupDisabledJobs($groupId); - // check if history cleanup is needed $lastCleanup = (int)$this->_cache->load(self::CACHE_KEY_LAST_HISTORY_CLEANUP_AT . $groupId); - $historyCleanUp = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_HISTORY_CLEANUP_EVERY, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE - ); + $historyCleanUp = (int)$this->getCronGroupConfigurationValue($groupId, self::XML_PATH_HISTORY_CLEANUP_EVERY); if ($lastCleanup > $this->dateTime->gmtTimestamp() - $historyCleanUp * self::SECONDS_IN_MINUTE) { return $this; } - - // check how long the record should stay unprocessed before marked as MISSED - $scheduleLifetime = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_SCHEDULE_LIFETIME, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE + // save time history cleanup was ran with no expiration + $this->_cache->save( + $this->dateTime->gmtTimestamp(), + self::CACHE_KEY_LAST_HISTORY_CLEANUP_AT . $groupId, + ['crontab'], + null ); - $scheduleLifetime = $scheduleLifetime * self::SECONDS_IN_MINUTE; - /** - * @var \Magento\Cron\Model\ResourceModel\Schedule\Collection $history - */ - $history = $this->_scheduleFactory->create()->getCollection()->addFieldToFilter( - 'status', - ['in' => [Schedule::STATUS_SUCCESS, Schedule::STATUS_MISSED, Schedule::STATUS_ERROR]] - )->load(); + $this->cleanupDisabledJobs($groupId); - $historySuccess = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_HISTORY_SUCCESS, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE - ); - $historyFailure = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_HISTORY_FAILURE, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE - ); + $historySuccess = (int)$this->getCronGroupConfigurationValue($groupId, self::XML_PATH_HISTORY_SUCCESS); + $historyFailure = (int)$this->getCronGroupConfigurationValue($groupId, self::XML_PATH_HISTORY_FAILURE); $historyLifetimes = [ Schedule::STATUS_SUCCESS => $historySuccess * self::SECONDS_IN_MINUTE, Schedule::STATUS_MISSED => $historyFailure * self::SECONDS_IN_MINUTE, Schedule::STATUS_ERROR => $historyFailure * self::SECONDS_IN_MINUTE, + Schedule::STATUS_PENDING => max($historyFailure, $historySuccess) * self::SECONDS_IN_MINUTE, ]; - $now = $this->dateTime->gmtTimestamp(); - /** @var Schedule $record */ - foreach ($history as $record) { - $checkTime = $record->getExecutedAt() ? strtotime($record->getExecutedAt()) : - strtotime($record->getScheduledAt()) + $scheduleLifetime; - if ($checkTime < $now - $historyLifetimes[$record->getStatus()]) { - $record->delete(); - } + $jobs = $this->_config->getJobs()[$groupId]; + $scheduleResource = $this->_scheduleFactory->create()->getResource(); + $connection = $scheduleResource->getConnection(); + $count = 0; + foreach ($historyLifetimes as $time) { + $count += $connection->delete( + $scheduleResource->getMainTable(), + [ + 'status = ?' => Schedule::STATUS_PENDING, + 'job_code in (?)' => array_keys($jobs), + 'created_at < ?' => $connection->formatDate($currentTime - $time) + ] + ); } - // save time history cleanup was ran with no expiration - $this->_cache->save( - $this->dateTime->gmtTimestamp(), - self::CACHE_KEY_LAST_HISTORY_CLEANUP_AT . $groupId, - ['crontab'], - null - ); - - return $this; + if ($count) { + $this->logger->info(sprintf('%d cron jobs were cleaned', $count)); + } } /** @@ -493,7 +543,7 @@ protected function saveSchedule($jobCode, $cronExpression, $timeInterval, $exist for ($time = $currentTime; $time < $timeAhead; $time += self::SECONDS_IN_MINUTE) { $scheduledAt = strftime('%Y-%m-%d %H:%M:00', $time); $alreadyScheduled = !empty($exists[$jobCode . '/' . $scheduledAt]); - $schedule = $this->generateSchedule($jobCode, $cronExpression, $time); + $schedule = $this->createSchedule($jobCode, $cronExpression, $time); $valid = $schedule->trySchedule(); if (!$valid) { if ($alreadyScheduled) { @@ -517,7 +567,7 @@ protected function saveSchedule($jobCode, $cronExpression, $timeInterval, $exist * @param int $time * @return Schedule */ - protected function generateSchedule($jobCode, $cronExpression, $time) + protected function createSchedule($jobCode, $cronExpression, $time) { $schedule = $this->_scheduleFactory->create() ->setCronExpr($cronExpression) @@ -535,10 +585,7 @@ protected function generateSchedule($jobCode, $cronExpression, $time) */ protected function getScheduleTimeInterval($groupId) { - $scheduleAheadFor = (int)$this->_scopeConfig->getValue( - 'system/cron/' . $groupId . '/' . self::XML_PATH_SCHEDULE_AHEAD_FOR, - \Magento\Store\Model\ScopeInterface::SCOPE_STORE - ); + $scheduleAheadFor = (int)$this->getCronGroupConfigurationValue($groupId, self::XML_PATH_SCHEDULE_AHEAD_FOR); $scheduleAheadFor = $scheduleAheadFor * self::SECONDS_IN_MINUTE; return $scheduleAheadFor; @@ -553,17 +600,27 @@ protected function getScheduleTimeInterval($groupId) */ private function cleanupDisabledJobs($groupId) { - $jobs = $this->getJobs(); + $jobs = $this->_config->getJobs(); + $jobsToCleanup = []; foreach ($jobs[$groupId] as $jobCode => $jobConfig) { if (!$this->getCronExpression($jobConfig)) { /** @var \Magento\Cron\Model\ResourceModel\Schedule $scheduleResource */ - $scheduleResource = $this->_scheduleFactory->create()->getResource(); - $scheduleResource->getConnection()->delete($scheduleResource->getMainTable(), [ - 'status=?' => Schedule::STATUS_PENDING, - 'job_code=?' => $jobCode, - ]); + $jobsToCleanup[] = $jobCode; } } + + if (count($jobsToCleanup) > 0) { + $scheduleResource = $this->_scheduleFactory->create()->getResource(); + $count = $scheduleResource->getConnection()->delete( + $scheduleResource->getMainTable(), + [ + 'status = ?' => Schedule::STATUS_PENDING, + 'job_code in (?)' => $jobsToCleanup, + ] + ); + + $this->logger->info(sprintf('%d cron jobs were cleaned', $count)); + } } /** @@ -593,12 +650,12 @@ private function getCronExpression($jobConfig) */ private function cleanupScheduleMismatches() { + /** @var \Magento\Cron\Model\ResourceModel\Schedule $scheduleResource */ + $scheduleResource = $this->_scheduleFactory->create()->getResource(); foreach ($this->invalid as $jobCode => $scheduledAtList) { - /** @var \Magento\Cron\Model\ResourceModel\Schedule $scheduleResource */ - $scheduleResource = $this->_scheduleFactory->create()->getResource(); $scheduleResource->getConnection()->delete($scheduleResource->getMainTable(), [ - 'status=?' => Schedule::STATUS_PENDING, - 'job_code=?' => $jobCode, + 'status = ?' => Schedule::STATUS_PENDING, + 'job_code = ?' => $jobCode, 'scheduled_at in (?)' => $scheduledAtList, ]); } @@ -606,13 +663,87 @@ private function cleanupScheduleMismatches() } /** - * @return array + * Get CronGroup Configuration Value + * + * @param $groupId + * @return int + */ + private function getCronGroupConfigurationValue($groupId, $path) + { + return $this->_scopeConfig->getValue( + 'system/cron/' . $groupId . '/' . $path, + \Magento\Store\Model\ScopeInterface::SCOPE_STORE + ); + } + + /** + * Is Group In Filter + * + * @param $groupId + * @return bool + */ + private function isGroupInFilter($groupId): bool + { + return !($this->_request->getParam('group') !== null + && trim($this->_request->getParam('group'), "'") !== $groupId); + } + + /** + * Process pending jobs + * + * @param $groupId + * @param $jobsRoot + * @param $currentTime + */ + private function processPendingJobs($groupId, $jobsRoot, $currentTime) + { + $procesedJobs = []; + $pendingJobs = $this->getPendingSchedules($groupId); + /** @var \Magento\Cron\Model\Schedule $schedule */ + foreach ($pendingJobs as $schedule) { + if (isset($procesedJobs[$schedule->getJobCode()])) { + // process only on job per run + continue; + } + $jobConfig = isset($jobsRoot[$schedule->getJobCode()]) ? $jobsRoot[$schedule->getJobCode()] : null; + if (!$jobConfig) { + continue; + } + + $scheduledTime = strtotime($schedule->getScheduledAt()); + if ($scheduledTime > $currentTime) { + continue; + } + + try { + if ($schedule->tryLockJob()) { + $this->_runJob($scheduledTime, $currentTime, $jobConfig, $schedule, $groupId); + } + } catch (\Exception $e) { + $this->processError($schedule, $e); + } + if ($schedule->getStatus() === Schedule::STATUS_SUCCESS) { + $procesedJobs[$schedule->getJobCode()] = true; + } + $schedule->save(); + } + } + + /** + * @param Schedule $schedule + * @param \Exception $exception + * @return void */ - private function getJobs() + private function processError(\Magento\Cron\Model\Schedule $schedule, \Exception $exception) { - if ($this->jobs === null) { - $this->jobs = $this->_config->getJobs(); + $schedule->setMessages($exception->getMessage()); + if ($schedule->getStatus() === Schedule::STATUS_ERROR) { + $this->logger->critical($exception); + } + if ($schedule->getStatus() === Schedule::STATUS_MISSED + && $this->state->getMode() === State::MODE_DEVELOPER + ) { + $this->logger->info($schedule->getMessages()); } - return $this->jobs; } } diff --git a/app/code/Magento/Cron/Test/Unit/Observer/ProcessCronQueueObserverTest.php b/app/code/Magento/Cron/Test/Unit/Observer/ProcessCronQueueObserverTest.php index fedd5612cd945..d14249e6b0e57 100644 --- a/app/code/Magento/Cron/Test/Unit/Observer/ProcessCronQueueObserverTest.php +++ b/app/code/Magento/Cron/Test/Unit/Observer/ProcessCronQueueObserverTest.php @@ -8,6 +8,7 @@ use Magento\Cron\Model\Schedule; use Magento\Cron\Observer\ProcessCronQueueObserver as ProcessCronQueueObserver; use Magento\Framework\App\State; +use Magento\Framework\Profiler\Driver\Standard\StatFactory; /** * Class \Magento\Cron\Test\Unit\Model\ObserverTest @@ -84,6 +85,11 @@ class ProcessCronQueueObserverTest extends \PHPUnit\Framework\TestCase */ protected $appStateMock; + /** + * @var \Magento\Framework\Lock\LockManagerInterface|\PHPUnit_Framework_MockObject_MockObject + */ + private $lockManagerMock; + /** * @var \Magento\Cron\Model\ResourceModel\Schedule|\PHPUnit_Framework_MockObject_MockObject */ @@ -116,6 +122,7 @@ protected function setUp() )->disableOriginalConstructor()->getMock(); $this->_collection->expects($this->any())->method('addFieldToFilter')->will($this->returnSelf()); $this->_collection->expects($this->any())->method('load')->will($this->returnSelf()); + $this->_scheduleFactory = $this->getMockBuilder( \Magento\Cron\Model\ScheduleFactory::class )->setMethods( @@ -135,6 +142,12 @@ protected function setUp() ->disableOriginalConstructor() ->getMock(); + $this->lockManagerMock = $this->getMockBuilder(\Magento\Framework\Lock\LockManagerInterface::class) + ->disableOriginalConstructor() + ->getMock(); + $this->lockManagerMock->method('lock')->willReturn(true); + $this->lockManagerMock->method('unlock')->willReturn(true); + $this->observer = $this->createMock(\Magento\Framework\Event\Observer::class); $this->dateTimeMock = $this->getMockBuilder(\Magento\Framework\Stdlib\DateTime\DateTime::class) @@ -159,6 +172,15 @@ protected function setUp() $this->scheduleResource->method('getConnection')->willReturn($connection); $connection->method('delete')->willReturn(1); + $this->statFactory = $this->getMockBuilder(StatFactory::class) + ->setMethods(['create']) + ->getMockForAbstractClass(); + + $this->stat = $this->getMockBuilder(\Magento\Framework\Profiler\Driver\Standard\Stat::class) + ->disableOriginalConstructor() + ->getMock(); + $this->statFactory->expects($this->any())->method('create')->willReturn($this->stat); + $this->_observer = new ProcessCronQueueObserver( $this->_objectManager, $this->_scheduleFactory, @@ -170,41 +192,23 @@ protected function setUp() $this->dateTimeMock, $phpExecutableFinderFactory, $this->loggerMock, - $this->appStateMock + $this->appStateMock, + $this->statFactory, + $this->lockManagerMock ); } - /** - * Test case without saved cron jobs in data base - */ - public function testDispatchNoPendingJobs() - { - $lastRun = $this->time + 10000000; - $this->_cache->expects($this->any())->method('load')->will($this->returnValue($lastRun)); - $this->_scopeConfig->expects($this->any())->method('getValue')->will($this->returnValue(0)); - - $this->_config->expects($this->once())->method('getJobs')->will($this->returnValue([])); - - $scheduleMock = $this->getMockBuilder( - \Magento\Cron\Model\Schedule::class - )->disableOriginalConstructor()->getMock(); - $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($this->_collection)); - $this->_scheduleFactory->expects($this->once())->method('create')->will($this->returnValue($scheduleMock)); - - $this->_observer->execute($this->observer); - } - /** * Test case for not existed cron jobs in files but in data base is presented */ public function testDispatchNoJobConfig() { $lastRun = $this->time + 10000000; - $this->_cache->expects($this->any())->method('load')->will($this->returnValue($lastRun)); - $this->_scopeConfig->expects($this->any())->method('getValue')->will($this->returnValue(0)); + $this->_cache->expects($this->atLeastOnce())->method('load')->will($this->returnValue($lastRun)); + $this->_scopeConfig->expects($this->atLeastOnce())->method('getValue')->will($this->returnValue(0)); $this->_config->expects( - $this->any() + $this->atLeastOnce() )->method( 'getJobs' )->will( @@ -212,16 +216,21 @@ public function testDispatchNoJobConfig() ); $schedule = $this->createPartialMock(\Magento\Cron\Model\Schedule::class, ['getJobCode', '__wakeup']); - $schedule->expects($this->once())->method('getJobCode')->will($this->returnValue('not_existed_job_code')); + $schedule->expects($this->atLeastOnce()) + ->method('getJobCode') + ->will($this->returnValue('not_existed_job_code')); $this->_collection->addItem($schedule); $scheduleMock = $this->getMockBuilder( \Magento\Cron\Model\Schedule::class )->disableOriginalConstructor()->getMock(); - $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($this->_collection)); - $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->any())->method('create')->will($this->returnValue($scheduleMock)); + $scheduleMock->expects($this->atLeastOnce()) + ->method('getCollection') + ->will($this->returnValue($this->_collection)); + $this->_scheduleFactory->expects($this->atLeastOnce()) + ->method('create') + ->will($this->returnValue($scheduleMock)); $this->_observer->execute($this->observer); } @@ -240,11 +249,13 @@ public function testDispatchCanNotLock() $schedule = $this->getMockBuilder( \Magento\Cron\Model\Schedule::class )->setMethods( - ['getJobCode', 'tryLockJob', 'getScheduledAt', '__wakeup', 'save'] + ['getJobCode', 'tryLockJob', 'getScheduledAt', '__wakeup', 'save', 'setFinishedAt'] )->disableOriginalConstructor()->getMock(); $schedule->expects($this->any())->method('getJobCode')->will($this->returnValue('test_job1')); - $schedule->expects($this->once())->method('getScheduledAt')->will($this->returnValue($dateScheduledAt)); + $schedule->expects($this->atLeastOnce())->method('getScheduledAt')->will($this->returnValue($dateScheduledAt)); $schedule->expects($this->once())->method('tryLockJob')->will($this->returnValue(false)); + $schedule->expects($this->never())->method('setFinishedAt'); + $abstractModel = $this->createMock(\Magento\Framework\Model\AbstractModel::class); $schedule->expects($this->any())->method('save')->will($this->returnValue($abstractModel)); $this->_collection->addItem($schedule); @@ -262,7 +273,9 @@ public function testDispatchCanNotLock() )->disableOriginalConstructor()->getMock(); $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($this->_collection)); $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->exactly(2))->method('create')->will($this->returnValue($scheduleMock)); + $this->_scheduleFactory->expects($this->atLeastOnce()) + ->method('create') + ->will($this->returnValue($scheduleMock)); $this->_observer->execute($this->observer); } @@ -272,10 +285,8 @@ public function testDispatchCanNotLock() */ public function testDispatchExceptionTooLate() { - $exceptionMessage = 'Too late for the schedule'; - $scheduleId = 42; + $exceptionMessage = 'Cron Job test_job1 is missed at 2017-07-30 15:00:00'; $jobCode = 'test_job1'; - $exception = $exceptionMessage . ' Schedule Id: ' . $scheduleId . ' Job Code: ' . $jobCode; $lastRun = $this->time + 10000000; $this->_cache->expects($this->any())->method('load')->willReturn($lastRun); @@ -299,25 +310,25 @@ public function testDispatchExceptionTooLate() 'getScheduleId', ] )->disableOriginalConstructor()->getMock(); - $schedule->expects($this->any())->method('getJobCode')->willReturn($jobCode); - $schedule->expects($this->once())->method('getScheduledAt')->willReturn($dateScheduledAt); + $schedule->expects($this->atLeastOnce())->method('getJobCode')->willReturn($jobCode); + $schedule->expects($this->atLeastOnce())->method('getScheduledAt')->willReturn($dateScheduledAt); $schedule->expects($this->once())->method('tryLockJob')->willReturn(true); $schedule->expects( - $this->once() + $this->any() )->method( 'setStatus' )->with( $this->equalTo(\Magento\Cron\Model\Schedule::STATUS_MISSED) )->willReturnSelf(); $schedule->expects($this->once())->method('setMessages')->with($this->equalTo($exceptionMessage)); - $schedule->expects($this->any())->method('getStatus')->willReturn(Schedule::STATUS_MISSED); - $schedule->expects($this->once())->method('getMessages')->willReturn($exceptionMessage); - $schedule->expects($this->once())->method('getScheduleId')->willReturn($scheduleId); + $schedule->expects($this->atLeastOnce())->method('getStatus')->willReturn(Schedule::STATUS_MISSED); + $schedule->expects($this->atLeastOnce())->method('getMessages')->willReturn($exceptionMessage); $schedule->expects($this->once())->method('save'); $this->appStateMock->expects($this->once())->method('getMode')->willReturn(State::MODE_DEVELOPER); - $this->loggerMock->expects($this->once())->method('info')->with($exception); + $this->loggerMock->expects($this->once())->method('info') + ->with('Cron Job test_job1 is missed at 2017-07-30 15:00:00'); $this->_collection->addItem($schedule); @@ -333,7 +344,7 @@ public function testDispatchExceptionTooLate() ->disableOriginalConstructor()->getMock(); $scheduleMock->expects($this->any())->method('getCollection')->willReturn($this->_collection); $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->exactly(2))->method('create')->willReturn($scheduleMock); + $this->_scheduleFactory->expects($this->atLeastOnce())->method('create')->willReturn($scheduleMock); $this->_observer->execute($this->observer); } @@ -388,7 +399,7 @@ public function testDispatchExceptionNoCallback() )->disableOriginalConstructor()->getMock(); $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($this->_collection)); $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->exactly(2))->method('create')->will($this->returnValue($scheduleMock)); + $this->_scheduleFactory->expects($this->once())->method('create')->will($this->returnValue($scheduleMock)); $this->_observer->execute($this->observer); } @@ -453,7 +464,7 @@ public function testDispatchExceptionInCallback( )->disableOriginalConstructor()->getMock(); $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($this->_collection)); $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->exactly(2))->method('create')->will($this->returnValue($scheduleMock)); + $this->_scheduleFactory->expects($this->once())->method('create')->will($this->returnValue($scheduleMock)); $this->_objectManager ->expects($this->once()) ->method('create') @@ -529,23 +540,22 @@ public function testDispatchRunJob() $scheduleMethods )->disableOriginalConstructor()->getMock(); $schedule->expects($this->any())->method('getJobCode')->will($this->returnValue('test_job1')); - $schedule->expects($this->once())->method('getScheduledAt')->will($this->returnValue($dateScheduledAt)); - $schedule->expects($this->once())->method('tryLockJob')->will($this->returnValue(true)); + $schedule->expects($this->atLeastOnce())->method('getScheduledAt')->will($this->returnValue($dateScheduledAt)); + $schedule->expects($this->atLeastOnce())->method('tryLockJob')->will($this->returnValue(true)); + $schedule->expects($this->any())->method('setFinishedAt')->willReturnSelf(); // cron start to execute some job $schedule->expects($this->any())->method('setExecutedAt')->will($this->returnSelf()); - $schedule->expects($this->at(5))->method('save'); + $schedule->expects($this->atLeastOnce())->method('save'); // cron end execute some job $schedule->expects( - $this->at(6) + $this->atLeastOnce() )->method( 'setStatus' )->with( $this->equalTo(\Magento\Cron\Model\Schedule::STATUS_SUCCESS) - )->will( - $this->returnSelf() - ); + )->willReturnSelf(); $schedule->expects($this->at(8))->method('save'); @@ -564,7 +574,7 @@ public function testDispatchRunJob() )->disableOriginalConstructor()->getMock(); $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($this->_collection)); $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->exactly(2))->method('create')->will($this->returnValue($scheduleMock)); + $this->_scheduleFactory->expects($this->once(2))->method('create')->will($this->returnValue($scheduleMock)); $testCronJob = $this->getMockBuilder('CronJob')->setMethods(['execute'])->getMock(); $testCronJob->expects($this->atLeastOnce())->method('execute')->with($schedule); @@ -599,6 +609,8 @@ public function testDispatchNotGenerate() )->will( $this->returnValue(['test_group' => []]) ); + $this->_config->expects($this->at(2))->method('getJobs')->will($this->returnValue($jobConfig)); + $this->_config->expects($this->at(3))->method('getJobs')->will($this->returnValue($jobConfig)); $this->_request->expects($this->any())->method('getParam')->will($this->returnValue('test_group')); $this->_cache->expects( $this->at(0) @@ -668,6 +680,8 @@ public function testDispatchGenerate() ]; $this->_config->expects($this->at(0))->method('getJobs')->willReturn($jobConfig); $this->_config->expects($this->at(1))->method('getJobs')->willReturn($jobs); + $this->_config->expects($this->at(2))->method('getJobs')->willReturn($jobs); + $this->_config->expects($this->at(3))->method('getJobs')->willReturn($jobs); $this->_request->expects($this->any())->method('getParam')->willReturn('default'); $this->_cache->expects( $this->at(0) @@ -744,7 +758,7 @@ public function testDispatchCleanup() $this->_request->expects($this->any())->method('getParam')->will($this->returnValue('test_group')); $this->_collection->addItem($schedule); - $this->_config->expects($this->exactly(2))->method('getJobs')->will($this->returnValue($jobConfig)); + $this->_config->expects($this->atLeastOnce())->method('getJobs')->will($this->returnValue($jobConfig)); $this->_cache->expects($this->at(0))->method('load')->will($this->returnValue($this->time + 10000000)); $this->_cache->expects($this->at(1))->method('load')->will($this->returnValue($this->time - 10000000)); @@ -771,7 +785,7 @@ public function testDispatchCleanup() )->setMethods(['getCollection', 'getResource'])->disableOriginalConstructor()->getMock(); $scheduleMock->expects($this->any())->method('getCollection')->will($this->returnValue($collection)); $scheduleMock->expects($this->any())->method('getResource')->will($this->returnValue($this->scheduleResource)); - $this->_scheduleFactory->expects($this->at(1))->method('create')->will($this->returnValue($scheduleMock)); + $this->_scheduleFactory->expects($this->any())->method('create')->will($this->returnValue($scheduleMock)); $this->_observer->execute($this->observer); } @@ -795,55 +809,17 @@ public function testMissedJobsCleanedInTime() $this->_cache->expects($this->at(2))->method('load')->will($this->returnValue($this->time + 10000000)); $this->_scheduleFactory->expects($this->at(2))->method('create')->will($this->returnValue($scheduleMock)); - // This item was scheduled 2 days and 2 hours ago - $dateScheduledAt = date('Y-m-d H:i:s', $this->time - 180000); - /** @var \Magento\Cron\Model\Schedule|\PHPUnit_Framework_MockObject_MockObject $schedule1 */ - $schedule1 = $this->getMockBuilder( - \Magento\Cron\Model\Schedule::class - )->disableOriginalConstructor()->setMethods( - ['getExecutedAt', 'getScheduledAt', 'getStatus', 'delete', '__wakeup'] - )->getMock(); - $schedule1->expects($this->any())->method('getExecutedAt')->will($this->returnValue(null)); - $schedule1->expects($this->any())->method('getScheduledAt')->will($this->returnValue($dateScheduledAt)); - $schedule1->expects($this->any())->method('getStatus')->will($this->returnValue(Schedule::STATUS_MISSED)); - //we expect this job be deleted from the list - $schedule1->expects($this->once())->method('delete')->will($this->returnValue(true)); - $this->_collection->addItem($schedule1); - - // This item was scheduled 1 day ago - $dateScheduledAt = date('Y-m-d H:i:s', $this->time - 86400); - $schedule2 = $this->getMockBuilder( - \Magento\Cron\Model\Schedule::class - )->disableOriginalConstructor()->setMethods( - ['getExecutedAt', 'getScheduledAt', 'getStatus', 'delete', '__wakeup'] - )->getMock(); - $schedule2->expects($this->any())->method('getExecutedAt')->will($this->returnValue(null)); - $schedule2->expects($this->any())->method('getScheduledAt')->will($this->returnValue($dateScheduledAt)); - $schedule2->expects($this->any())->method('getStatus')->will($this->returnValue(Schedule::STATUS_MISSED)); - //we don't expect this job be deleted from the list - $schedule2->expects($this->never())->method('delete'); - $this->_collection->addItem($schedule2); - - $this->_config->expects($this->exactly(2))->method('getJobs')->will($this->returnValue($jobConfig)); - - $this->_scopeConfig->expects($this->at(0))->method('getValue') - ->with($this->equalTo('system/cron/test_group/history_cleanup_every')) - ->will($this->returnValue(10)); - $this->_scopeConfig->expects($this->at(1))->method('getValue') - ->with($this->equalTo('system/cron/test_group/schedule_lifetime')) - ->will($this->returnValue(2*24*60)); - $this->_scopeConfig->expects($this->at(2))->method('getValue') - ->with($this->equalTo('system/cron/test_group/history_success_lifetime')) - ->will($this->returnValue(0)); - $this->_scopeConfig->expects($this->at(3))->method('getValue') - ->with($this->equalTo('system/cron/test_group/history_failure_lifetime')) - ->will($this->returnValue(0)); - $this->_scopeConfig->expects($this->at(4))->method('getValue') - ->with($this->equalTo('system/cron/test_group/schedule_generate_every')) - ->will($this->returnValue(0)); - $this->_scopeConfig->expects($this->at(5))->method('getValue') - ->with($this->equalTo('system/cron/test_group/use_separate_process')) - ->will($this->returnValue(0)); + $this->_config->expects($this->atLeastOnce())->method('getJobs')->will($this->returnValue($jobConfig)); + + $this->_scopeConfig->expects($this->any())->method('getValue') + ->willReturnMap([ + ['system/cron/test_group/use_separate_process', 0], + ['system/cron/test_group/history_cleanup_every', 10], + ['system/cron/test_group/schedule_lifetime', 2*24*60], + ['system/cron/test_group/history_success_lifetime', 0], + ['system/cron/test_group/history_failure_lifetime', 0], + ['system/cron/test_group/schedule_generate_every', 0], + ]); $this->_collection->expects($this->any())->method('addFieldToFilter')->will($this->returnSelf()); $this->_collection->expects($this->any())->method('load')->will($this->returnSelf()); diff --git a/app/etc/di.xml b/app/etc/di.xml index de5084067660d..0a5c05cf1006d 100755 --- a/app/etc/di.xml +++ b/app/etc/di.xml @@ -37,6 +37,7 @@ + diff --git a/dev/tests/integration/testsuite/Magento/Framework/Lock/Backend/DatabaseTest.php b/dev/tests/integration/testsuite/Magento/Framework/Lock/Backend/DatabaseTest.php new file mode 100644 index 0000000000000..53077500aa7da --- /dev/null +++ b/dev/tests/integration/testsuite/Magento/Framework/Lock/Backend/DatabaseTest.php @@ -0,0 +1,50 @@ +objectManager = \Magento\TestFramework\Helper\Bootstrap::getObjectManager(); + $this->model = $this->objectManager->create(\Magento\Framework\Lock\Backend\Database::class); + } + + public function testLockAndUnlock() + { + $name = 'test_lock'; + + $this->assertFalse($this->model->isLocked($name)); + + $this->assertTrue($this->model->lock($name)); + $this->assertTrue($this->model->isLocked($name)); + + $this->assertTrue($this->model->unlock($name)); + $this->assertFalse($this->model->isLocked($name)); + } + + public function testUnlockWithoutExistingLock() + { + $name = 'test_lock'; + + $this->assertFalse($this->model->isLocked($name)); + $this->assertFalse($this->model->unlock($name)); + } +} diff --git a/lib/internal/Magento/Framework/Lock/Backend/Database.php b/lib/internal/Magento/Framework/Lock/Backend/Database.php new file mode 100644 index 0000000000000..6d1bf07b5b331 --- /dev/null +++ b/lib/internal/Magento/Framework/Lock/Backend/Database.php @@ -0,0 +1,158 @@ +resource = $resource; + $this->deploymentConfig = $deploymentConfig; + $this->prefix = $prefix; + } + + /** + * Sets a lock for name + * + * @param string $name lock name + * @param int $timeout How long to wait lock acquisition in seconds, negative value means infinite timeout + * @return bool + * @throws InputException + * @throws AlreadyExistsException + */ + public function lock(string $name, int $timeout = -1): bool + { + $name = $this->addPrefix($name); + + /** + * Before MySQL 5.7.5, only a single simultaneous lock per connection can be acquired. + * This limitation can be removed once MySQL minimum requirement has been raised, + * currently we support MySQL 5.6 way only. + */ + if ($this->currentLock) { + throw new AlreadyExistsException( + new Phrase( + 'Current connection is already holding lock for $1, only single lock allowed', + [$this->currentLock] + ) + ); + } + + $result = (bool)$this->resource->getConnection()->query( + "SELECT GET_LOCK(?, ?);", + [(string)$name, (int)$timeout] + )->fetchColumn(); + + if ($result === true) { + $this->currentLock = $name; + } + + return $result; + } + + /** + * Releases a lock for name + * + * @param string $name lock name + * @return bool + * @throws InputException + */ + public function unlock(string $name): bool + { + $name = $this->addPrefix($name); + + $result = (bool)$this->resource->getConnection()->query( + "SELECT RELEASE_LOCK(?);", + [(string)$name] + )->fetchColumn(); + + if ($result === true) { + $this->currentLock = false; + } + + return $result; + } + + /** + * Tests of lock is set for name + * + * @param string $name lock name + * @return bool + * @throws InputException + */ + public function isLocked(string $name): bool + { + $name = $this->addPrefix($name); + + return (bool)$this->resource->getConnection()->query( + "SELECT IS_USED_LOCK(?);", + [(string)$name] + )->fetchColumn(); + } + + /** + * Adds prefix and checks for max length of lock name + * + * Limited to 64 characters in MySQL. + * + * @param string $name + * @return string $name + * @throws InputException + */ + private function addPrefix(string $name): string + { + $name = $this->getPrefix() . '|' . $name; + + if (strlen($name) > 64) { + throw new InputException(new Phrase('Lock name too long: %1...', [substr($name, 0, 64)])); + } + + return $name; + } + + /** + * Get installation specific lock prefix to avoid lock conflicts + * + * @return string lock prefix + */ + private function getPrefix(): string + { + if ($this->prefix === null) { + $this->prefix = (string)$this->deploymentConfig->get( + ConfigOptionsListConstants::CONFIG_PATH_DB_CONNECTION_DEFAULT + . '/' + . ConfigOptionsListConstants::KEY_NAME, + '' + ); + } + + return $this->prefix; + } +} diff --git a/lib/internal/Magento/Framework/Lock/LockManagerInterface.php b/lib/internal/Magento/Framework/Lock/LockManagerInterface.php new file mode 100644 index 0000000000000..9df65f45adac3 --- /dev/null +++ b/lib/internal/Magento/Framework/Lock/LockManagerInterface.php @@ -0,0 +1,44 @@ +connection = $this->getMockBuilder(\Magento\Framework\DB\Adapter\AdapterInterface::class) + ->disableOriginalConstructor() + ->getMockForAbstractClass(); + $this->resource = $this->getMockBuilder(\Magento\Framework\App\ResourceConnection::class) + ->disableOriginalConstructor() + ->getMock(); + $this->statement = $this->getMockBuilder(\Zend_Db_Statement_Interface::class) + ->disableOriginalConstructor() + ->getMockForAbstractClass(); + + $this->resource->expects($this->any()) + ->method('getConnection') + ->willReturn($this->connection); + + $this->connection->expects($this->any()) + ->method('query') + ->willReturn($this->statement); + + $this->objectManager = new \Magento\Framework\TestFramework\Unit\Helper\ObjectManager($this); + + /** @var Database $database */ + $this->database = $this->objectManager->getObject( + Database::class, + ['resource' => $this->resource] + ); + } + + public function testLock() + { + $this->statement->expects($this->once()) + ->method('fetchColumn') + ->willReturn(true); + + $this->assertTrue($this->database->lock('testLock')); + } + + /** + * @expectedException \Magento\Framework\Exception\InputException + */ + public function testlockWithTooLongName() + { + $this->database->lock('BbXbyf9rIY5xuAVdviQJmh76FyoeeVHTDpcjmcImNtgpO4Hnz4xk76ZGEyYALvrQu'); + } + + /** + * @expectedException \Magento\Framework\Exception\AlreadyExistsException + */ + public function testlockWithAlreadyAcquiredLockInSameSession() + { + $this->statement->expects($this->any()) + ->method('fetchColumn') + ->willReturn(true); + + $this->database->lock('testLock'); + $this->database->lock('differentLock'); + } +}