From a6ed26a9286139697318ca8799e95e9f953ba4c5 Mon Sep 17 00:00:00 2001 From: Chris Morrell Date: Mon, 8 Nov 2021 16:53:55 -0500 Subject: [PATCH 1/5] Scheduled event lifecycle refactor --- .../Console/Scheduling/CallbackEvent.php | 90 +++++++++++-------- src/Illuminate/Console/Scheduling/Event.php | 87 +++++++++--------- .../Scheduling/ScheduleFinishCommand.php | 2 +- 3 files changed, 99 insertions(+), 80 deletions(-) diff --git a/src/Illuminate/Console/Scheduling/CallbackEvent.php b/src/Illuminate/Console/Scheduling/CallbackEvent.php index dde5d7dea549..0561d24ac9c6 100644 --- a/src/Illuminate/Console/Scheduling/CallbackEvent.php +++ b/src/Illuminate/Console/Scheduling/CallbackEvent.php @@ -24,11 +24,25 @@ class CallbackEvent extends Event */ protected $parameters; + /** + * The result of the callback execution. + * + * @var mixed + */ + protected $result; + + /** + * The exception that was thrown when calling the callback. + * + * @var \Throwable|null + */ + protected $exception; + /** * Create a new event instance. * * @param \Illuminate\Console\Scheduling\EventMutex $mutex - * @param string $callback + * @param string|callable $callback * @param array $parameters * @param \DateTimeZone|string|null $timezone * @return void @@ -50,47 +64,43 @@ public function __construct(EventMutex $mutex, $callback, array $parameters = [] } /** - * Run the given event. + * Run the callback event. * * @param \Illuminate\Contracts\Container\Container $container * @return mixed * - * @throws \Exception + * @throws \Throwable */ public function run(Container $container) { - if ($this->description && $this->withoutOverlapping && - ! $this->mutex->create($this)) { - return; - } + parent::run($container); - $pid = getmypid(); - - register_shutdown_function(function () use ($pid) { - if ($pid === getmypid()) { - $this->removeMutex(); - } - }); + if ($this->exception) { + throw $this->exception; + } - parent::callBeforeCallbacks($container); + return $this->result; + } + /** + * Run the callback. + * + * @param \Illuminate\Contracts\Container\Container $container + * @return int + */ + protected function execute($container) + { try { - $response = is_object($this->callback) - ? $container->call([$this->callback, '__invoke'], $this->parameters) - : $container->call($this->callback, $this->parameters); + $this->result = is_object($this->callback) + ? $container->call([$this->callback, '__invoke'], $this->parameters) + : $container->call($this->callback, $this->parameters); - $this->exitCode = $response === false ? 1 : 0; + return $this->result === false ? 1 : 0; } catch (Throwable $e) { - $this->exitCode = 1; - - throw $e; - } finally { - $this->removeMutex(); + $this->exception = $e; - parent::callAfterCallbacks($container); + return 1; } - - return $response; } /** @@ -100,8 +110,8 @@ public function run(Container $container) */ protected function removeMutex() { - if ($this->description && $this->withoutOverlapping) { - $this->mutex->forget($this); + if ($this->description) { + parent::removeMutex(); } } @@ -121,13 +131,7 @@ public function withoutOverlapping($expiresAt = 1440) ); } - $this->withoutOverlapping = true; - - $this->expiresAt = $expiresAt; - - return $this->skip(function () { - return $this->mutex->exists($this); - }); + return parent::withoutOverlapping($expiresAt); } /** @@ -145,9 +149,7 @@ public function onOneServer() ); } - $this->onOneServer = true; - - return $this; + return parent::onOneServer(); } /** @@ -173,4 +175,14 @@ public function getSummaryForDisplay() return is_string($this->callback) ? $this->callback : 'Callback'; } + + /** + * Determine if the event should skip because another process is overlapping. + * + * @return bool + */ + public function shouldSkipDueToOverlapping() + { + return $this->description && parent::shouldSkipDueToOverlapping(); + } } diff --git a/src/Illuminate/Console/Scheduling/Event.php b/src/Illuminate/Console/Scheduling/Event.php index 4de88f163dbf..a78c2a4df950 100644 --- a/src/Illuminate/Console/Scheduling/Event.php +++ b/src/Illuminate/Console/Scheduling/Event.php @@ -188,17 +188,20 @@ public function getDefaultOutput() * * @param \Illuminate\Contracts\Container\Container $container * @return void + * + * @throws \Throwable */ public function run(Container $container) { - if ($this->withoutOverlapping && - ! $this->mutex->create($this)) { + if ($this->shouldSkipDueToOverlapping()) { return; } - $this->runInBackground - ? $this->runCommandInBackground($container) - : $this->runCommandInForeground($container); + $exitCode = $this->start($container); + + if (! $this->runInBackground) { + $this->finish($container, $exitCode); + } } /** @@ -212,42 +215,54 @@ public function mutexName() } /** - * Run the command in the foreground. + * Run the command process. * * @param \Illuminate\Contracts\Container\Container $container - * @return void + * @return int + * + * @throws \Throwable */ - protected function runCommandInForeground(Container $container) + protected function start($container) { try { $this->callBeforeCallbacks($container); - $this->exitCode = Process::fromShellCommandline( - $this->buildCommand(), base_path(), null, null, null - )->run(); - - $this->callAfterCallbacks($container); - } finally { + return $this->execute($container); + } catch (Throwable $exception) { $this->removeMutex(); + + throw $exception; } } /** - * Run the command in the background. + * Run the command process. + * + * @param \Illuminate\Contracts\Container\Container $container + * @return int + */ + protected function execute($container) + { + return Process::fromShellCommandline( + $this->buildCommand(), base_path(), null, null, null + )->run(); + } + + /** + * Mark the command process as finished and run callbacks/cleanup. * * @param \Illuminate\Contracts\Container\Container $container + * @param int $exitCode * @return void */ - protected function runCommandInBackground(Container $container) + public function finish(Container $container, $exitCode) { - try { - $this->callBeforeCallbacks($container); + $this->exitCode = (int) $exitCode; - Process::fromShellCommandline($this->buildCommand(), base_path(), null, null, null)->run(); - } catch (Throwable $exception) { + try { + $this->callAfterCallbacks($container); + } finally { $this->removeMutex(); - - throw $exception; } } @@ -277,24 +292,6 @@ public function callAfterCallbacks(Container $container) } } - /** - * Call all of the "after" callbacks for the event. - * - * @param \Illuminate\Contracts\Container\Container $container - * @param int $exitCode - * @return void - */ - public function callAfterCallbacksWithExitCode(Container $container, $exitCode) - { - $this->exitCode = (int) $exitCode; - - try { - $this->callAfterCallbacks($container); - } finally { - $this->removeMutex(); - } - } - /** * Build the command string. * @@ -381,6 +378,16 @@ public function filtersPass($app) return true; } + /** + * Determine if the event should skip because another process is overlapping. + * + * @return bool + */ + public function shouldSkipDueToOverlapping() + { + return $this->withoutOverlapping && ! $this->mutex->create($this); + } + /** * Ensure that the output is stored on disk in a log file. * diff --git a/src/Illuminate/Console/Scheduling/ScheduleFinishCommand.php b/src/Illuminate/Console/Scheduling/ScheduleFinishCommand.php index db52531b4a38..03a5020dd606 100644 --- a/src/Illuminate/Console/Scheduling/ScheduleFinishCommand.php +++ b/src/Illuminate/Console/Scheduling/ScheduleFinishCommand.php @@ -49,7 +49,7 @@ public function handle(Schedule $schedule) collect($schedule->events())->filter(function ($value) { return $value->mutexName() == $this->argument('id'); })->each(function ($event) { - $event->callafterCallbacksWithExitCode($this->laravel, $this->argument('code')); + $event->finish($this->laravel, $this->argument('code')); $this->laravel->make(Dispatcher::class)->dispatch(new ScheduledBackgroundTaskFinished($event)); }); From f56e6ca67fae196ffe435924badab8d7f5e80295 Mon Sep 17 00:00:00 2001 From: Chris Morrell Date: Thu, 2 Dec 2021 08:55:10 -0500 Subject: [PATCH 2/5] Address background callbacks --- .../Console/Scheduling/CallbackEvent.php | 10 + .../Console/CallbackSchedulingTest.php | 134 +++++++++++ .../Console/CommandSchedulingTest.php | 209 ++++++++++++++++++ 3 files changed, 353 insertions(+) create mode 100644 tests/Integration/Console/CallbackSchedulingTest.php create mode 100644 tests/Integration/Console/CommandSchedulingTest.php diff --git a/src/Illuminate/Console/Scheduling/CallbackEvent.php b/src/Illuminate/Console/Scheduling/CallbackEvent.php index 0561d24ac9c6..1f8be4da5830 100644 --- a/src/Illuminate/Console/Scheduling/CallbackEvent.php +++ b/src/Illuminate/Console/Scheduling/CallbackEvent.php @@ -6,6 +6,7 @@ use Illuminate\Support\Reflector; use InvalidArgumentException; use LogicException; +use RuntimeException; use Throwable; class CallbackEvent extends Event @@ -63,6 +64,15 @@ public function __construct(EventMutex $mutex, $callback, array $parameters = [] $this->timezone = $timezone; } + /** + * @return void + * @throws \RuntimeException + */ + public function runInBackground() + { + throw new RuntimeException('Callbacks can not be scheduled to run in the background.'); + } + /** * Run the callback event. * diff --git a/tests/Integration/Console/CallbackSchedulingTest.php b/tests/Integration/Console/CallbackSchedulingTest.php new file mode 100644 index 000000000000..702ff8116553 --- /dev/null +++ b/tests/Integration/Console/CallbackSchedulingTest.php @@ -0,0 +1,134 @@ +store = new Repository(new ArrayStore(true)); + } + + public function store($name = null) + { + return $this->store; + } + }; + + $container = Container::getInstance(); + + $container->instance(EventMutex::class, new CacheEventMutex($cache)); + $container->instance(SchedulingMutex::class, new CacheSchedulingMutex($cache)); + } + + protected function tearDown(): void + { + Container::setInstance(null); + + parent::tearDown(); + } + + public function testExecutionOrder() + { + $event = $this->app->make(Schedule::class) + ->call($this->logger('call')) + ->after($this->logger('after 1')) + ->before($this->logger('before 1')) + ->after($this->logger('after 2')) + ->before($this->logger('before 2')); + + $this->artisan('schedule:run'); + + $this->assertLogged('before 1', 'before 2', 'call', 'after 1', 'after 2'); + } + + public function testCallbacksCannotRunInBackground() + { + $this->expectException(RuntimeException::class); + + $this->app->make(Schedule::class) + ->call($this->logger('call')) + ->runInBackground(); + } + + public function testExceptionHandlingInCallback() + { + $event = $this->app->make(Schedule::class) + ->call($this->logger('call')) + ->name('test-event') + ->withoutOverlapping(); + + // Set up "before" and "after" hooks to ensure they're called + $event->before($this->logger('before'))->after($this->logger('after')); + + // Register a hook to validate that the mutex was initially created + $mutexWasCreated = false; + $event->before(function () use (&$mutexWasCreated, $event) { + $mutexWasCreated = $event->mutex->exists($event); + }); + + // We'll trigger an exception in an "after" hook to test exception handling + $event->after(function () { + throw new RuntimeException; + }); + + // Because exceptions are caught by the ScheduleRunCommand, we need to listen for + // the "failed" event to check whether our exception was actually thrown + $failed = false; + $this->app->make(Dispatcher::class) + ->listen(ScheduledTaskFailed::class, function (ScheduledTaskFailed $failure) use (&$failed, $event) { + if ($failure->task === $event) { + $failed = true; + } + }); + + $this->artisan('schedule:run'); + + // Hooks and execution should happn in correct order + $this->assertLogged('before', 'call', 'after'); + + // Our exception should have resulted in a failure event + $this->assertTrue($failed); + + // Validate that the mutex was originally created, but that it's since + // been removed (even though an exception was thrown) + $this->assertTrue($mutexWasCreated); + $this->assertFalse($event->mutex->exists($event)); + } + + protected function logger($message) + { + return function () use ($message) { + $this->log[] = $message; + }; + } + + protected function assertLogged(...$message) + { + $this->assertEquals($message, $this->log); + } +} diff --git a/tests/Integration/Console/CommandSchedulingTest.php b/tests/Integration/Console/CommandSchedulingTest.php new file mode 100644 index 000000000000..d29d2ae14500 --- /dev/null +++ b/tests/Integration/Console/CommandSchedulingTest.php @@ -0,0 +1,209 @@ +fs = new Filesystem; + + $this->id = Str::random(); + $this->logfile = storage_path("logs/command_scheduling_test_{$this->id}.log"); + + $this->writeArtisanScript(); + } + + protected function tearDown(): void + { + $this->fs->delete($this->logfile); + $this->fs->delete(base_path('artisan')); + + if (! is_null($this->originalArtisan)) { + $this->fs->put(base_path('artisan'), $this->originalArtisan); + } + + parent::tearDown(); + } + + /** + * @dataProvider executionProvider + */ + public function testExecutionOrder($background) + { + $event = $this->app->make(Schedule::class) + ->command("test:{$this->id}") + ->onOneServer() + ->after(function () { + $this->fs->append($this->logfile, "after\n"); + }) + ->before(function () { + $this->fs->append($this->logfile, "before\n"); + }); + + if ($background) { + $event->runInBackground(); + } + + // We'll trigger the scheduler three times to simulate multiple servers + $this->artisan('schedule:run'); + $this->artisan('schedule:run'); + $this->artisan('schedule:run'); + + if ($background) { + // Since our command is running in a separate process, we need to wait + // until it has finished executing before running our assertions. + $this->waitForLogMessages('before', 'handled', 'after'); + } + + $this->assertLogged('before', 'handled', 'after'); + } + + public function executionProvider() + { + return [ + 'Foreground' => [false], + 'Background' => [true], + ]; + } + + protected function waitForLogMessages(...$messages) + { + $tries = 0; + $sleep = 100000; // 100K microseconds = 0.1 second + $limit = 50; // 0.1s * 50 = 5 second wait limit + + do { + $log = $this->fs->get($this->logfile); + + if (Str::containsAll($log, $messages)) { + return; + } + + $tries++; + usleep($sleep); + } while ($tries < $limit); + } + + protected function assertLogged(...$messages) + { + $log = trim($this->fs->get($this->logfile)); + + $this->assertEquals(implode("\n", $messages), $log); + } + + protected function writeArtisanScript() + { + $path = base_path('artisan'); + + // Save existing artisan script if there is one + if ($this->fs->exists($path)) { + $this->originalArtisan = $this->fs->get($path); + } + + $thisFile = __FILE__; + $logfile = var_export($this->logfile, true); + + $script = <<make(Illuminate\Contracts\Console\Kernel::class); + +// Here is our custom command for the test +class CommandSchedulingTestCommand_{$this->id} extends Illuminate\Console\Command +{ + protected \$signature = 'test:{$this->id}'; + + public function handle() + { + \$logfile = {$logfile}; + (new Illuminate\Filesystem\Filesystem)->append(\$logfile, "handled\\n"); + } +} + +// Register command with Kernel +Illuminate\Console\Application::starting(function (\$artisan) { + \$artisan->add(new CommandSchedulingTestCommand_{$this->id}); +}); + +// Add command to scheduler so that the after() callback is trigger in our spawned process +Illuminate\Foundation\Application::getInstance() + ->booted(function (\$app) { + \$app->resolving(Illuminate\Console\Scheduling\Schedule::class, function(\$schedule) { + \$fs = new Illuminate\Filesystem\Filesystem; + \$schedule->command("test:{$this->id}") + ->after(function() use (\$fs) { + \$logfile = {$logfile}; + \$fs->append(\$logfile, "after\\n"); + }) + ->before(function() use (\$fs) { + \$logfile = {$logfile}; + \$fs->append(\$logfile, "before\\n"); + }); + }); + }); + +\$status = \$kernel->handle( + \$input = new Symfony\Component\Console\Input\ArgvInput, + new Symfony\Component\Console\Output\ConsoleOutput +); + +\$kernel->terminate(\$input, \$status); + +exit(\$status); + +PHP; + + $this->fs->put($path, $script); + } +} From dfb09fd171b3bd34bde0078bef36d2e5b0aabe61 Mon Sep 17 00:00:00 2001 From: Chris Morrell Date: Thu, 2 Dec 2021 08:56:12 -0500 Subject: [PATCH 3/5] Code style --- src/Illuminate/Console/Scheduling/CallbackEvent.php | 1 + 1 file changed, 1 insertion(+) diff --git a/src/Illuminate/Console/Scheduling/CallbackEvent.php b/src/Illuminate/Console/Scheduling/CallbackEvent.php index 1f8be4da5830..b0790e43794f 100644 --- a/src/Illuminate/Console/Scheduling/CallbackEvent.php +++ b/src/Illuminate/Console/Scheduling/CallbackEvent.php @@ -66,6 +66,7 @@ public function __construct(EventMutex $mutex, $callback, array $parameters = [] /** * @return void + * * @throws \RuntimeException */ public function runInBackground() From 8845d432f11fa4b2dfe7ec33b885caf18a879c7a Mon Sep 17 00:00:00 2001 From: Chris Morrell Date: Thu, 2 Dec 2021 08:56:42 -0500 Subject: [PATCH 4/5] StyleCI --- src/Illuminate/Console/Scheduling/CallbackEvent.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Illuminate/Console/Scheduling/CallbackEvent.php b/src/Illuminate/Console/Scheduling/CallbackEvent.php index b0790e43794f..283e5a5df979 100644 --- a/src/Illuminate/Console/Scheduling/CallbackEvent.php +++ b/src/Illuminate/Console/Scheduling/CallbackEvent.php @@ -66,7 +66,7 @@ public function __construct(EventMutex $mutex, $callback, array $parameters = [] /** * @return void - * + * * @throws \RuntimeException */ public function runInBackground() From 71a5de418065e5920e861d41a8866e0d261cdf83 Mon Sep 17 00:00:00 2001 From: Taylor Otwell Date: Tue, 7 Dec 2021 15:33:03 -0600 Subject: [PATCH 5/5] formatting --- .../Console/Scheduling/CallbackEvent.php | 78 ++++++++++--------- src/Illuminate/Console/Scheduling/Event.php | 28 +++---- 2 files changed, 54 insertions(+), 52 deletions(-) diff --git a/src/Illuminate/Console/Scheduling/CallbackEvent.php b/src/Illuminate/Console/Scheduling/CallbackEvent.php index 283e5a5df979..e91600ac3a40 100644 --- a/src/Illuminate/Console/Scheduling/CallbackEvent.php +++ b/src/Illuminate/Console/Scheduling/CallbackEvent.php @@ -26,14 +26,14 @@ class CallbackEvent extends Event protected $parameters; /** - * The result of the callback execution. + * The result of the callback's execution. * * @var mixed */ protected $result; /** - * The exception that was thrown when calling the callback. + * The exception that was thrown when calling the callback, if any. * * @var \Throwable|null */ @@ -64,16 +64,6 @@ public function __construct(EventMutex $mutex, $callback, array $parameters = [] $this->timezone = $timezone; } - /** - * @return void - * - * @throws \RuntimeException - */ - public function runInBackground() - { - throw new RuntimeException('Callbacks can not be scheduled to run in the background.'); - } - /** * Run the callback event. * @@ -93,6 +83,28 @@ public function run(Container $container) return $this->result; } + /** + * Determine if the event should skip because another process is overlapping. + * + * @return bool + */ + public function shouldSkipDueToOverlapping() + { + return $this->description && parent::shouldSkipDueToOverlapping(); + } + + /** + * Indicate that the callback should run in the background. + * + * @return void + * + * @throws \RuntimeException + */ + public function runInBackground() + { + throw new RuntimeException('Scheduled closures can not be run in the background.'); + } + /** * Run the callback. * @@ -114,18 +126,6 @@ protected function execute($container) } } - /** - * Clear the mutex for the event. - * - * @return void - */ - protected function removeMutex() - { - if ($this->description) { - parent::removeMutex(); - } - } - /** * Do not allow the event to overlap each other. * @@ -163,16 +163,6 @@ public function onOneServer() return parent::onOneServer(); } - /** - * Get the mutex name for the scheduled command. - * - * @return string - */ - public function mutexName() - { - return 'framework/schedule-'.sha1($this->description); - } - /** * Get the summary of the event for display. * @@ -188,12 +178,24 @@ public function getSummaryForDisplay() } /** - * Determine if the event should skip because another process is overlapping. + * Get the mutex name for the scheduled command. * - * @return bool + * @return string */ - public function shouldSkipDueToOverlapping() + public function mutexName() { - return $this->description && parent::shouldSkipDueToOverlapping(); + return 'framework/schedule-'.sha1($this->description); + } + + /** + * Clear the mutex for the event. + * + * @return void + */ + protected function removeMutex() + { + if ($this->description) { + parent::removeMutex(); + } } } diff --git a/src/Illuminate/Console/Scheduling/Event.php b/src/Illuminate/Console/Scheduling/Event.php index a78c2a4df950..2df0417ae07d 100644 --- a/src/Illuminate/Console/Scheduling/Event.php +++ b/src/Illuminate/Console/Scheduling/Event.php @@ -205,13 +205,13 @@ public function run(Container $container) } /** - * Get the mutex name for the scheduled command. + * Determine if the event should skip because another process is overlapping. * - * @return string + * @return bool */ - public function mutexName() + public function shouldSkipDueToOverlapping() { - return 'framework'.DIRECTORY_SEPARATOR.'schedule-'.sha1($this->expression.$this->command); + return $this->withoutOverlapping && ! $this->mutex->create($this); } /** @@ -378,16 +378,6 @@ public function filtersPass($app) return true; } - /** - * Determine if the event should skip because another process is overlapping. - * - * @return bool - */ - public function shouldSkipDueToOverlapping() - { - return $this->withoutOverlapping && ! $this->mutex->create($this); - } - /** * Ensure that the output is stored on disk in a log file. * @@ -938,6 +928,16 @@ public function preventOverlapsUsing(EventMutex $mutex) return $this; } + /** + * Get the mutex name for the scheduled command. + * + * @return string + */ + public function mutexName() + { + return 'framework'.DIRECTORY_SEPARATOR.'schedule-'.sha1($this->expression.$this->command); + } + /** * Delete the mutex for the event. *