[meta] Create a 'Profiling' install profile, for testbot-powered simple profiling and easier local profiling

Note: all the DataCollectors and service wrappers were essentially copy/pasted from https://www.drupal.org/project/webprofiler. Many thanks to lussoluca and dawehner for Web Profiler!

The 'Profiling' profile's default config is identical to this:

cp profiles/standard/config/install/* profiles/profiling/config/install/
cp profiles/testing/config/install/* profiles/profiling/config/install/

I've attached a *-without_config_files-do-not-test.patch file for easier reviewing.

For reviewers:

1. we can add more data collectors, but I kept it to 3 simple/clear/cleanly implementable ones for this initial patch: cache, config and services
2. the default content is being generated in profiling.install
3. the profiled scenarios are these:
   

     /**
      * Profiles various scenarios, compares with the expected profiling data.
      */
     public function testScenarios() {
       $this->profileScenario('anon, front page, cold cache', '', new ExpectedProfilingData(73, 70, 67, 210));
       $this->profileScenario('anon, front page, warm cache', '', new ExpectedProfilingData(84, 0, 34, 194));
       $this->profileScenario('anon, 404, cold cache', 'non-existing-relative-url-that-will-result-in-a-404', new ExpectedProfilingData(15, 0, 26, 167));
       $this->profileScenario('anon, 404, warm cache', 'non-existing-relative-url-that-will-result-in-a-404', new ExpectedProfilingData(15, 0, 26, 167));
       $this->profileScenario('anon, /contact, cold cache', 'contact', new ExpectedProfilingData(40, 9, 32, 181));
       $this->profileScenario('anon, /contact, warm cache', 'contact', new ExpectedProfilingData(43, 0, 31, 181));
       $this->drupalGet('system/ajax');
       $this->profileScenario('anon, /system/ajax, warm cache', 'system/ajax', new ExpectedProfilingData(3, 0, 6, 135));
   
       $this->drupalLogin($this->root_user);
       $this->profileScenario('auth, front page, cold cache', '', new ExpectedProfilingData(109, 11, 48, 199));
       $this->profileScenario('auth, front page, warm cache', '', new ExpectedProfilingData(93, 0, 39, 197));
       $this->profileScenario('auth, 404, cold cache', 'non-existing-relative-url-that-will-result-in-a-404', new ExpectedProfilingData(25, 1, 33, 172));
       $this->profileScenario('auth, 404, warm cache', 'non-existing-relative-url-that-will-result-in-a-404', new ExpectedProfilingData(26, 0, 33, 172));
       $this->drupalGet('system/ajax');
       $this->profileScenario('auth, /system/ajax, warm cache', 'system/ajax', new ExpectedProfilingData(3, 0, 5, 134));
       $this->profileScenario('auth, /admin, cold cache', 'admin', new ExpectedProfilingData(37, 6, 31, 176));
       $this->profileScenario('auth, /admin, warm cache', 'admin', new ExpectedProfilingData(40, 0, 30, 176));
       $this->profileScenario('auth, /node/add/article, cold cache', 'admin', new ExpectedProfilingData(40, 0, 30, 176));
       $this->profileScenario('auth, /node/add/article, warm cache', 'admin', new ExpectedProfilingData(40, 0, 30, 176));
     }
   

4. This reuses a lot from Symfony:
   

   services:
     profiler:
       class: Symfony\Component\HttpKernel\Profiler\Profiler
       arguments: ['@profiler.file_storage', '@logger.channel.profiler']
     profiler.listener:
       class: Symfony\Component\HttpKernel\EventListener\ProfilerListener
       arguments: ['@profiler']
       tags:
         - { name: event_subscriber }
     profiler.file_storage:
       class: Symfony\Component\HttpKernel\Profiler\FileProfilerStorage
       arguments: ['%data_collector.storage%']
     logger.channel.profiler:
       class: Drupal\Core\Logger\LoggerChannel
       factory_method: get
       factory_service: logger.factory
       arguments: ['profiler']
   

#3.1: I didn't add it to normal core because 1) it has no UI; it can only be used programmatically, 2) it's intended to be hidden (so to #3.5: yes!) — it's specifically designed to be used by the tests. Perhaps I should rename it to test_profiler. Therefore I think #3.2 is also unnecsesary.

#3.3: I agree that this feels bizarre — but as you already say, it comes straight from Web Profiler. I do think it's valuable to register the number of cache hits. But I also think we should record how many actual "cache gets" there are. If we have 50 cache hits, but get them in 20 cache gets, that's important to know.

#3.4: Indeed :)

#4: Great to get confirmation, thanks :)

#6: not yet, but it could. I fear those results do depend on the environment though: PHP version and CPU architecture would affect this, and possibly the OS used as well.

Turning this into a meta, we should get this done, in baby steps. @dawehner and @amateescu are taking this on.

Per #2497185-20: [no patch] Create standardized core profiling scenarios and start tracking metrics for them, where we also agreed upon the (initial) set of scenarios to profile:

Proposed plan of attack. (From a call with Moshe, effulgentsia, catch and Tyler Littlefield.)

1. Put the scenarios in the IS into core in #2308683: [meta] Create a 'Profiling' install profile, for testbot-powered simple profiling and easier local profiling.
2. We should automate metrics that we can automate, to get feedback *while* we're working on core.
   We'll add metrics one by one, to ensure they don't increase beyond the recorded number, starting with:
   1. peak mem: number+5%
   2. DB queries (if possible: distinguish between reads and inserts): exact number
   3. initialized services: exact number
3. The number of function calls, we cannot automate. So, we should manually record the number of function calls in the various scenarios today, and then compare before tagging the first RC. (For RC, it should simply not exceed the number as of today.)

Doing steps 1 and 2.2 in #2497185: [no patch] Create standardized core profiling scenarios and start tracking metrics for them. Will file child issues for 2.2, 2.3 and 3 later.

(#19 accidentally removed the "meta" prefix, oops!)

Quoting @catch at #2497185-22: [no patch] Create standardized core profiling scenarios and start tracking metrics for them.

So, we should manually record the number of function calls in the various scenarios today, and then compare before tagging the first RC. (For RC, it should simply not exceed the number as of today.)

I think I'd probably want to modify this slightly to 'with critical performance patches applied' - just because if we don't do that, then we could in theory re-introduce the equivalent of several critical performance issues without noticing.

#21: I'm pretty sure that's happening because profiling_install() puts the first ten nodes in the main menu, yet that menu does not exist. It does not exist because the "Profiling" install profile in this patch does not include any config to be installed. The patch in #1 does. The patch in #1 basically copied all config from the "Standard" install profile. I think you want to do the same here. (And perhaps then modify it going forward, but that's a good starting point at least.)

I'll take a look at fixing #31. Will assign to me when I actually work on it.

This should fail with a single exception: for the single assertion that the newly added test adds.

#43 introduced a separate scenario to profile SQL. I don't think this makes sense: it requires us to render the exact same pages again. Why not collect that the first time around? This makes the test significantly slower.

In fact, it looks like this SQL data collector that you added made tests several orders of magnitude slower. It seems to send tests into some sort of recursive installation loop. I think because it's collecting the function call stack as well.

#19 mentioned 3 things: peak memory, SQL queries and initialized services. To help get this patch back on track, I'm adding the initialized services part back (it already was in #1), freshly copy/pasted from the webprofiler module.

I've added the DatabaseDataCollector from Web Profiler instead of the custom written SQL data collector. I'm not yet using that data collector in this patch though, because there's something interesting about it. See the next reroll.

I've also added a warm cache scenario, which shows how this was intended to be used.

1. +++ b/core/profiles/profiling/profiling.install
   --- /dev/null
   +++ b/core/profiles/profiling/src/SQLDataCollector.php
   
   +++ b/core/profiles/profiling/src/SQLDataCollector.php
   @@ -0,0 +1,34 @@
   +namespace Drupal\profiling;
   

   This does not belong in the install profile, but in \Drupal\Core\Profiler, like my patch in #1 already did.

2. +++ b/core/profiles/profiling/profiling.info.yml
   @@ -0,0 +1,44 @@
   +dependencies:
   +  - simpletest
   +  - node
   +  - history
   +  - block
   +  - breakpoint
   +  - ckeditor
   +  - color
   +  - config
   +  - comment
   +  - contextual
   +  - contact
   +  - datetime
   +  - block_content
   +  - quickedit
   +  - editor
   +  - entity_reference
   +  - help
   +  - image
   +  - menu_ui
   +  - menu_link_content
   +  - options
   +  - path
   +  - taxonomy
   +  - dblog
   +  - search
   +  - shortcut
   +  - toolbar
   +  - field_ui
   +  - file
   +  - rdf
   +  - views
   +  - views_ui
   +  - tour
   +  - text
   

   How did you end up with this list of modules to install? This is not at all a copy of the Standard install profile, and hence it's not actually testing something we want to be testing.

   The simpletest module for example never makes sense to enable when profiling.

   And the page_cache module is conspicuously missing, without explanation. (It should not be enabled because it is a middleware, during which no events are fired, and hence no profiling is possible. But that reason for its absence should be explicitly documented, and now it is.)

3. +++ b/core/profiles/profiling/modules/profiler/profiler.info.yml
   @@ -0,0 +1,6 @@
   +description: 'Will profilele variousus scenarios in the future, currently only peak memory. Stores the results in files.'
   

   s/profilele/profile/
   s/variousus/various/

   And generally outdated.

   Plus, factually wrong, because this does not profile scenarios. A module can never profile scenarios, only a test can. This is a module that simply gathers profiling data.

And now with query counts being measured. Note how the peak memory numbers increase drastically (from ~6% more than the expected number of 32 MB, to ~34% more). This makes sense: collecting all that query information causes the memory usage to increase.

I don't think there's a way around this. But … that really, really sucks. It's because the measuring logic and the measured logic both are part of the same problem. I don't think we can solve this.

Either we have some heuristic to subtract some number of memory bytes based on the number of logged queries, or we simply cannot measure database queries. (Or we need to update the DB API to provide a much more efficient way of measuring the number of queries.)

And here's some clean-up plus todos.

@sorressean: Can you please post the interdiff together with the patch next time? d.o supports attaching multiple files per comment. Or is there an accessibility problem with that perhaps?

So, all expected numbers have changed, which is why there are 6 exceptions. That's an easy fix :)

But, what's concerning is that the numbers are so vastly different. Let's first get a green patch, and let's then upload the same patch ten times in a single comment. That'll run the same tests ten times, so we'll see if the measured numbers are sufficiently consistent for this test to be reliable.

On a call with @effulgentsia, @sorressean and I, we decided to decrease the scope that was defined in #19: rather than doing peak mem, DB queries and initialized services, do only initialized services. That's still a great first step, still very valuable, but doesn't suffer from any of the problems with peak mem and DB queries.

(Problems with A) peak mem: opcache differences between testbots make it very unpredictable, infra improvements necessary, B) measuring DB queries, and the way that that is supported by doing extensive logging, significantly affects peak mem.)

1. +++ b/core/core.services.yml
   @@ -1508,3 +1508,10 @@ services:
   +  # Data collector for profiling.
   

   This comment is rather pointless, since the service tag already indicates that. Let's remove it.

2. +++ b/core/lib/Drupal/Core/Profiler/ServiceDataCollector.php
   @@ -0,0 +1,78 @@
   +<?php
   +
   +namespace Drupal\Core\Profiler;
   

   Missing docs.

3. +++ b/core/lib/Drupal/Core/Profiler/ServiceDataCollector.php
   @@ -0,0 +1,78 @@
   +class ServiceDataCollector extends DataCollector {
   

   Missing docs.

4. +++ b/core/lib/Drupal/Core/Profiler/ServiceDataCollector.php
   @@ -0,0 +1,78 @@
   +  /**
   +   * @var \Symfony\Component\DependencyInjection\IntrospectableContainerInterface
   +   */
   +  private $container;
   +
   +  /**
   +   * @param \Symfony\Component\DependencyInjection\IntrospectableContainerInterface $container
   +   */
   +  public function __construct(IntrospectableContainerInterface $container) {
   

   Incomplete docs.

5. +++ b/core/lib/Drupal/Core/Profiler/ServiceDataCollector.php
   @@ -0,0 +1,78 @@
   +  /**
   +   * @return int
   +   */
   +  public function getInitializedServicesWithoutProfilerServices() {
   

   Incomplete docs.

6. +++ b/core/profiles/profiling/modules/profiler/profiler.info.yml
   @@ -0,0 +1,6 @@
   +description: 'Gathers simple profiling data (peak memory, number of initialized services, and so on).'
   

   Outdated.

7. +++ b/core/profiles/profiling/modules/profiler/src/Compiler/ProfilerPass.php
   @@ -0,0 +1,38 @@
   +<?php
   +
   +namespace Drupal\profiler\Compiler;
   

   Missing docs.

8. +++ b/core/profiles/profiling/modules/profiler/src/Compiler/ProfilerPass.php
   @@ -0,0 +1,38 @@
   +/**
   + * Class ProfilerPass
   + */
   +class ProfilerPass implements CompilerPassInterface {
   

   Actual docs needed.

9. +++ b/core/profiles/profiling/modules/profiler/src/Compiler/ProfilerPass.php
   @@ -0,0 +1,38 @@
   +  /**
   +   * @param \Symfony\Component\DependencyInjection\ContainerBuilder $container
   +   *
   +   * @throws \InvalidArgumentException
   +   */
   +  public function process(ContainerBuilder $container) {
   

   Incomplete docblock.

10. +++ b/core/profiles/profiling/profiling.info.yml
    @@ -0,0 +1,46 @@
    +description: 'Profile for profiling (measuring performance). currently Includes one scenario to track Drupal performance.'
    

    s/currenty Includes/Currently includes/

11. +++ b/core/profiles/profiling/src/Tests/ProfilingTest.php
    @@ -0,0 +1,166 @@
    +/**
    + * Holds profiling data.
    + * In a basic form, this class encapsolates an array, but does not allow
    + * setting values once they have been initialized.
    + *
    + */
    +class ExpectedProfilingData {
    +  public $service_count;
    +  function __construct($service_count) {
    +    $this->service_count = $service_count;
    +  }
    +}
    

    This needs to be moved into a separate file and needs some serious cleanup.

12. +++ b/core/profiles/profiling/src/Tests/ProfilingTest.php
    @@ -0,0 +1,166 @@
    +    // @todo Add more scenarios, e.g. the ones in the first patch.
    

    Let's do this now.

13. +++ b/core/profiles/profiling/src/Tests/ProfilingTest.php
    @@ -0,0 +1,166 @@
    +  /***
    +   * Formats a specified number.
    +   * Valid values are G|M|K.
    +   */
    +  protected function formatValue($value, $format = 'G') {
    

    Incomplete docblock.

14. +++ b/core/profiles/profiling/src/Tests/ProfilingTest.php
    @@ -0,0 +1,166 @@
    +  /**
    +   * Like ::assertEqual(), but informs us about a regression or improvement.
    +      * variation_percentage: the amount given data can
    +   * change above or below.
    +   * Format is one of G|M|K|P.
    +   * (gigabyte, megabyte, kilobyte or plane).
    +   * For all values excluding plane, the result will be formatted.
    +   *
    +   */
    

    Incomplete docblock and indentation problems.

    Also: s/plane/plain/?

15. +++ b/core/profiles/profiling/src/Tests/ProfilingTest.php
    @@ -0,0 +1,166 @@
    +    $args = array(
    

    Let's use PHP 5.5 short notation array syntax.