perf: Add config options to trigger individual and sample profiling using excimer

Signed-off-by: Julius Knorr <jus@bitgrid.net>
pull/52099/head
Julius Knorr 6 months ago
parent cb4fcd0f40
commit 3fc9a99521
  1. 4
      .reuse/dep5
  2. 282
      build/stubs/excimer.php
  3. 59
      config/config.sample.php
  4. 17
      lib/base.php
  5. 1
      lib/composer/composer/autoload_classmap.php
  6. 1
      lib/composer/composer/autoload_static.php
  7. 95
      lib/private/Profiler/BuiltInProfiler.php
  8. 1
      psalm.xml

@ -131,6 +131,10 @@ Files: build/stubs/pcntl.php build/stubs/zip.php
Copyright: 2022 JetBrains
License: Apache-2.0
Files: build/stubs/excimer.php
Copyright: 2019 Wikimedia Foundation
License: Apache-2.0
Files: core/js/mimetypelist.js core/js/core.json themes/example/core/img
Copyright: 2016 ownCloud, Inc., 2016-2024 Nextcloud GmbH and Nextcloud contributors
License: AGPL-3.0-only

@ -0,0 +1,282 @@
<?php
/** Real (wall-clock) time */
define('EXCIMER_REAL', 0);
/** CPU time (user and system) consumed by the thread during execution */
define('EXCIMER_CPU', 1);
/**
* A sampling profiler.
*
* Collects a stack trace every time a timer event fires.
*/
class ExcimerProfiler {
/**
* Set the period.
*
* This will take effect the next time start() is called.
*
* If this method is not called, the default period of 0.1 seconds
* will be used.
*
* @param float $period The period in seconds
*/
public function setPeriod($period) {
}
/**
* Set the event type. May be either EXCIMER_REAL, for real (wall-clock)
* time, or EXCIMER_CPU, for CPU time. The default is EXCIMER_REAL.
*
* This will take effect the next time start() is called.
*
* @param int $eventType
*/
public function setEventType($eventType) {
}
/**
* Set the maximum depth of stack trace collection. If this depth is
* exceeded, the traversal up the stack will be terminated, so the function
* will appear to have no caller.
*
* By default, there is no limit. If this is called with a depth of zero,
* the limit is disabled.
*
* This will take effect immediately.
*
* @param int $maxDepth
*/
public function setMaxDepth($maxDepth) {
}
/**
* Set a callback which will be called once the specified number of samples
* has been collected.
*
* When the ExcimerProfiler object is destroyed, the callback will also
* be called, unless no samples have been collected.
*
* The callback will be called with a single argument: the ExcimerLog
* object containing the samples. Before the callback is called, a new
* ExcimerLog object will be created and registered with the
* ExcimerProfiler. So ExcimerProfiler::getLog() should not be used from
* the callback, since it will not return the samples.
*
* @param callable $callback
* @param int $maxSamples
*/
public function setFlushCallback($callback, $maxSamples) {
}
/**
* Clear the flush callback. No callback will be called regardless of
* how many samples are collected.
*/
public function clearFlushCallback() {
}
/**
* Start the profiler. If the profiler was already running, it will be
* stopped and restarted with new options.
*/
public function start() {
}
/**
* Stop the profiler.
*/
public function stop() {
}
/**
* Get the current ExcimerLog object.
*
* Note that if the profiler is running, the object thus returned may be
* modified by a timer event at any time, potentially invalidating your
* analysis. Instead, the profiler should be stopped first, or flush()
* should be used.
*
* @return ExcimerLog
*/
public function getLog() {
}
/**
* Create and register a new ExcimerLog object, and return the old
* ExcimerLog object.
*
* This will return all accumulated events to this point, and reset the
* log with a new log of zero length.
*
* @return ExcimerLog
*/
public function flush() {
}
}
/**
* A collected series of stack traces and some utility methods to aggregate them.
*
* ExcimerLog acts as a container for ExcimerLogEntry objects. The Iterator or
* ArrayAccess interfaces may be used to access them. For example:
*
* foreach ( $profiler->getLog() as $entry ) {
* var_dump( $entry->getTrace() );
* }
*/
class ExcimerLog implements ArrayAccess, Iterator {
/**
* ExcimerLog is not constructible by user code. Objects of this type
* are available via:
* - ExcimerProfiler::getLog()
* - ExcimerProfiler::flush()
* - The callback to ExcimerProfiler::setFlushCallback()
*/
final private function __construct() {
}
/**
* Aggregate the stack traces and convert them to a line-based format
* understood by Brendan Gregg's FlameGraph utility. Each stack trace is
* represented as a series of function names, separated by semicolons.
* After this identifier, there is a single space character, then a number
* giving the number of times the stack appeared. Then there is a line
* break. This is repeated for each unique stack trace.
*
* @return string
*/
public function formatCollapsed() {
}
/**
* Produce an array with an element for every function which appears in
* the log. The key is a human-readable unique identifier for the function,
* method or closure. The value is an associative array with the following
* elements:
*
* - self: The number of events in which the function itself was running,
* no other userspace function was being called. This includes time
* spent in internal functions that this function called.
* - inclusive: The number of events in which this function appeared
* somewhere in the stack.
*
* And optionally the following elements, if they are relevant:
*
* - file: The filename in which the function appears
* - line: The exact line number at which the first relevant event
* occurred.
* - class: The class name in which the method is defined
* - function: The name of the function or method
* - closure_line: The line number at which the closure was defined
*
* The event counts in the "self" and "inclusive" fields are adjusted for
* overruns. They represent an estimate of the number of profiling periods
* in which those functions were present.
*
* @return array
*/
public function aggregateByFunction() {
}
/**
* Get an array which can be JSON encoded for import into speedscope
*
* @return array
*/
public function getSpeedscopeData() {
}
/**
* Get the total number of profiling periods represented by this log.
*
* @return int
*/
public function getEventCount() {
}
/**
* Get the current ExcimerLogEntry object. Part of the Iterator interface.
*
* @return ExcimerLogEntry|null
*/
public function current() {
}
/**
* Get the current integer key or null. Part of the Iterator interface.
*
* @return int|null
*/
public function key() {
}
/**
* Advance to the next log entry. Part of the Iterator interface.
*/
public function next() {
}
/**
* Rewind back to the first log entry. Part of the Iterator interface.
*/
public function rewind() {
}
/**
* Check if the current position is valid. Part of the Iterator interface.
*
* @return bool
*/
public function valid() {
}
/**
* Get the number of log entries contained in this log. This is always less
* than or equal to the number returned by getEventCount(), which includes
* overruns.
*
* @return int
*/
public function count() {
}
/**
* Determine whether a log entry exists at the specified array offset.
* Part of the ArrayAccess interface.
*
* @param int $offset
* @return bool
*/
public function offsetExists($offset) {
}
/**
* Get the ExcimerLogEntry object at the specified array offset.
*
* @param int $offset
* @return ExcimerLogEntry|null
*/
public function offsetGet($offset) {
}
/**
* This function is included for compliance with the ArrayAccess interface.
* It raises a warning and does nothing.
*
* @param int $offset
* @param mixed $value
*/
public function offsetSet($offset, $value) {
}
/**
* This function is included for compliance with the ArrayAccess interface.
* It raises a warning and does nothing.
*
* @param int $offset
*/
public function offsetUnset($offset) {
}
}

@ -1182,6 +1182,65 @@ $CONFIG = [
*/
'profiler' => false,
/**
* Enable profiling for individual requests if profiling single requests is enabled or the secret is passed.
* This requires the excimer extension to be installed. Be careful with this, as it can generate a lot of data.
*
* The profile data will be stored as a json file in the profiling.path directory that can be analysed with speedscope.
*
* Defaults to ``false``
*/
'profiling.request' => false,
/**
* The rate at which profiling data is collected for individual requests.
* A lower value means more data points but higher overhead.
*
* Defaults to ``0.001``
*/
'profiling.request.rate' => 0.001,
/**
* A secret token that can be passed via ?profile_secret=<secret> to enable profiling for a specific request.
* This allows profiling specific requests in production without enabling it globally.
*
* No default value.
*/
'profiling.secret' => '',
/**
* Enable sampling-based profiling. This collects profiling data periodically rather than per-request.
* This requires the excimer extension to be installed. Be careful with this, as it can generate a lot of data.
*
* The profile data will be stored as a plain text file in the profiling.path directory that can be analysed with speedscope.
*
* Defaults to ``false``
*/
'profiling.sample' => false,
/**
* The rate at which sampling profiling data is collected in seconds.
* A lower value means more frequent samples but higher overhead.
*
* Defaults to ``1``
*/
'profiling.sample.rate' => 1,
/**
* How often (in minutes) the sample log files are rotated.
*
* Defaults to ``60``
*/
'profiling.sample.rotation' => 60,
/**
* The directory where profiling data is stored.
*
* Note that this directory must be writable by the web server user and will not be cleaned up automatically.
*/
'profiling.path' => '/tmp',
/**
* Alternate Code Locations
*

@ -7,6 +7,7 @@ declare(strict_types=1);
* SPDX-License-Identifier: AGPL-3.0-only
*/
use OC\Encryption\HookManager;
use OC\Profiler\BuiltInProfiler;
use OC\Share20\GroupDeletedListener;
use OC\Share20\Hooks;
use OC\Share20\UserDeletedListener;
@ -14,6 +15,7 @@ use OC\Share20\UserRemovedListener;
use OCP\EventDispatcher\IEventDispatcher;
use OCP\Group\Events\GroupDeletedEvent;
use OCP\Group\Events\UserRemovedEvent;
use OCP\IConfig;
use OCP\ILogger;
use OCP\IRequest;
use OCP\IURLGenerator;
@ -126,7 +128,6 @@ class OC {
}
}
if (OC::$CLI) {
OC::$WEBROOT = self::$config->getValue('overwritewebroot', '');
} else {
@ -522,7 +523,7 @@ class OC {
* We use an additional cookie since we want to protect logout CSRF and
* also we can't directly interfere with PHP's session mechanism.
*/
private static function performSameSiteCookieProtection(\OCP\IConfig $config): void {
private static function performSameSiteCookieProtection(IConfig $config): void {
$request = Server::get(IRequest::class);
// Some user agents are notorious and don't really properly follow HTTP
@ -635,6 +636,16 @@ class OC {
self::$server = new \OC\Server(\OC::$WEBROOT, self::$config);
self::$server->boot();
try {
$profiler = new BuiltInProfiler(
Server::get(IConfig::class),
Server::get(IRequest::class),
);
$profiler->start();
} catch (\Throwable $e) {
logger('core')->error('Failed to start profiler: ' . $e->getMessage(), ['app' => 'base']);
}
if (self::$CLI && in_array('--' . \OCP\Console\ReservedOptions::DEBUG_LOG, $_SERVER['argv'])) {
\OC\Core\Listener\BeforeMessageLoggedEventListener::setup();
}
@ -654,7 +665,7 @@ class OC {
// initialize intl fallback if necessary
OC_Util::isSetLocaleWorking();
$config = Server::get(\OCP\IConfig::class);
$config = Server::get(IConfig::class);
if (!defined('PHPUNIT_RUN')) {
$errorHandler = new OC\Log\ErrorHandler(
\OCP\Server::get(\Psr\Log\LoggerInterface::class),

@ -1852,6 +1852,7 @@ return array(
'OC\\Profile\\Actions\\WebsiteAction' => $baseDir . '/lib/private/Profile/Actions/WebsiteAction.php',
'OC\\Profile\\ProfileManager' => $baseDir . '/lib/private/Profile/ProfileManager.php',
'OC\\Profile\\TProfileHelper' => $baseDir . '/lib/private/Profile/TProfileHelper.php',
'OC\\Profiler\\BuiltInProfiler' => $baseDir . '/lib/private/Profiler/BuiltInProfiler.php',
'OC\\Profiler\\FileProfilerStorage' => $baseDir . '/lib/private/Profiler/FileProfilerStorage.php',
'OC\\Profiler\\Profile' => $baseDir . '/lib/private/Profiler/Profile.php',
'OC\\Profiler\\Profiler' => $baseDir . '/lib/private/Profiler/Profiler.php',

@ -1893,6 +1893,7 @@ class ComposerStaticInit749170dad3f5e7f9ca158f5a9f04f6a2
'OC\\Profile\\Actions\\WebsiteAction' => __DIR__ . '/../../..' . '/lib/private/Profile/Actions/WebsiteAction.php',
'OC\\Profile\\ProfileManager' => __DIR__ . '/../../..' . '/lib/private/Profile/ProfileManager.php',
'OC\\Profile\\TProfileHelper' => __DIR__ . '/../../..' . '/lib/private/Profile/TProfileHelper.php',
'OC\\Profiler\\BuiltInProfiler' => __DIR__ . '/../../..' . '/lib/private/Profiler/BuiltInProfiler.php',
'OC\\Profiler\\FileProfilerStorage' => __DIR__ . '/../../..' . '/lib/private/Profiler/FileProfilerStorage.php',
'OC\\Profiler\\Profile' => __DIR__ . '/../../..' . '/lib/private/Profiler/Profile.php',
'OC\\Profiler\\Profiler' => __DIR__ . '/../../..' . '/lib/private/Profiler/Profiler.php',

@ -0,0 +1,95 @@
<?php
declare(strict_types=1);
/**
* SPDX-FileCopyrightText: 2025 Nextcloud GmbH and Nextcloud contributors
* SPDX-License-Identifier: AGPL-3.0-only
*/
namespace OC\Profiler;
use DateTime;
use OCP\IConfig;
use OCP\IRequest;
class BuiltInProfiler {
private \ExcimerProfiler $excimer;
public function __construct(
private IConfig $config,
private IRequest $request,
) {
}
public function start(): void {
if (!extension_loaded('excimer')) {
return;
}
$shouldProfileSingleRequest = $this->shouldProfileSingleRequest();
$shouldSample = $this->config->getSystemValueBool('profiling.sample') && !$shouldProfileSingleRequest;
if (!$shouldProfileSingleRequest && !$shouldSample) {
return;
}
$requestRate = $this->config->getSystemValue('profiling.request.rate', 0.001);
$sampleRate = $this->config->getSystemValue('profiling.sample.rate', 1.0);
$eventType = $this->config->getSystemValue('profiling.event_type', EXCIMER_REAL);
$this->excimer = new \ExcimerProfiler();
$this->excimer->setPeriod($shouldProfileSingleRequest ? $requestRate : $sampleRate);
$this->excimer->setEventType($eventType);
$this->excimer->setMaxDepth(250);
if ($shouldSample) {
$this->excimer->setFlushCallback([$this, 'handleSampleFlush'], 1);
}
$this->excimer->start();
register_shutdown_function([$this, 'handleShutdown']);
}
public function handleSampleFlush(\ExcimerLog $log): void {
file_put_contents($this->getSampleFilename(), $log->formatCollapsed(), FILE_APPEND);
}
public function handleShutdown(): void {
$this->excimer->stop();
if (!$this->shouldProfileSingleRequest()) {
$this->excimer->flush();
return;
}
$request = \OCP\Server::get(IRequest::class);
$data = $this->excimer->getLog()->getSpeedscopeData();
$data['profiles'][0]['name'] = $request->getMethod() . ' ' . $request->getRequestUri() . ' ' . $request->getId();
file_put_contents($this->getProfileFilename(), json_encode($data, JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE));
}
private function shouldProfileSingleRequest(): bool {
$shouldProfileSingleRequest = $this->config->getSystemValueBool('profiling.request', false);
$profileSecret = $this->config->getSystemValueString('profiling.secret', '');
$secretParam = $this->request->getParam('profile_secret') ?? null;
return $shouldProfileSingleRequest || (!empty($profileSecret) && $profileSecret === $secretParam);
}
private function getSampleFilename(): string {
$profilePath = $this->config->getSystemValueString('profiling.path', '/tmp');
$sampleRotation = $this->config->getSystemValueInt('profiling.sample.rotation', 60);
$timestamp = floor(time() / ($sampleRotation * 60)) * ($sampleRotation * 60);
$sampleName = date('Y-m-d_Hi', (int)$timestamp);
return $profilePath . '/sample-' . $sampleName . '.log';
}
private function getProfileFilename(): string {
$profilePath = $this->config->getSystemValueString('profiling.path', '/tmp');
$requestId = $this->request->getId();
return $profilePath . '/profile-' . (new DateTime)->format('Y-m-d_His_v') . '-' . $requestId . '.json';
}
}

@ -74,6 +74,7 @@
</extraFiles>
<stubs>
<file name="build/stubs/apcu.php"/>
<file name="build/stubs/excimer.php"/>
<file name="build/stubs/gd.php"/>
<file name="build/stubs/imagick.php"/>
<file name="build/stubs/intl.php"/>

Loading…
Cancel
Save