diff --git a/.github/workflows/acceptance.yml b/.github/workflows/acceptance.yml index d7221042c..48d51e184 100644 --- a/.github/workflows/acceptance.yml +++ b/.github/workflows/acceptance.yml @@ -6,7 +6,7 @@ on: behat_tags: description: 'Behat tags to execute' required: true - default: '~@performance' + default: '' moodle_branch: description: 'Moodle branch' required: true @@ -27,7 +27,7 @@ jobs: MOODLE_DOCKER_PHP_VERSION: '8.1' MOODLE_BRANCH: ${{ github.event.inputs.moodle_branch || 'main' }} MOODLE_REPOSITORY: ${{ github.event.inputs.moodle_repository || 'https://github.com/moodle/moodle' }} - BEHAT_TAGS: ${{ github.event.inputs.behat_tags || '~@performance' }} + BEHAT_TAGS: ${{ github.event.inputs.behat_tags || '' }} steps: - uses: actions/checkout@v4 diff --git a/.github/workflows/performance.yml b/.github/workflows/performance.yml deleted file mode 100644 index fa5ecdd61..000000000 --- a/.github/workflows/performance.yml +++ /dev/null @@ -1,58 +0,0 @@ -name: Performance - -on: [ workflow_dispatch ] - -jobs: - performance: - runs-on: ubuntu-latest - env: - MOODLE_DOCKER_DB: pgsql - MOODLE_DOCKER_BROWSER: chrome - MOODLE_DOCKER_PHP_VERSION: '8.0' - steps: - - uses: actions/checkout@v4 - - uses: actions/setup-node@v4 - with: - node-version-file: '.nvmrc' - - name: Additional checkouts - run: | - git clone --branch main --depth 1 https://github.com/moodle/moodle $GITHUB_WORKSPACE/moodle - git clone --branch main --depth 1 https://github.com/moodlehq/moodle-docker $GITHUB_WORKSPACE/moodle-docker - - name: Install npm packages - run: npm ci --no-audit - - name: Generate Behat tests plugin - run: | - export MOODLE_DOCKER_WWWROOT=$GITHUB_WORKSPACE/moodle - npx gulp behat - - name: Configure & launch Moodle with Docker - run: | - export MOODLE_DOCKER_WWWROOT=$GITHUB_WORKSPACE/moodle - cp $GITHUB_WORKSPACE/moodle-docker/config.docker-template.php $GITHUB_WORKSPACE/moodle/config.php - sed -i "67i\ 'capabilities' => [" $GITHUB_WORKSPACE/moodle/config.php - sed -i "68i\ 'extra_capabilities' => [" $GITHUB_WORKSPACE/moodle/config.php - sed -i "69i\ 'goog:loggingPrefs' => ['performance' => 'ALL']," $GITHUB_WORKSPACE/moodle/config.php - sed -i "70i\ 'chromeOptions' => ['perfLoggingPrefs' => ['traceCategories' => 'devtools.timeline']]," $GITHUB_WORKSPACE/moodle/config.php - sed -i "71i\ ]," $GITHUB_WORKSPACE/moodle/config.php - sed -i "72i\ ]," $GITHUB_WORKSPACE/moodle/config.php - sed -i "84i\$CFG->behat_ionic_wwwroot = 'http://moodleapp';" $GITHUB_WORKSPACE/moodle/config.php - $GITHUB_WORKSPACE/moodle-docker/bin/moodle-docker-compose pull - $GITHUB_WORKSPACE/moodle-docker/bin/moodle-docker-compose up -d - $GITHUB_WORKSPACE/moodle-docker/bin/moodle-docker-wait-for-db - - name: Compile & launch app with Docker - run: | - docker build --build-arg build_command="npm run build:test" -t moodlehq/moodleapp:performance . - docker run -d --rm --name moodleapp moodlehq/moodleapp:performance - docker network connect moodle-docker_default moodleapp --alias moodleapp - - name: Init Behat - run: | - export MOODLE_DOCKER_WWWROOT=$GITHUB_WORKSPACE/moodle - $GITHUB_WORKSPACE/moodle-docker/bin/moodle-docker-compose exec -T webserver sh -c "php admin/tool/behat/cli/init.php" - - name: Run performance tests - run: | - export MOODLE_DOCKER_WWWROOT=$GITHUB_WORKSPACE/moodle - for i in {0..2} - do - $GITHUB_WORKSPACE/moodle-docker/bin/moodle-docker-compose exec -T webserver sh -c "php admin/tool/behat/cli/run.php --tags="@performance" --auto-rerun" - done - - name: Show performance results - run: node ./scripts/print-performance-measures.js $GITHUB_WORKSPACE/moodle/behatperformancemeasures/ diff --git a/local_moodleappbehat/tests/behat/behat_app.php b/local_moodleappbehat/tests/behat/behat_app.php index c3a5d65ab..696b3a1e2 100644 --- a/local_moodleappbehat/tests/behat/behat_app.php +++ b/local_moodleappbehat/tests/behat/behat_app.php @@ -57,7 +57,6 @@ class behat_app extends behat_app_helper { } $this->featurepath = dirname($feature->getFile()); - $this->configure_performance_logs(); } /** @@ -82,23 +81,6 @@ class behat_app extends behat_app_helper { $this->enter_site(); } - /** - * Configure performance logs. - */ - protected function configure_performance_logs() { - global $CFG; - - $performanceLogs = $CFG->behat_profiles['default']['capabilities']['extra_capabilities']['goog:loggingPrefs']['performance'] ?? null; - - if ($performanceLogs !== 'ALL') { - return; - } - - // Enable DB Logging only for app tests with performance logs activated. - $this->getSession()->visit($this->get_app_url() . '/assets/env.json'); - $this->execute_script("document.cookie = 'MoodleAppDBLoggingEnabled=true;path=/';"); - } - /** * Check whether the current page is the login form. */ diff --git a/local_moodleappbehat/tests/behat/behat_performance.php b/local_moodleappbehat/tests/behat/behat_performance.php deleted file mode 100644 index 72f1b25c0..000000000 --- a/local_moodleappbehat/tests/behat/behat_performance.php +++ /dev/null @@ -1,128 +0,0 @@ -. - -use Behat\Mink\Exception\DriverException; -use Behat\Mink\Exception\ExpectationException; - -require_once(__DIR__ . '/../../../../lib/behat/behat_base.php'); -require_once(__DIR__ . '/classes/performance_measure.php'); - -/** - * Behat step definitions to measure performance. - */ -class behat_performance extends behat_base { - - /** - * @var array - */ - private $measures = []; - - /** - * Start measuring performance. - * - * @When /^I start measuring "([^"]+)"$/ - */ - public function i_start_measuring(string $name) { - $this->measures[$name] = new performance_measure($name, $this->getSession()->getDriver()); - $this->measures[$name]->start(); - } - - /** - * Stop measuring performance. - * - * @When /^I stop measuring "([^"]+)"$/ - */ - public function i_stop_measuring(string $name) { - $this->get_performance_measure($name)->end(); - } - - /** - * Assert how long a performance measure took. - * - * @Then /^"([^"]+)" should have taken (less than|more than|exactly) (\d+(?:\.\d+)? (?:seconds|milliseconds))$/ - */ - public function timing_should_have_taken(string $measure, string $comparison, string $expectedtime) { - $measuretiming = $this->get_performance_measure($measure); - $comparison = $this->parse_comparison($comparison); - $expectedtime = $this->parse_time($expectedtime); - - if (!call_user_func($comparison, $measuretiming->duration, $expectedtime)) { - throw new ExpectationException( - "Expected duration for '$measure' failed! (took {$measuretiming->duration}ms)", - $this->getSession()->getDriver() - ); - } - - $measuretiming->store(); - } - - /** - * Parse time. - * - * @param string $text Time string. - * @return float - */ - private function parse_time(string $text): float { - $spaceindex = strpos($text, ' '); - $value = floatval(substr($text, 0, $spaceindex)); - - if (substr($text, $spaceindex + 1) == 'seconds') { - $value *= 1000; - } - - return $value; - } - - /** - * Parse a comparison function. - * - * @param string $text Comparison string. - * @return Closure - */ - private function parse_comparison(string $text): Closure { - switch ($text) { - case 'less than': - return function ($a, $b) { - return $a < $b; - }; - case 'more than': - return function ($a, $b) { - return $a > $b; - }; - case 'exactly': - return function ($a, $b) { - return $a === $b; - }; - default: - break; - } - } - - /** - * Get performance measure by name. - * - * @param string $name Performance measure name. - * @return performance_measure Performance measure. - */ - private function get_performance_measure(string $name): performance_measure { - if (!isset($this->measures[$name])) { - throw new DriverException("'$name' performance measure does not exist."); - } - - return $this->measures[$name]; - } - -} diff --git a/local_moodleappbehat/tests/behat/classes/performance_measure.php b/local_moodleappbehat/tests/behat/classes/performance_measure.php deleted file mode 100644 index db3b378de..000000000 --- a/local_moodleappbehat/tests/behat/classes/performance_measure.php +++ /dev/null @@ -1,346 +0,0 @@ -. - -use Behat\Mink\Exception\DriverException; -use Facebook\WebDriver\Exception\InvalidArgumentException; -use Moodle\BehatExtension\Driver\WebDriver; - -require_once(__DIR__ . '/../behat_app.php'); - -/** - * Performance measures for one particular metric. - */ -class performance_measure implements behat_app_listener { - - const STORAGE_FOLDER = '/behatperformancemeasures/'; - - /** - * @var string - */ - public $name; - - /** - * @var int - */ - public $start; - - /** - * @var int - */ - public $end; - - /** - * @var int - */ - public $duration; - - /** - * @var int - */ - public $scripting; - - /** - * @var int - */ - public $styling; - - /** - * @var int - */ - public $blocking; - - /** - * @var int - */ - public $databaseStart; - - /** - * @var int - */ - public $database; - - /** - * @var int - */ - public $networking; - - /** - * @var array - */ - private $longTasks = []; - - /** - * @var Closure - */ - private $behatAppUnsubscribe; - - /** - * @var Moodle\BehatExtension\Driver\WebDriver - */ - private $driver; - - public function __construct(string $name, WebDriver $driver) { - $this->name = $name; - $this->driver = $driver; - } - - /** - * Start timing. - */ - public function start(): void { - $this->start = $this->now(); - - $this->observeLongTasks(); - $this->startDatabaseCount(); - - $this->behatAppUnsubscribe = behat_app::listen($this); - } - - /** - * Stop timing. - */ - public function end(): void { - $this->end = $this->now(); - - $this->stopLongTasksObserver(); - - call_user_func($this->behatAppUnsubscribe); - $this->behatAppUnsubscribe = null; - - $this->analyseDuration(); - $this->analyseLongTasks(); - $this->analyseDatabaseUsage(); - $this->analysePerformanceLogs(); - } - - /** - * Persist measure logs in storage. - */ - public function store(): void { - global $CFG; - - $storagefolderpath = $CFG->dirroot . static::STORAGE_FOLDER; - - if (!file_exists($storagefolderpath)) { - mkdir($storagefolderpath); - } - - $data = [ - 'name' => $this->name, - 'start' => $this->start, - 'end' => $this->end, - 'duration' => $this->duration, - 'scripting' => $this->scripting, - 'styling' => $this->styling, - 'blocking' => $this->blocking, - 'longTasks' => count($this->longTasks), - 'database' => $this->database, - 'networking' => $this->networking, - ]; - - file_put_contents($storagefolderpath . time() . '.json', json_encode($data)); - } - - /** - * @inheritdoc - */ - public function on_app_load(): void { - if (is_null($this->start) || !is_null($this->end)) { - return; - } - - $this->observeLongTasks(); - } - - /** - * @inheritdoc - */ - public function on_app_unload(): void { - $this->stopLongTasksObserver(); - } - - /** - * Get current time. - * - * @return int Current time in milliseconds. - */ - private function now(): int { - return $this->driver->evaluateScript('Date.now()'); - } - - /** - * Start observing long tasks. - */ - private function observeLongTasks(): void { - $this->driver->executeScript(" - if (window.MA_PERFORMANCE_OBSERVER) return; - - window.MA_LONG_TASKS = []; - window.MA_PERFORMANCE_OBSERVER = new PerformanceObserver(list => { - for (const entry of list.getEntries()) { - window.MA_LONG_TASKS.push(entry); - } - }); - window.MA_PERFORMANCE_OBSERVER.observe({ entryTypes: ['longtask'] }); - "); - } - - /** - * Record how many database queries have been logged so far. - */ - private function startDatabaseCount(): void { - try { - $this->databaseStart = $this->driver->evaluateScript('dbProvider.queryLogs.length') ?? 0; - } catch (Exception $e) { - $this->databaseStart = 0; - } - } - - /** - * Flush Performance observer. - */ - private function stopLongTasksObserver(): void { - $newLongTasks = $this->driver->evaluateScript(" - return (function() { - if (!window.MA_PERFORMANCE_OBSERVER) { - return []; - } - - window.MA_PERFORMANCE_OBSERVER.disconnect(); - - const observer = window.MA_PERFORMANCE_OBSERVER; - const longTasks = window.MA_LONG_TASKS; - - delete window.MA_PERFORMANCE_OBSERVER; - delete window.MA_LONG_TASKS; - - return [...longTasks, ...observer.takeRecords()]; - })(); - "); - - if ($newLongTasks) { - $this->longTasks = array_merge($this->longTasks, $newLongTasks); - } - } - - /** - * Analyse duration. - */ - private function analyseDuration(): void { - $this->duration = $this->end - $this->start; - } - - /** - * Analyse long tasks. - */ - private function analyseLongTasks(): void { - $blockingDuration = 0; - - foreach ($this->longTasks as $longTask) { - $blockingDuration += $longTask['duration'] - 50; - } - - $this->blocking = $blockingDuration; - } - - /** - * Analyse database usage. - */ - private function analyseDatabaseUsage(): void { - $this->database = $this->driver->evaluateScript('dbProvider.queryLogs.length') - $this->databaseStart; - } - - /** - * Analyse performance logs. - */ - private function analysePerformanceLogs(): void { - global $CFG; - - $scriptingDuration = 0; - $stylingDuration = 0; - $networkingCount = 0; - $logs = $this->getPerformanceLogs(); - - foreach ($logs as $log) { - // TODO this should filter by end time as well, but it seems like the timestamps are not - // working as expected. - if ($log['timestamp'] < $this->start) { - continue; - } - - $message = json_decode($log['message'])->message; - $messagename = $message->params->name ?? ''; - - if (in_array($messagename, ['FunctionCall', 'GCEvent', 'MajorGC', 'MinorGC', 'EvaluateScript'])) { - $scriptingDuration += $message->params->dur; - - continue; - } - - if (in_array($messagename, ['UpdateLayoutTree', 'RecalculateStyles', 'ParseAuthorStyleSheet'])) { - $stylingDuration += $message->params->dur; - - continue; - } - - if (in_array($messagename, ['XHRLoad']) && !str_starts_with($message->params->args->data->url, $CFG->behat_ionic_wwwroot)) { - $networkingCount++; - - continue; - } - } - - $this->scripting = round($scriptingDuration / 1000); - $this->styling = round($stylingDuration / 1000); - $this->networking = $networkingCount; - } - - /** - * Get performance logs. - * - * @return array Performance logs. - */ - private function getPerformanceLogs(): array { - try { - return $this->driver->getWebDriver()->manage()->getLog('performance'); - } catch (InvalidArgumentException $e) { - throw new DriverException( - implode("\n", [ - "It wasn't possible to get performance logs, make sure that you have configured the following capabilities:", - "", - "\$CFG->behat_profiles = [", - " 'default' => [", - " 'browser' => 'chrome',", - " 'wd_host' => 'http://selenium:4444/wd/hub',", - " 'capabilities' => [", - " 'extra_capabilities' => [", - " 'goog:loggingPrefs' => ['performance' => 'ALL'],", - " 'chromeOptions' => [", - " 'perfLoggingPrefs' => [", - " 'traceCategories' => 'devtools.timeline',", - " ],", - " ],", - " ],", - " ],", - " ],", - "];", - "", - ]) - ); - } - } - -} diff --git a/scripts/print-performance-measures.js b/scripts/print-performance-measures.js deleted file mode 100755 index 24019b117..000000000 --- a/scripts/print-performance-measures.js +++ /dev/null @@ -1,87 +0,0 @@ -#!/usr/bin/env node - -// (C) Copyright 2015 Moodle Pty Ltd. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -const { readdirSync, readFileSync } = require('fs'); - -if (process.argv.length < 3) { - console.error('Missing measure timings storage path argument'); - process.exit(1); -} - -const performanceMeasuresStoragePath = process.argv[2].trimRight('/') + '/'; -const files = readdirSync(performanceMeasuresStoragePath); -const performanceMeasures = {}; - -if (files.length === 0) { - console.log('No logs found!'); - process.exit(0); -} - -// Aggregate data -for (const file of files) { - const performanceMeasure = JSON.parse(readFileSync(performanceMeasuresStoragePath + file)); - - performanceMeasures[performanceMeasure.name] = performanceMeasures[performanceMeasure.name] ?? { - duration: [], - scripting: [], - styling: [], - blocking: [], - longTasks: [], - database: [], - networking: [], - }; - performanceMeasures[performanceMeasure.name].duration.push(performanceMeasure.duration); - performanceMeasures[performanceMeasure.name].scripting.push(performanceMeasure.scripting); - performanceMeasures[performanceMeasure.name].styling.push(performanceMeasure.styling); - performanceMeasures[performanceMeasure.name].blocking.push(performanceMeasure.blocking); - performanceMeasures[performanceMeasure.name].longTasks.push(performanceMeasure.longTasks); - performanceMeasures[performanceMeasure.name].database.push(performanceMeasure.database); - performanceMeasures[performanceMeasure.name].networking.push(performanceMeasure.networking); -} - -// Calculate averages -for (const [name, { duration, scripting, styling, blocking, longTasks, database, networking }] of Object.entries(performanceMeasures)) { - const totalRuns = duration.length; - const averageDuration = Math.round(duration.reduce((total, duration) => total + duration) / totalRuns); - const averageScripting = Math.round(scripting.reduce((total, scripting) => total + scripting) / totalRuns); - const averageStyling = Math.round(styling.reduce((total, styling) => total + styling) / totalRuns); - const averageBlocking = Math.round(blocking.reduce((total, blocking) => total + blocking) / totalRuns); - const averageLongTasks = Math.round(longTasks.reduce((total, longTasks) => total + longTasks) / totalRuns); - const averageDatabase = Math.round(database.reduce((total, database) => total + database) / totalRuns); - const averageNetworking = Math.round(networking.reduce((total, networking) => total + networking) / totalRuns); - - performanceMeasures[name] = { - 'Total duration': `${averageDuration}ms`, - 'Scripting': `${averageScripting}ms`, - 'Styling': `${averageStyling}ms`, - 'Blocking': `${averageBlocking}ms`, - '# Network requests': averageNetworking, - '# DB Queries': averageDatabase, - '# Long Tasks': averageLongTasks, - '# runs': totalRuns, - }; -} - -// Sort tests -const tests = Object.keys(performanceMeasures).sort(); -const sortedPerformanceMeasures = {}; - -for (const test of tests) { - sortedPerformanceMeasures[test] = performanceMeasures[test]; -} - -// Display data -console.table(sortedPerformanceMeasures); diff --git a/src/core/tests/behat/performance.feature b/src/core/tests/behat/performance.feature deleted file mode 100644 index 950dfee4e..000000000 --- a/src/core/tests/behat/performance.feature +++ /dev/null @@ -1,99 +0,0 @@ -@app @javascript @performance -Feature: Measure performance. - - # In order to run performance tests, you need to add the following capabilities to your Behat configuration: - # - # $CFG->behat_profiles = [ - # 'default' => [ - # 'browser' => 'chrome', - # 'wd_host' => 'http://selenium:4444/wd/hub', - # 'capabilities' => [ - # 'extra_capabilities' => [ - # 'goog:loggingPrefs' => ['performance' => 'ALL'], - # 'chromeOptions' => [ - # 'perfLoggingPrefs' => [ - # 'traceCategories' => 'devtools.timeline', - # ], - # ], - # ], - # ], - # ], - # ]; - - Background: - Given the following "users" exist: - | username | - | student1 | - And the following "courses" exist: - | fullname | shortname | category | - | Course 1 | C1 | 0 | - And the following "course enrolments" exist: - | user | course | role | - | student1 | C1 | student | - And the following "activities" exist: - | activity | name | intro | course | idnumber | option | section | - | choice | Choice course 1 | Test choice description | C1 | choice1 | Option 1, Option 2, Option 3 | 1 | - - Scenario: First Contentful Paint - Given I start measuring "First Contentful Paint" - When I launch the app runtime - Then I should find "Welcome to the Moodle App!" in the app - - When I stop measuring "First Contentful Paint" - Then "First Contentful Paint" should have taken less than 6 seconds - - Scenario: Time to Interactive - Given I start measuring "Time to Interactive" - When I launch the app runtime - Then I should find "Welcome to the Moodle App!" in the app - - When I press "Skip" in the app - Then I should not find "Skip" in the app - And I should find "Connect to Moodle" in the app - - When I stop measuring "Time to Interactive" - Then "Time to Interactive" should have taken less than 7 seconds - - Scenario: Total Blocking Time - Given I launch the app runtime - Then I should find "Welcome to the Moodle App!" in the app - - When I start measuring "Total Blocking Time" - And I press "Skip" in the app - Then I should not find "Skip" in the app - And I should find "Connect to Moodle" in the app - - When I stop measuring "Total Blocking Time" - Then "Total Blocking Time" should have taken less than 2 seconds - - Scenario: Login - When I launch the app - Then I should see "Connect to Moodle" - But I should not see "Welcome to the Moodle App!" - - When I start measuring "Login" - And I set the field "Your site" to "$WWWROOT" in the app - And I press "Connect to your site" in the app - And I log in as "student1" - And I should find "Timeline" in the app - - When I stop measuring "Login" - Then "Login" should have taken less than 10 seconds - - Scenario: Open Activity - Given I entered the app as "student1" - Then I press "My courses" in the app - And I should find "Course 1" in the app - - When I reload the page - And I start measuring "Open Activity" - And I wait the app to restart - Then I should find "Course 1" in the app - - When I enter the course "Course 1" in the app - And I press "Choice course 1" in the app - Then I should find "Option 1" in the app - - When I stop measuring "Open Activity" - # TODO Check back to 7s or review perfect timings - Then "Open Activity" should have taken less than 8 seconds