diff --git a/app/Classes/VATUSAMoodle.php b/app/Classes/VATUSAMoodle.php index 652bba2..24a7e85 100644 --- a/app/Classes/VATUSAMoodle.php +++ b/app/Classes/VATUSAMoodle.php @@ -53,6 +53,12 @@ class VATUSAMoodle extends MoodleRest private $isTest; + /** @var array|null Memoized result of getCategories() for the lifetime of this instance */ + private $categoriesCache = null; + + /** @var int Seconds to bound each Moodle HTTP request to */ + private const HTTP_TIMEOUT_SECONDS = 30; + /** * VATUSAMoodle constructor. * @@ -91,6 +97,32 @@ public function setSSO(bool $isSSO = true) } } + /** + * Make the request, with a bounded HTTP timeout. + * + * The vendored MoodleRest::request() uses file_get_contents()/stream contexts with no + * explicit timeout, so it silently falls back to PHP's default_socket_timeout ini + * (60s, not guaranteed). Scope an explicit timeout tightly around each individual call + * rather than setting it once for the process, since default_socket_timeout is a + * process-global ini setting also consulted by predis (CACHE_DRIVER=redis). + * + * @param string $function + * @param array|null $parameters + * @param string $method + * + * @return mixed + * @throws \Exception + */ + public function request($function, $parameters = null, $method = self::METHOD_GET) + { + $previous = ini_set('default_socket_timeout', self::HTTP_TIMEOUT_SECONDS); + try { + return parent::request($function, $parameters, $method); + } finally { + ini_set('default_socket_timeout', $previous); + } + } + /** * Get all Cohorts * @return mixed @@ -124,7 +156,11 @@ public function getCohortMembers(): array */ public function getCategories() { - return $this->request("core_course_get_categories"); + if ($this->categoriesCache === null) { + $this->categoriesCache = $this->request("core_course_get_categories"); + } + + return $this->categoriesCache; } /** diff --git a/app/Console/Kernel.php b/app/Console/Kernel.php index 192fa85..a0063e2 100644 --- a/app/Console/Kernel.php +++ b/app/Console/Kernel.php @@ -4,6 +4,8 @@ use Illuminate\Console\Scheduling\Schedule; use Illuminate\Foundation\Console\Kernel as ConsoleKernel; +use Illuminate\Support\Facades\Cache; +use Illuminate\Support\Facades\Log; class Kernel extends ConsoleKernel { @@ -30,18 +32,32 @@ class Kernel extends ConsoleKernel */ protected function schedule(Schedule $schedule) { - // Helper function to create a 'before' hook closure with the command name + // Helper function to create a 'before' hook closure with the command name. + // Records the start time in cache (not a shared closure variable) because + // runInBackground() events run their 'after' hook in a separate, freshly-booted + // `schedule:finish` process with no memory in common with this one. $createBeforeHook = function (string $commandName) { return function () use ($commandName) { - // Use logger() or Log::info() etc. logger("Starting scheduled task: {$commandName}"); + Cache::put("schedule:started:{$commandName}", now(), now()->addHours(6)); }; }; - // Helper function to create an 'after' hook closure with the command name - $createAfterHook = function (string $commandName) { - return function () use ($commandName) { - logger("Finished scheduled task: {$commandName}"); + // Helper function to create an 'after' hook closure with the command name. + // $warnAfterMinutes, when given, logs a WARN if the run exceeded that duration — + // used for commands with a withoutOverlapping() lock window to catch a run + // approaching that window before it starts stacking overlapping instances. + $createAfterHook = function (string $commandName, ?int $warnAfterMinutes = null) { + return function () use ($commandName, $warnAfterMinutes) { + $startedAt = Cache::pull("schedule:started:{$commandName}"); + $elapsedMinutes = $startedAt ? round(now()->diffInSeconds($startedAt) / 60, 1) : null; + + logger("Finished scheduled task: {$commandName}" . + ($elapsedMinutes !== null ? " ({$elapsedMinutes} min)" : "")); + + if ($warnAfterMinutes !== null && $elapsedMinutes !== null && $elapsedMinutes > $warnAfterMinutes) { + Log::warning("Scheduled task {$commandName} took {$elapsedMinutes} minutes, exceeding the {$warnAfterMinutes}-minute warn threshold."); + } }; }; @@ -60,7 +76,7 @@ protected function schedule(Schedule $schedule) ->runInBackground() ->withoutOverlapping(120) ->before($createBeforeHook($commandName)) - ->after($createAfterHook($commandName)); + ->after($createAfterHook($commandName, 90)); $commandName = 'vatsim:flights'; $schedule->command($commandName) @@ -86,7 +102,7 @@ protected function schedule(Schedule $schedule) ->withoutOverlapping(60) ->runInBackground() ->before($createBeforeHook($commandName)) - ->after($createAfterHook($commandName)); + ->after($createAfterHook($commandName, 45)); $commandName = "controller:eligibility"; $schedule->command($commandName)