Skip to content

Improve NPM api tests execution time

David Fernandez requested to merge 10io-speedup-npm-api-tests into master

What does this MR do?

(From the rails performance training assignment)

Speed up npm_packages_spec.rb test execution by:

  • using let_it_be in favor of let or let!
  • using a single let_it_be(:project) for all examples by:
  • avoid calling factories when it was not necessary. For example, calling create(:personal_access_token) for several examples where a single let_it_be(:personal_access_token) gets the job done.

Before this MR

test-prof profiling factories:

$ FPROF=1 bundle exec rspec ee/spec/requests/api/npm_packages_spec.rb
[TEST PROF INFO] FactoryProf enabled (simple mode)
Run options: include {:focus=>true}

All examples were filtered out; ignoring {:focus=>true}

==> Setting up Gitaly...
Checking gitaly-ruby Gemfile...
Checking gitaly-ruby bundle...
The Gemfile's dependencies are satisfied
Trying to connect to gitaly: ....... OK
    Gitaly set up in 1.272505 seconds...

==> Setting up GitLab Elasticsearch Indexer...
    GitLab Elasticsearch Indexer set up in 0.000114 seconds...
...........................................................................................................................................................................

Finished in 1 minute 11.25 seconds (files took 27 seconds to load)
171 examples, 0 failures

[TEST PROF INFO] Factories usage

 Total: 1415
 Total top-level: 956
 Total time: 30.7159s
 Total uniq factories: 16

   total   top-level   total time   top-level time                           name

     280         171      7.4507s          4.6147s                           user
     177         171     18.1886s         17.4543s                        project
     176           0      1.7605s          0.0000s                   package_file
     176         176      3.2619s          3.2619s                    npm_package
     122         122      0.6824s          0.6824s          personal_access_token
     121         121      0.4241s          0.4241s                   packages_tag
     109         109      1.8927s          1.8927s                          group
      68           0      1.9471s          0.0000s                      namespace
      64          64      0.6446s          0.6446s       packages_dependency_link
      64           0      0.2726s          0.0000s            packages_dependency
      15          15      0.7031s          0.7031s             oauth_access_token
      15           0      0.5358s          0.0000s                    application
      15           0      0.4514s          0.0000s                          owner
       6           0      0.8359s          0.0000s                    ci_pipeline
       6           6      1.0272s          1.0272s                       ci_build
       1           1      0.0109s          0.0109s                        license

This report gives us the potential factory candidates where we should use let_it_be.

Special mention for personal_access_token which is called 122 times and it is not present in the spec file. After some digging, this factory is actually called by api_helpers.rb. So for method #api, it's better to provide a personal_access_token than a user. By providing a user, this function will call create(:personal_access_token, user: user) which is what is happening here.

test-prof profiling the event 'factory.create':

$ EVENT_PROF_EXAMPLES=1 EVENT_PROF='factory.create' bundle exec rspec ee/spec/requests/api/npm_packages_spec.rb
Run options: include {:focus=>true}

All examples were filtered out; ignoring {:focus=>true}
[TEST PROF INFO] EventProf enabled (factory.create)

==> Setting up Gitaly...
Checking gitaly-ruby Gemfile...
Checking gitaly-ruby bundle...
The Gemfile's dependencies are satisfied
Trying to connect to gitaly: ....... OK
    Gitaly set up in 1.322114 seconds...

==> Setting up GitLab Elasticsearch Indexer...
    GitLab Elasticsearch Indexer set up in 0.000138 seconds...
...........................................................................................................................................................................[TEST PROF INFO] EventProf results for factory.create

Total time: 00:32.128 of 01:10.233 (45.75%)
Total events: 956

Top 5 slowest suites (by time):

API::NpmPackages (./ee/spec/requests/api/npm_packages_spec.rb:5) – 00:32.128 (956 / 171) of 01:10.233 (45.75%)

Top 5 slowest tests (by time):

returns the p...with job token (./ee/spec/requests/api/npm_packages_spec.rb:24) – 00:00.553 (9) of 00:00.785 (70.38%)
rejects reque...in the license (./ee/spec/requests/api/npm_packages_spec.rb:140) – 00:00.513 (8) of 00:03.100 (16.57%)
returns the package info (./ee/spec/requests/api/npm_packages_spec.rb:45) – 00:00.485 (8) of 00:00.665 (72.87%)
creates the package metadata (./ee/spec/requests/api/npm_packages_spec.rb:325) – 00:00.380 (5) of 00:00.600 (63.39%)
returns the package info (./ee/spec/requests/api/npm_packages_spec.rb:45) – 00:00.335 (8) of 00:00.616 (54.42%)

We see that we are spending 30+ seconds in factories (956 create events), which accounts for 45% of the test execution time. 😱

With this MR

test-prof profiling factories:

$ FPROF=1 bundle exec rspec ee/spec/requests/api/npm_packages_spec.rb
[TEST PROF INFO] FactoryProf enabled (simple mode)
Run options: include {:focus=>true}

All examples were filtered out; ignoring {:focus=>true}

==> Setting up Gitaly...
Checking gitaly-ruby Gemfile...
Checking gitaly-ruby bundle...
The Gemfile's dependencies are satisfied
Trying to connect to gitaly: ....... OK
    Gitaly set up in 1.232617 seconds...

==> Setting up GitLab Elasticsearch Indexer...
    GitLab Elasticsearch Indexer set up in 0.000162 seconds...
...........................................................................................................................................................................

Finished in 46.97 seconds (files took 30.31 seconds to load)
171 examples, 0 failures

[TEST PROF INFO] Factories usage

 Total: 58
 Total top-level: 33
 Total time: 1.5248s
 Total uniq factories: 16

   total   top-level   total time   top-level time                           name

      12           0      0.1397s          0.0000s                   package_file
      12          12      0.2565s          0.2565s                    npm_package
       9           9      0.0256s          0.0256s                   packages_tag
       4           0      0.0372s          0.0000s            packages_dependency
       4           4      0.0755s          0.0755s       packages_dependency_link
       3           1      0.6888s          0.1902s                        project
       2           2      0.7774s          0.7774s                       ci_build
       2           1      0.1084s          0.0804s                           user
       2           0      0.5746s          0.0000s                    ci_pipeline
       2           0      0.1516s          0.0000s                      namespace
       1           1      0.0178s          0.0178s                          group
       1           1      0.0185s          0.0185s          personal_access_token
       1           0      0.0308s          0.0000s                          owner
       1           0      0.0464s          0.0000s                    application
       1           1      0.0128s          0.0128s                        license
       1           1      0.0701s          0.0701s             oauth_access_token

This is looking much better. For several factories, we managed to have a unique call (see personal_access_token for example).

test-prof profiling the event 'factory.create':

$ EVENT_PROF_EXAMPLES=1 EVENT_PROF='factory.create' bundle exec rspec ee/spec/requests/api/npm_packages_spec.rb
Run options: include {:focus=>true}

All examples were filtered out; ignoring {:focus=>true}
[TEST PROF INFO] EventProf enabled (factory.create)

==> Setting up Gitaly...
Checking gitaly-ruby Gemfile...
Checking gitaly-ruby bundle...
The Gemfile's dependencies are satisfied
Trying to connect to gitaly: ........ OK
    Gitaly set up in 1.345508 seconds...

==> Setting up GitLab Elasticsearch Indexer...
    GitLab Elasticsearch Indexer set up in 0.000211 seconds...
...........................................................................................................................................................................[TEST PROF INFO] EventProf results for factory.create

Total time: 00:01.410 of 00:44.781 (3.15%)
Total events: 33

Top 5 slowest suites (by time):

API::NpmPackages (./ee/spec/requests/api/npm_packages_spec.rb:5) – 00:01.410 (33 / 171) of 00:44.781 (3.15%)

Top 5 slowest tests (by time):

creates the package metadata (./ee/spec/requests/api/npm_packages_spec.rb:328) – 00:00.163 (1) of 00:00.407 (40.06%)
returns an er...already exists (./ee/spec/requests/api/npm_packages_spec.rb:341) – 00:00.107 (1) of 00:00.314 (34.31%)
returns not_found (./ee/spec/support/shared_examples/requests/response_status_shared_examples.rb:4) – 00:00.022 (2) of 00:00.268 (8.52%)
returns not_found (./ee/spec/support/shared_examples/requests/response_status_shared_examples.rb:4) – 00:00.021 (2) of 00:00.244 (8.61%)

We see that we are spending 1.4 seconds in factories (33 create events), which accounts now for 3% of the test execution time. 🍾

We can see a ~37% improvement in the total execution time. 🎉

Does this MR meet the acceptance criteria?

Conformity

Availability and Testing

Security

If this MR contains changes to processing or storing of credentials or tokens, authorization and authentication methods and other items described in the security review guidelines:

  • Label as security and @ mention @gitlab-com/gl-security/appsec
  • The MR includes necessary changes to maintain consistency between UI, API, email, or other methods
  • Security reports checked/validated by a reviewer from the AppSec team
Edited by David Fernandez

Merge request reports