Skip to content

refactor(CapabilitiesManager): log slow capabilities in a single message #58971

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
szaimen merged 2 commits into from
Jun 16, 2026
Merged

refactor(CapabilitiesManager): log slow capabilities in a single message #58971

Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
3e6d2dc
fix(CapabilitiesManager): only check execution time if debug mode is …
szaimen Mar 16, 2026
3881d9b
refactor(CapabilitiesManager): log slow capabilities in a single message
szaimen Jun 15, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
57 changes: 40 additions & 17 deletions lib/private/CapabilitiesManager.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@ public function __construct(
*/
public function getCapabilities(bool $public = false, bool $initialState = false) : array {
$capabilities = [];
$slowCapabilities = [];
foreach ($this->capabilities as $capability) {
try {
$c = $capability();
Expand All @@ -57,36 +58,58 @@ public function getCapabilities(bool $public = false, bool $initialState = false
// that we would otherwise inject to every page load
continue;
}

$startTime = microtime(true);
$capabilities = array_replace_recursive($capabilities, $c->getCapabilities());
$endTime = microtime(true);
$timeSpent = $endTime - $startTime;
$timeSpent = microtime(true) - $startTime;

if ($timeSpent > self::ACCEPTABLE_LOADING_TIME) {
$logLevel = match (true) {
$timeSpent > self::ACCEPTABLE_LOADING_TIME * 16 => ILogger::FATAL,
$timeSpent > self::ACCEPTABLE_LOADING_TIME * 8 => ILogger::ERROR,
$timeSpent > self::ACCEPTABLE_LOADING_TIME * 4 => ILogger::WARN,
$timeSpent > self::ACCEPTABLE_LOADING_TIME * 2 => ILogger::INFO,
default => ILogger::DEBUG,
};
$this->logger->log(
$logLevel,
'Capabilities of {className} took {duration} seconds to generate.',
[
'className' => get_class($c),
'duration' => round($timeSpent, 2),
]
);
$slowCapabilities[get_class($c)] = $timeSpent;
}
}
} else {
throw new \InvalidArgumentException('The given Capability (' . get_class($c) . ') does not implement the ICapability interface');
}
}

if ($slowCapabilities !== []) {
$this->logSlowCapabilities($slowCapabilities);
}

return $capabilities;
}

/**
* Log a single message for all capabilities that took too long to generate,
* using the highest log level applicable to the slowest one.
*
* @param array<string, float> $slowCapabilities Map of class name to time spent in seconds
*/
private function logSlowCapabilities(array $slowCapabilities): void {
$slowestTime = max($slowCapabilities);
$logLevel = match (true) {
$slowestTime > self::ACCEPTABLE_LOADING_TIME * 16 => ILogger::FATAL,
$slowestTime > self::ACCEPTABLE_LOADING_TIME * 8 => ILogger::ERROR,
$slowestTime > self::ACCEPTABLE_LOADING_TIME * 4 => ILogger::WARN,
$slowestTime > self::ACCEPTABLE_LOADING_TIME * 2 => ILogger::INFO,
default => ILogger::DEBUG,
};

$durations = [];
foreach ($slowCapabilities as $className => $timeSpent) {
$durations[] = $className . ' (' . round($timeSpent, 2) . 's)';
}

$this->logger->log(
$logLevel,
'Generating the capabilities of the following apps took longer than {acceptable} seconds: {capabilities}',
[
'acceptable' => self::ACCEPTABLE_LOADING_TIME,
'capabilities' => implode(', ', $durations),
]
);
}

/**
* In order to improve lazy loading a closure can be registered which will be called in case
* capabilities are actually requested
Expand Down
Loading