From 6d1ce070a02b457a023d94e34f5064398c75f3ca Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Thu, 7 Mar 2024 17:00:53 +0100 Subject: [PATCH 01/17] Print sorted list of executed examples after tests Useful e.g. for comparing what got executed with different runs. Needs --first-is-1 for parallel rspec, which also fixes the first group prefix to be [TEST GROUP 1] instead of [TEST GROUP ] --- .github/workflows/ci.yml | 4 +++- .rspec_parallel | 1 + 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 92257578eb..3e68edde02 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -56,6 +56,8 @@ jobs: - name: Calculate number of parallel_rspec processes (half of num of lines in runtime log) run: echo "PARALLEL_TEST_PROCESSORS=$(( ($(cat test/var/log/parallel_runtime_rspec.${STACK}.log | wc -l)+2-1)/2 ))" >> "$GITHUB_ENV" - name: Execute tests - run: bundle exec parallel_rspec --group-by runtime --unknown-runtime 1 --allowed-missing 100 --runtime-log "test/var/log/parallel_runtime_rspec.${STACK}.log" --verbose-command --combine-stderr --prefix-output-with-test-env-number test/spec/ + run: bundle exec parallel_rspec --group-by runtime --first-is-1 --unknown-runtime 1 --allowed-missing 100 --runtime-log "test/var/log/parallel_runtime_rspec.${STACK}.log" --verbose-command --combine-stderr --prefix-output-with-test-env-number test/spec/ + - name: Print list of executed examples + run: cat test/var/log/group.*.json | jq -r --slurp '[.[].examples[]] | sort_by(.id) | flatten[] | .full_description' - name: Print parallel_runtime_rspec.log run: cat parallel_runtime_rspec.log | grep -E '^test/spec/[a-z0-9_/\.-]+\.rb:[0-9]+\.[0-9]+$' | sort diff --git a/.rspec_parallel b/.rspec_parallel index 32dcd0b4fe..3694d423c3 100644 --- a/.rspec_parallel +++ b/.rspec_parallel @@ -1,2 +1,3 @@ --format progress +--format json --out test/var/log/group.<%= "%02d" % ENV["TEST_ENV_NUMBER"] %>.json --format ParallelTests::RSpec::RuntimeLogger --out parallel_runtime_rspec.log From 5429b24062178439cd562c6f775e30f83b261c5e Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 7 Feb 2024 17:19:23 +0100 Subject: [PATCH 02/17] Fewer 'heroku run' calls in php_base_shared Speeds up tests --- test/spec/php_base_shared.rb | 49 ++++++++++++------- .../log/parallel_runtime_rspec.heroku-20.log | 12 ++--- .../log/parallel_runtime_rspec.heroku-22.log | 6 +-- 3 files changed, 39 insertions(+), 28 deletions(-) diff --git a/test/spec/php_base_shared.rb b/test/spec/php_base_shared.rb index 55db04c473..f462953ab6 100644 --- a/test/spec/php_base_shared.rb +++ b/test/spec/php_base_shared.rb @@ -1,13 +1,31 @@ require_relative "spec_helper" +require "securerandom" shared_examples "A basic PHP application" do |series| context "with a composer.json requiring PHP #{series}" do before(:all) do @app = new_app_with_stack_and_platrepo('test/fixtures/default', - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs php '#{series}.*'") or raise "Failed to require PHP version" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs php '#{series}.*'") or raise "Failed to require PHP version" } ) @app.deploy + + delimiter = SecureRandom.uuid + run_cmds = [ + "php -v", + "php -i", + "php -i | grep memory_limit", + "ldd .heroku/php/bin/php .heroku/php/lib/php/extensions/no-debug-non-zts-*/{imap,mbstring,pdo_sqlite,sqlite3}.so | grep -E ' => (/usr)?/lib/' | grep -e 'libc-client.so' -e 'libonig.so' -e 'libsqlite3.so' -e 'libzip.so' | wc -l", + ] + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + .map { |cmd| "#{cmd} 2>&1" } + .join("; echo -n '#{delimiter}'; ") + retry_until retry: 3, sleep: 5 do + # must be careful with multiline command strings, as the CLI effectively appends '; echo $?' to the command when using 'heroku run -x' + # we put all commands into a subshell with set -e, so that one failing will abort early, but the following '; echo $?' logic still executes + @run = expect_exit(code: 0) { @app.run("( set -e; #{run_cmds.strip}; )", :return_obj => true) }.output.split(delimiter) + end end after(:all) do @@ -16,30 +34,23 @@ it "picks a version from the desired series" do expect(@app.output).to match(/- php \(#{Regexp.escape(series)}\./) - retry_until retry: 3, sleep: 5 do - expect(@app.run('php -v')).to match(/#{Regexp.escape(series)}\./) - end + expect(@run[0]).to match(/#{Regexp.escape(series)}\./) end it "has Heroku php.ini defaults" do - retry_until retry: 3, sleep: 5 do - ini_output = @app.run('php -i') - expect(ini_output).to match(/date.timezone => UTC/) - .and match(/error_reporting => 30719/) - .and match(/expose_php => Off/) - .and match(/user_ini.cache_ttl => 86400/) - .and match(/variables_order => EGPCS/) - end + expect(@run[1]) + .to match(/date.timezone => UTC/) + .and match(/error_reporting => 30719/) + .and match(/expose_php => Off/) + .and match(/user_ini.cache_ttl => 86400/) + .and match(/variables_order => EGPCS/) end it "uses all available RAM as PHP CLI memory_limit" do - retry_until retry: 3, sleep: 5 do - expect(@app.run("php -i | grep memory_limit")).to match "memory_limit => 536870912 => 536870912" - end + expect(@run[2]).to match("memory_limit => 536870912 => 536870912") end it "is running a PHP build that links against libc-client, libonig, libsqlite3 and libzip from the stack" do - ldd_output = @app.run("ldd .heroku/php/bin/php .heroku/php/lib/php/extensions/no-debug-non-zts-*/{imap,mbstring,pdo_sqlite,sqlite3}.so | grep -E ' => (/usr)?/lib/' | grep -e 'libc-client.so' -e 'libonig.so' -e 'libsqlite3.so' -e 'libzip.so' | wc -l") # 1x libc-client.so for extensions/…/imap.so # 1x libonig for extensions/…/mbstring.so # 1x libsqlite3.so for extensions/…/pdo_sqlite.so @@ -47,9 +58,9 @@ # 1x libsqlite3.so for bin/php (before heroku-22) # 1x libzip.so for bin/php if "heroku-20" == ENV['STACK'] - expect(ldd_output).to match(/^6$/) + expect(@run[3]).to match(/^6$/) else - expect(ldd_output).to match(/^5$/) + expect(@run[3]).to match(/^5$/) end end end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index c2b80e8baf..26fcd61886 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -8,40 +8,40 @@ test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:110 test/spec/nginx_spec.rb:49 -test/spec/php-7.3_base_spec.rb:55 +test/spec/php-7.3_base_spec.rb:30 test/spec/php-7.3_boot-apache2_spec.rb:110 test/spec/php-7.3_boot-nginx_spec.rb:100 test/spec/php-7.3_concurrency-apache2_spec.rb:130 test/spec/php-7.3_concurrency-nginx_spec.rb:120 -test/spec/php-7.4_base_spec.rb:55 +test/spec/php-7.4_base_spec.rb:30 test/spec/php-7.4_boot-apache2_spec.rb:110 test/spec/php-7.4_boot-nginx_spec.rb:100 test/spec/php-7.4_concurrency-apache2_spec.rb:130 test/spec/php-7.4_concurrency-nginx_spec.rb:120 test/spec/php-7.4_sigterm-apache2_spec.rb:55 test/spec/php-7.4_sigterm-nginx_spec.rb:55 -test/spec/php-8.0_base_spec.rb:55 +test/spec/php-8.0_base_spec.rb:30 test/spec/php-8.0_boot-apache2_spec.rb:110 test/spec/php-8.0_boot-nginx_spec.rb:100 test/spec/php-8.0_concurrency-apache2_spec.rb:130 test/spec/php-8.0_concurrency-nginx_spec.rb:120 test/spec/php-8.0_sigterm-apache2_spec.rb:55 test/spec/php-8.0_sigterm-nginx_spec.rb:55 -test/spec/php-8.1_base_spec.rb:55 +test/spec/php-8.1_base_spec.rb:30 test/spec/php-8.1_boot-apache2_spec.rb:110 test/spec/php-8.1_boot-nginx_spec.rb:100 test/spec/php-8.1_concurrency-apache2_spec.rb:130 test/spec/php-8.1_concurrency-nginx_spec.rb:120 test/spec/php-8.1_sigterm-apache2_spec.rb:55 test/spec/php-8.1_sigterm-nginx_spec.rb:55 -test/spec/php-8.2_base_spec.rb:55 +test/spec/php-8.2_base_spec.rb:30 test/spec/php-8.2_boot-apache2_spec.rb:110 test/spec/php-8.2_boot-nginx_spec.rb:100 test/spec/php-8.2_concurrency-apache2_spec.rb:130 test/spec/php-8.2_concurrency-nginx_spec.rb:120 test/spec/php-8.2_sigterm-apache2_spec.rb:55 test/spec/php-8.2_sigterm-nginx_spec.rb:55 -test/spec/php-8.3_base_spec.rb:55 +test/spec/php-8.3_base_spec.rb:30 test/spec/php-8.3_boot-apache2_spec.rb:110 test/spec/php-8.3_boot-nginx_spec.rb:100 test/spec/php-8.3_concurrency-apache2_spec.rb:130 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index ff854a4f1a..15b3c206ff 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -8,21 +8,21 @@ test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:110 test/spec/nginx_spec.rb:49 -test/spec/php-8.1_base_spec.rb:55 +test/spec/php-8.1_base_spec.rb:30 test/spec/php-8.1_boot-apache2_spec.rb:110 test/spec/php-8.1_boot-nginx_spec.rb:100 test/spec/php-8.1_concurrency-apache2_spec.rb:130 test/spec/php-8.1_concurrency-nginx_spec.rb:120 test/spec/php-8.1_sigterm-apache2_spec.rb:55 test/spec/php-8.1_sigterm-nginx_spec.rb:55 -test/spec/php-8.2_base_spec.rb:55 +test/spec/php-8.2_base_spec.rb:30 test/spec/php-8.2_boot-apache2_spec.rb:110 test/spec/php-8.2_boot-nginx_spec.rb:100 test/spec/php-8.2_concurrency-apache2_spec.rb:130 test/spec/php-8.2_concurrency-nginx_spec.rb:120 test/spec/php-8.2_sigterm-apache2_spec.rb:55 test/spec/php-8.2_sigterm-nginx_spec.rb:55 -test/spec/php-8.3_base_spec.rb:55 +test/spec/php-8.3_base_spec.rb:30 test/spec/php-8.3_boot-apache2_spec.rb:110 test/spec/php-8.3_boot-nginx_spec.rb:100 test/spec/php-8.3_concurrency-apache2_spec.rb:130 From fb2b1dd4b09dd5bb78f496143cc5b66361f4b66d Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 6 Mar 2024 15:49:20 +0100 Subject: [PATCH 03/17] Fewer 'heroku run' calls in php_default_spec Speeds up tests --- test/spec/php_default_spec.rb | 60 +++++++++++-------- .../log/parallel_runtime_rspec.heroku-20.log | 2 +- .../log/parallel_runtime_rspec.heroku-22.log | 2 +- 3 files changed, 38 insertions(+), 26 deletions(-) diff --git a/test/spec/php_default_spec.rb b/test/spec/php_default_spec.rb index 69901c593b..305c1e73d9 100644 --- a/test/spec/php_default_spec.rb +++ b/test/spec/php_default_spec.rb @@ -1,4 +1,5 @@ require_relative "spec_helper" +require "securerandom" describe "A PHP application" do context "like the Heroku Getting Started guide example for PHP" do @@ -10,36 +11,47 @@ end context "with just an index.php" do - let(:app) { - new_app_with_stack_and_platrepo('test/fixtures/default') - } - it "picks a default version from the expected series" do - app.deploy do |app| - series = expected_default_php(ENV["STACK"]) - expect(app.output).to match(/- php \(#{Regexp.escape(series)}\./) - retry_until retry: 3, sleep: 5 do - expect(app.run('php -v')).to match(/#{Regexp.escape(series)}\./) - end + before(:all) do + @app = new_app_with_stack_and_platrepo('test/fixtures/default') + @app.deploy + + delimiter = SecureRandom.uuid + run_cmds = [ + "php -v", + "env | grep COMPOSER_", + ] + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + .map { |cmd| "#{cmd} 2>&1" } + .join("; echo -n '#{delimiter}'; ") + retry_until retry: 3, sleep: 5 do + # must be careful with multiline command strings, as the CLI effectively appends '; echo $?' to the command when using 'heroku run -x' + # we put all commands into a subshell with set -e, so that one failing will abort early, but the following '; echo $?' logic still executes + @run = expect_exit(code: 0) { @app.run("( set -e; #{run_cmds.strip}; )", :return_obj => true) }.output.split(delimiter) end end - # FIXME re-use deploy + + after(:all) do + @app.teardown! + end + + it "picks a default version from the expected series" do + series = expected_default_php(ENV["STACK"]) + expect(@app.output).to match(/- php \(#{Regexp.escape(series)}\./) + expect(@run[0]).to match(/#{Regexp.escape(series)}\./) + end + it "serves traffic" do - app.deploy do |app| - expect(successful_body(app)) - end + expect(successful_body(@app)) end it "has Composer defaults set" do - app.deploy do |app| - retry_until retry: 3, sleep: 5 do - composer_envs = app.run('env | grep COMPOSER_') - expect(composer_envs) - .to match(/^COMPOSER_MEMORY_LIMIT=536870912$/) - .and match(/^COMPOSER_MIRROR_PATH_REPOS=1$/) - .and match(/^COMPOSER_NO_INTERACTION=1$/) - .and match(/^COMPOSER_PROCESS_TIMEOUT=0$/) - end - end + expect(@run[1]) + .to match(/^COMPOSER_MEMORY_LIMIT=536870912$/) + .and match(/^COMPOSER_MIRROR_PATH_REPOS=1$/) + .and match(/^COMPOSER_NO_INTERACTION=1$/) + .and match(/^COMPOSER_PROCESS_TIMEOUT=0$/) end end end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 26fcd61886..bb3385a8ce 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -48,5 +48,5 @@ test/spec/php-8.3_concurrency-apache2_spec.rb:130 test/spec/php-8.3_concurrency-nginx_spec.rb:120 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 -test/spec/php_default_spec.rb:80 +test/spec/php_default_spec.rb:55 test/spec/platform_spec.rb:105 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 15b3c206ff..7a27223d8c 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -29,5 +29,5 @@ test/spec/php-8.3_concurrency-apache2_spec.rb:130 test/spec/php-8.3_concurrency-nginx_spec.rb:120 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 -test/spec/php_default_spec.rb:80 +test/spec/php_default_spec.rb:55 test/spec/platform_spec.rb:65 From c2aa0416d9460eef4d57eaab5447edb7c077cd3c Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 6 Mar 2024 15:50:52 +0100 Subject: [PATCH 04/17] Fewer 'heroku run' calls in php_boot_shared Speeds up tests --- test/spec/php_boot_shared.rb | 64 +++++++++++-------- .../log/parallel_runtime_rspec.heroku-20.log | 24 +++---- .../log/parallel_runtime_rspec.heroku-22.log | 12 ++-- 3 files changed, 54 insertions(+), 46 deletions(-) diff --git a/test/spec/php_boot_shared.rb b/test/spec/php_boot_shared.rb index a3ddeec95b..29739cb560 100644 --- a/test/spec/php_boot_shared.rb +++ b/test/spec/php_boot_shared.rb @@ -1,4 +1,5 @@ require_relative "spec_helper" +require "securerandom" shared_examples "A PHP application for testing boot options" do |series, server| # the matrix of options and arguments to test @@ -101,39 +102,46 @@ def self.gencmd(args) combinations = interesting.map {|v| genmatrix(matrix, v)}.flatten(1).uniq # # a few more "manual" cases combinations << {0 => "heroku-php-#{server}", "--verbose" => true, "-C" => "conf/#{server}.server.include.conf", "-F" => "conf/fpm.include.conf"} - combinations.each do | combination | + + commands = Array.new + combinations.each do |combination| cmd = gencmd(combination) - context "launching using `#{cmd}'" do - if combination.value?(false) or cmd.match("broken") - it "does not boot" do - retry_until retry: 3, sleep: 5 do - # check if "timeout" exited with a status other than 124, which means the process exited (due to the expected error) before "timeout" stepped in after the given duration (five seconds) and terminated it - expect_exit(expect: :not_to, code: 124) { @app.run("timeout 15 #{cmd}", :return_obj => true) } - end - end - else - it "boots" do - retry_until retry: 3, sleep: 5 do - # check if "waitforit" exited with status 0, which means the process successfully output the expected message - expect_exit(expect: :to, code: 0) { @app.run("./waitforit.sh 15 'ready for connections' #{cmd}", :return_obj => true) } - end - end - end + if combination.value?(false) or cmd.match("broken") + commands << {group: "does not boot", title: "using command #{cmd}", cmd: "timeout 10 #{cmd}", expect: :not_to, operator: :eq, code: 124} + else + commands << {group: "boots", title: "using command #{cmd}", cmd: "./waitforit.sh 10 'ready for connections' #{cmd}", expect: :to, operator: :eq, code: 0} end end - context "launching using too many arguments" do - it "fails to boot" do - retry_until retry: 3, sleep: 5 do - expect_exit(expect: :to, code: 2) { @app.run("timeout 10 heroku-php-#{server} docroot/ anotherarg", :return_obj => true) } - end - end - end + # some more simple arg cases + commands << {group: "does not boot", title: "using too many arguments", cmd: "timeout 10 heroku-php-#{server} docroot/ anotherarg", expect: :to, operator: :eq, code: 2} + commands << {group: "does not boot", title: "using unknown options", cmd: "timeout 10 heroku-php-#{server} --what -u erp", expect: :to, operator: :eq, code: 2} - context "launching using unknown options" do - it "fails to boot" do - retry_until retry: 3, sleep: 5 do - expect_exit(expect: :to, code: 2) { @app.run("timeout 10 heroku-php-#{server} --what -u erp", :return_obj => true) } + commands.group_by { |command| command[:group] }.each do |group, examples| + + context group do + before(:all) do + delimiter = SecureRandom.uuid + # run the command, then print a newline and the exit status (which we also test against) + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + run_cmds = examples + .map { |example| "#{example[:cmd]} 2>&1; echo $'\\n'$?" } + .join("; echo -n '#{delimiter}'; ") + retry_until retry: 3, sleep: 5 do + @run = @app.run(run_cmds).split(delimiter) + end + end + + examples.each_with_index do |example, index| + it example[:title] do + output, _, code = @run[index].rstrip.rpartition("\n") + expect(code).method(example[:expect]).call( + method(example[:operator]).call(example[:code].to_s), + "Expected exit code #{code} #{example[:expect]} be #{example[:operator]} to #{example[:code]}; output:\n#{output}" + ) + end end end end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index bb3385a8ce..294c4a8eb4 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -9,41 +9,41 @@ test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:110 test/spec/nginx_spec.rb:49 test/spec/php-7.3_base_spec.rb:30 -test/spec/php-7.3_boot-apache2_spec.rb:110 -test/spec/php-7.3_boot-nginx_spec.rb:100 +test/spec/php-7.3_boot-apache2_spec.rb:65 +test/spec/php-7.3_boot-nginx_spec.rb:55 test/spec/php-7.3_concurrency-apache2_spec.rb:130 test/spec/php-7.3_concurrency-nginx_spec.rb:120 test/spec/php-7.4_base_spec.rb:30 -test/spec/php-7.4_boot-apache2_spec.rb:110 -test/spec/php-7.4_boot-nginx_spec.rb:100 +test/spec/php-7.4_boot-apache2_spec.rb:65 +test/spec/php-7.4_boot-nginx_spec.rb:55 test/spec/php-7.4_concurrency-apache2_spec.rb:130 test/spec/php-7.4_concurrency-nginx_spec.rb:120 test/spec/php-7.4_sigterm-apache2_spec.rb:55 test/spec/php-7.4_sigterm-nginx_spec.rb:55 test/spec/php-8.0_base_spec.rb:30 -test/spec/php-8.0_boot-apache2_spec.rb:110 -test/spec/php-8.0_boot-nginx_spec.rb:100 +test/spec/php-8.0_boot-apache2_spec.rb:65 +test/spec/php-8.0_boot-nginx_spec.rb:55 test/spec/php-8.0_concurrency-apache2_spec.rb:130 test/spec/php-8.0_concurrency-nginx_spec.rb:120 test/spec/php-8.0_sigterm-apache2_spec.rb:55 test/spec/php-8.0_sigterm-nginx_spec.rb:55 test/spec/php-8.1_base_spec.rb:30 -test/spec/php-8.1_boot-apache2_spec.rb:110 -test/spec/php-8.1_boot-nginx_spec.rb:100 +test/spec/php-8.1_boot-apache2_spec.rb:65 +test/spec/php-8.1_boot-nginx_spec.rb:55 test/spec/php-8.1_concurrency-apache2_spec.rb:130 test/spec/php-8.1_concurrency-nginx_spec.rb:120 test/spec/php-8.1_sigterm-apache2_spec.rb:55 test/spec/php-8.1_sigterm-nginx_spec.rb:55 test/spec/php-8.2_base_spec.rb:30 -test/spec/php-8.2_boot-apache2_spec.rb:110 -test/spec/php-8.2_boot-nginx_spec.rb:100 +test/spec/php-8.2_boot-apache2_spec.rb:65 +test/spec/php-8.2_boot-nginx_spec.rb:55 test/spec/php-8.2_concurrency-apache2_spec.rb:130 test/spec/php-8.2_concurrency-nginx_spec.rb:120 test/spec/php-8.2_sigterm-apache2_spec.rb:55 test/spec/php-8.2_sigterm-nginx_spec.rb:55 test/spec/php-8.3_base_spec.rb:30 -test/spec/php-8.3_boot-apache2_spec.rb:110 -test/spec/php-8.3_boot-nginx_spec.rb:100 +test/spec/php-8.3_boot-apache2_spec.rb:65 +test/spec/php-8.3_boot-nginx_spec.rb:55 test/spec/php-8.3_concurrency-apache2_spec.rb:130 test/spec/php-8.3_concurrency-nginx_spec.rb:120 test/spec/php-8.3_sigterm-apache2_spec.rb:55 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 7a27223d8c..84e03e2ba2 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -9,22 +9,22 @@ test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:110 test/spec/nginx_spec.rb:49 test/spec/php-8.1_base_spec.rb:30 -test/spec/php-8.1_boot-apache2_spec.rb:110 -test/spec/php-8.1_boot-nginx_spec.rb:100 +test/spec/php-8.1_boot-apache2_spec.rb:65 +test/spec/php-8.1_boot-nginx_spec.rb:55 test/spec/php-8.1_concurrency-apache2_spec.rb:130 test/spec/php-8.1_concurrency-nginx_spec.rb:120 test/spec/php-8.1_sigterm-apache2_spec.rb:55 test/spec/php-8.1_sigterm-nginx_spec.rb:55 test/spec/php-8.2_base_spec.rb:30 -test/spec/php-8.2_boot-apache2_spec.rb:110 -test/spec/php-8.2_boot-nginx_spec.rb:100 +test/spec/php-8.2_boot-apache2_spec.rb:65 +test/spec/php-8.2_boot-nginx_spec.rb:55 test/spec/php-8.2_concurrency-apache2_spec.rb:130 test/spec/php-8.2_concurrency-nginx_spec.rb:120 test/spec/php-8.2_sigterm-apache2_spec.rb:55 test/spec/php-8.2_sigterm-nginx_spec.rb:55 test/spec/php-8.3_base_spec.rb:30 -test/spec/php-8.3_boot-apache2_spec.rb:110 -test/spec/php-8.3_boot-nginx_spec.rb:100 +test/spec/php-8.3_boot-apache2_spec.rb:65 +test/spec/php-8.3_boot-nginx_spec.rb:55 test/spec/php-8.3_concurrency-apache2_spec.rb:130 test/spec/php-8.3_concurrency-nginx_spec.rb:120 test/spec/php-8.3_sigterm-apache2_spec.rb:55 From 6f4cac46dd073df73d33d50cb5e2d393dcf01a60 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 6 Mar 2024 15:51:09 +0100 Subject: [PATCH 05/17] Fewer 'heroku run' calls in php_concurrency_shared Speeds up tests --- test/spec/php_concurrency_shared.rb | 182 ++++++++++-------- .../log/parallel_runtime_rspec.heroku-20.log | 24 +-- .../log/parallel_runtime_rspec.heroku-22.log | 12 +- 3 files changed, 121 insertions(+), 97 deletions(-) diff --git a/test/spec/php_concurrency_shared.rb b/test/spec/php_concurrency_shared.rb index 087757a97e..f6aba1660d 100644 --- a/test/spec/php_concurrency_shared.rb +++ b/test/spec/php_concurrency_shared.rb @@ -1,4 +1,5 @@ require_relative "spec_helper" +require "securerandom" shared_examples "A PHP application for testing WEB_CONCURRENCY behavior" do |series, server| @@ -15,93 +16,99 @@ @app.teardown! end - context "setting concurrency via .user.ini memory_limit" do - it "calculates concurrency correctly" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt docroot/", :return_obj => true) }.output) + context "setting concurrency via" do + before(:all) do + delimiter = SecureRandom.uuid + run_cmds = [ + "heroku-php-#{server} -tt docroot/", + "heroku-php-#{server} -tt docroot/onegig/", + "heroku-php-#{server} -tt -F conf/fpm.include.conf docroot/", + "heroku-php-#{server} -tt", + "heroku-php-#{server} -tt -F conf/fpm.include.conf", + "heroku-php-#{server} -tt -F conf/fpm.onegig.conf", + "heroku-php-#{server} -tt -F conf/fpm.admin.conf docroot/onegig/", + "heroku-php-#{server} -tt -F conf/fpm.unlimited.conf", + "WEB_CONCURRENCY=22 heroku-php-#{server} -tt", + "WEB_CONCURRENCY=22 heroku-php-#{server} -tt docroot/onegig/", + "WEB_CONCURRENCY=22 heroku-php-#{server} -tt -F conf/fpm.onegig.conf", + "WEB_CONCURRENCY=zomg heroku-php-#{server} -tt", + ] + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + .map { |cmd| "#{cmd} 2>&1" } + .join("; echo -n '#{delimiter}'; ") + retry_until retry: 3, sleep: 5 do + # must be careful with multiline command strings, as the CLI effectively appends '; echo $?' to the command when using 'heroku run -x' + # we put all commands into a subshell with set -e, so that one failing will abort early, but the following '; echo $?' logic still executes + @run = expect_exit(code: 0) { @app.run("( set -e; #{run_cmds}; )", :return_obj => true) }.output.split(delimiter) + end + end + + context ".user.ini memory_limit" do + it "calculates concurrency correctly" do + expect(@run[0]) .to match("PHP memory_limit is 32M Bytes") .and match("pm.max_children = 16") end - end - it "always launches at least one worker" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt docroot/onegig/", :return_obj => true) }.output) + it "always launches at least one worker" do + expect(@run[1]) .to match("PHP memory_limit is 1024M Bytes") .and match("pm.max_children = 1") end - end - it "takes precedence over a PHP-FPM memory_limit" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.include.conf docroot/", :return_obj => true) }.output) + it "takes precedence over a PHP-FPM memory_limit" do + expect(@run[2]) .to match("PHP memory_limit is 32M Bytes") .and match("pm.max_children = 16") end - end - it "is only done for a .user.ini directly in the document root" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt", :return_obj => true) }.output) + it "is only done for a .user.ini directly in the document root" do + expect(@run[3]) .to match("PHP memory_limit is 128M Bytes") .and match("pm.max_children = 4") end end - end - - context "setting concurrency via FPM config memory_limit" do - it "calculates concurrency correctly" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.include.conf", :return_obj => true) }.output) + + context "FPM config memory_limit" do + it "calculates concurrency correctly" do + expect(@run[4]) .to match("PHP memory_limit is 16M Bytes") .and match("pm.max_children = 32") end - end - it "always launches at least one worker" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.onegig.conf", :return_obj => true) }.output) + it "always launches at least one worker" do + expect(@run[5]) .to match("PHP memory_limit is 1024M Bytes") .and match("pm.max_children = 1") end - end - it "takes precedence over a .user.ini memory_limit if it's a php_admin_value" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.admin.conf docroot/onegig/", :return_obj => true) }.output) + it "takes precedence over a .user.ini memory_limit if it's a php_admin_value" do + expect(@run[6]) .to match("PHP memory_limit is 24M Bytes") .and match("pm.max_children = 21") end - end - it "handles a negative (unlimited) memory_limit" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.unlimited.conf", :return_obj => true) }.output) + it "handles a negative (unlimited) memory_limit" do + expect(@run[7]) .to match("PHP memory_limit is unlimited") .and match("pm.max_children = 1") end end - end - - context "setting WEB_CONCURRENCY explicitly" do - it "uses the explicit value" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt", :return_obj => true, :heroku => {:env => "WEB_CONCURRENCY=22"}) }.output) + + context "an explicit WEB_CONCURRENCY var" do + it "uses the explicit value" do + expect(@run[8]) .to match("\\$WEB_CONCURRENCY env var is set, skipping automatic calculation") .and match("pm.max_children = 22") end - end - it "overrides a .user.ini memory_limit" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt docroot/onegig/", :return_obj => true, :heroku => {:env => "WEB_CONCURRENCY=22"}) }.output) + it "overrides a .user.ini memory_limit" do + expect(@run[9]) .to match("\\$WEB_CONCURRENCY env var is set, skipping automatic calculation") .and match("pm.max_children = 22") end - end - it "overrides an FPM config memory_limit" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.onegig.conf", :return_obj => true, :heroku => {:env => "WEB_CONCURRENCY=22"}) }.output) + it "overrides an FPM config memory_limit" do + expect(@run[10]) .to match("\\$WEB_CONCURRENCY env var is set, skipping automatic calculation") .and match("pm.max_children = 22") end - end - it "ignores an illegal value" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("heroku-php-#{server} -tt -F conf/fpm.onegig.conf", :return_obj => true, :heroku => {:env => "WEB_CONCURRENCY=zomg"}) }.output) + it "ignores an illegal value" do + expect(@run[11]) .to match("\\$WEB_CONCURRENCY env var is set, skipping automatic calculation") .and include("Setting WEB_CONCURRENCY=1 (was outside allowed range)") .and match("pm.max_children = 1") @@ -130,38 +137,55 @@ # for these, we fake the CPU core count by "overriding" getconf context "running on a machine with unusual core-to-RAM ratios" do - it "calculates a worker count that does not vastly exceed CPU core capacity" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("getconf() { echo '_NPROCESSORS_ONLN 1'; }; export -f getconf; heroku-php-#{server} -v -tt", :return_obj => true, :heroku => {:size => "Performance-M"}) }.output) - .to match("Available RAM is 2560M Bytes") - .and match("Number of CPU cores is 1") - .and match("Calculated number of workers based on RAM and CPU cores is 10") - .and match("Maximum number of workers that fit available RAM at memory_limit is 20") - .and match("Limiting number of workers to 10") - .and match("pm.max_children = 10") + before(:all) do + delimiter = SecureRandom.uuid + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + run_cmds = [<<~CMD1, <<~CMD2, <<~CMD3].map { |cmd| cmd.strip }.map { |cmd| "#{cmd} 2>&1" }.join("; echo -n '#{delimiter}'; ") + getconf() { echo '_NPROCESSORS_ONLN 1'; } + export -f getconf + heroku-php-#{server} -v -tt 2>&1 + CMD1 + getconf() { echo '_NPROCESSORS_ONLN 16'; } + heroku-php-#{server} -v -tt 2>&1 + CMD2 + getconf() { echo '_NPROCESSORS_ONLN 1'; } + heroku-php-#{server} -v -tt -F conf/fpm.admin.conf 2>&1 + CMD3 + retry_until retry: 3, sleep: 5 do + # must be careful with multiline command strings, as the CLI effectively appends '; echo $?' to the command when using 'heroku run -x' + # we put all commands into a subshell with set -e, so that one failing will abort early, but the following '; echo $?' logic still executes + @run = expect_exit(code: 0) { @app.run("( set -e; #{run_cmds.strip}; )", :return_obj => true, :heroku => {:size => "Performance-M"}) }.output.split(delimiter) end end + + it "calculates a worker count that does not vastly exceed CPU core capacity" do + expect(@run[0]) + .to match(/Available RAM is 2560M Bytes$/) + .and match(/Number of CPU cores is 1$/) + .and match(/Calculated number of workers based on RAM and CPU cores is 10$/) + .and match(/Maximum number of workers that fit available RAM at memory_limit is 20$/) + .and match(/Limiting number of workers to 10$/) + .and match(/pm.max_children = 10$/) + end it "calculates a worker count whose cumulative memory_limit will not exceed available RAM" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("getconf() { echo '_NPROCESSORS_ONLN 16'; }; export -f getconf; heroku-php-#{server} -v -tt", :return_obj => true, :heroku => {:size => "Standard-1X"}) }.output) - .to match("Available RAM is 512M Bytes") - .and match("Number of CPU cores is 16") - .and match("Calculated number of workers based on RAM and CPU cores is 64") - .and match("Maximum number of workers that fit available RAM at memory_limit is 4") - .and match("Limiting number of workers to 4") - .and match("pm.max_children = 4") - end + expect(@run[1]) + .to match(/Available RAM is 2560M Bytes$/) + .and match(/Number of CPU cores is 16$/) + .and match(/Calculated number of workers based on RAM and CPU cores is 160$/) + .and match(/Maximum number of workers that fit available RAM at memory_limit is 20$/) + .and match(/Limiting number of workers to 20$/) + .and match(/pm.max_children = 20$/) end it "calculates a correct worker count for memory_limits that divide available RAM with a remainder" do - retry_until retry: 3, sleep: 5 do - expect(expect_exit(code: 0) { @app.run("getconf() { echo '_NPROCESSORS_ONLN 1'; }; export -f getconf; heroku-php-#{server} -v -tt -F conf/fpm.admin.conf", :return_obj => true, :heroku => {:size => "Performance-M"}) }.output) - .to match("Available RAM is 2560M Bytes") - .and match("Number of CPU cores is 1") - .and match(/Calculated number of workers based on RAM and CPU cores is 53$/) - .and match(/Maximum number of workers that fit available RAM at memory_limit is 106$/) - .and match(/Limiting number of workers to 53$/) - .and match(/pm.max_children = 53$/) - end + expect(@run[2]) + .to match(/Available RAM is 2560M Bytes$/) + .and match(/Number of CPU cores is 1$/) + .and match(/Calculated number of workers based on RAM and CPU cores is 53$/) + .and match(/Maximum number of workers that fit available RAM at memory_limit is 106$/) + .and match(/Limiting number of workers to 53$/) + .and match(/pm.max_children = 53$/) end end end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 294c4a8eb4..6f692a8a6f 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -11,41 +11,41 @@ test/spec/nginx_spec.rb:49 test/spec/php-7.3_base_spec.rb:30 test/spec/php-7.3_boot-apache2_spec.rb:65 test/spec/php-7.3_boot-nginx_spec.rb:55 -test/spec/php-7.3_concurrency-apache2_spec.rb:130 -test/spec/php-7.3_concurrency-nginx_spec.rb:120 +test/spec/php-7.3_concurrency-apache2_spec.rb:70 +test/spec/php-7.3_concurrency-nginx_spec.rb:65 test/spec/php-7.4_base_spec.rb:30 test/spec/php-7.4_boot-apache2_spec.rb:65 test/spec/php-7.4_boot-nginx_spec.rb:55 -test/spec/php-7.4_concurrency-apache2_spec.rb:130 -test/spec/php-7.4_concurrency-nginx_spec.rb:120 +test/spec/php-7.4_concurrency-apache2_spec.rb:70 +test/spec/php-7.4_concurrency-nginx_spec.rb:65 test/spec/php-7.4_sigterm-apache2_spec.rb:55 test/spec/php-7.4_sigterm-nginx_spec.rb:55 test/spec/php-8.0_base_spec.rb:30 test/spec/php-8.0_boot-apache2_spec.rb:65 test/spec/php-8.0_boot-nginx_spec.rb:55 -test/spec/php-8.0_concurrency-apache2_spec.rb:130 -test/spec/php-8.0_concurrency-nginx_spec.rb:120 +test/spec/php-8.0_concurrency-apache2_spec.rb:70 +test/spec/php-8.0_concurrency-nginx_spec.rb:65 test/spec/php-8.0_sigterm-apache2_spec.rb:55 test/spec/php-8.0_sigterm-nginx_spec.rb:55 test/spec/php-8.1_base_spec.rb:30 test/spec/php-8.1_boot-apache2_spec.rb:65 test/spec/php-8.1_boot-nginx_spec.rb:55 -test/spec/php-8.1_concurrency-apache2_spec.rb:130 -test/spec/php-8.1_concurrency-nginx_spec.rb:120 +test/spec/php-8.1_concurrency-apache2_spec.rb:70 +test/spec/php-8.1_concurrency-nginx_spec.rb:65 test/spec/php-8.1_sigterm-apache2_spec.rb:55 test/spec/php-8.1_sigterm-nginx_spec.rb:55 test/spec/php-8.2_base_spec.rb:30 test/spec/php-8.2_boot-apache2_spec.rb:65 test/spec/php-8.2_boot-nginx_spec.rb:55 -test/spec/php-8.2_concurrency-apache2_spec.rb:130 -test/spec/php-8.2_concurrency-nginx_spec.rb:120 +test/spec/php-8.2_concurrency-apache2_spec.rb:70 +test/spec/php-8.2_concurrency-nginx_spec.rb:65 test/spec/php-8.2_sigterm-apache2_spec.rb:55 test/spec/php-8.2_sigterm-nginx_spec.rb:55 test/spec/php-8.3_base_spec.rb:30 test/spec/php-8.3_boot-apache2_spec.rb:65 test/spec/php-8.3_boot-nginx_spec.rb:55 -test/spec/php-8.3_concurrency-apache2_spec.rb:130 -test/spec/php-8.3_concurrency-nginx_spec.rb:120 +test/spec/php-8.3_concurrency-apache2_spec.rb:70 +test/spec/php-8.3_concurrency-nginx_spec.rb:65 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 test/spec/php_default_spec.rb:55 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 84e03e2ba2..7089ea9c0b 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -11,22 +11,22 @@ test/spec/nginx_spec.rb:49 test/spec/php-8.1_base_spec.rb:30 test/spec/php-8.1_boot-apache2_spec.rb:65 test/spec/php-8.1_boot-nginx_spec.rb:55 -test/spec/php-8.1_concurrency-apache2_spec.rb:130 -test/spec/php-8.1_concurrency-nginx_spec.rb:120 +test/spec/php-8.1_concurrency-apache2_spec.rb:70 +test/spec/php-8.1_concurrency-nginx_spec.rb:65 test/spec/php-8.1_sigterm-apache2_spec.rb:55 test/spec/php-8.1_sigterm-nginx_spec.rb:55 test/spec/php-8.2_base_spec.rb:30 test/spec/php-8.2_boot-apache2_spec.rb:65 test/spec/php-8.2_boot-nginx_spec.rb:55 -test/spec/php-8.2_concurrency-apache2_spec.rb:130 -test/spec/php-8.2_concurrency-nginx_spec.rb:120 +test/spec/php-8.2_concurrency-apache2_spec.rb:70 +test/spec/php-8.2_concurrency-nginx_spec.rb:65 test/spec/php-8.2_sigterm-apache2_spec.rb:55 test/spec/php-8.2_sigterm-nginx_spec.rb:55 test/spec/php-8.3_base_spec.rb:30 test/spec/php-8.3_boot-apache2_spec.rb:65 test/spec/php-8.3_boot-nginx_spec.rb:55 -test/spec/php-8.3_concurrency-apache2_spec.rb:130 -test/spec/php-8.3_concurrency-nginx_spec.rb:120 +test/spec/php-8.3_concurrency-apache2_spec.rb:70 +test/spec/php-8.3_concurrency-nginx_spec.rb:65 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 test/spec/php_default_spec.rb:55 From 28bffbab37befba9736e4d0eff35b6a0bad9dd49 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 14 Feb 2024 01:09:20 +0100 Subject: [PATCH 06/17] Fewer 'heroku run' calls in blackfire_shared Speeds up tests --- test/spec/blackfire_shared.rb | 74 ++++++++++++------- .../log/parallel_runtime_rspec.heroku-20.log | 4 +- .../log/parallel_runtime_rspec.heroku-22.log | 4 +- 3 files changed, 53 insertions(+), 29 deletions(-) diff --git a/test/spec/blackfire_shared.rb b/test/spec/blackfire_shared.rb index 662f475e87..18d3bdb8f7 100644 --- a/test/spec/blackfire_shared.rb +++ b/test/spec/blackfire_shared.rb @@ -1,4 +1,5 @@ require_relative "spec_helper" +require "securerandom" require 'ansi/core' shared_examples "A PHP application using ext-blackfire and" do |agent| @@ -20,32 +21,28 @@ @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', buildpacks: buildpacks, config: credentials.merge({ "BLACKFIRE_LOG_LEVEL" => "4"}), - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-blackfire:*'") or raise "Failed to require PHP/ext-blackfire" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-blackfire:*'") or raise "Failed to require PHP/ext-blackfire" } ) elsif mode == "without BLACKFIRE_SERVER_TOKEN" # ext-blackfire is listed as a dependency in composer.json, but a BLACKFIRE_SERVER_TOKEN/ID is missing @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', buildpacks: buildpacks, config: { "BLACKFIRE_LOG_LEVEL" => "4" }, - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-blackfire:*'") or raise "Failed to require PHP/ext-blackfire" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-blackfire:*'") or raise "Failed to require PHP/ext-blackfire" } ) elsif mode == "with default BLACKFIRE_LOG_LEVEL" # ext-blackfire is listed as a dependency in composer.json, and BLACKFIRE_LOG_LEVEL is the default (1=error) @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', buildpacks: buildpacks, config: credentials, - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-blackfire:*'") or raise "Failed to require PHP/ext-blackfire" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-blackfire:*'") or raise "Failed to require PHP/ext-blackfire" } ) else # a BLACKFIRE_SERVER_TOKEN/ID triggers the automatic installation of ext-blackfire at the end of the build @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', buildpacks: buildpacks, config: credentials.merge({ "BLACKFIRE_LOG_LEVEL" => "4"}), - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*'") or raise "Failed to require PHP version" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*'") or raise "Failed to require PHP version" } ) end @app.deploy @@ -80,30 +77,57 @@ end end - ['heroku-php-apache2', 'heroku-php-nginx'].each do |script| - # without log level info, we will not see the messages we're using to test any behavior - # but we need to assert that no info is printed at all in this case - it "does not output info messages during startup with #{script}", if: mode == "with default BLACKFIRE_LOG_LEVEL" do + context "during boot" do + cases = ['heroku-php-apache2', 'heroku-php-nginx'] + before(:all) do + delimiter = SecureRandom.uuid + # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + run_cmds = cases + .map { |script| "#{script} -F conf/fpm.include.broken 2>&1"} + .join("; echo -n '#{delimiter}'; ") retry_until retry: 3, sleep: 5 do - out = @app.run("#{script} -F conf/fpm.include.broken") # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call - expect(out).not_to match(/\[Info\]/) # this message should not occur if defaults are applied correctly + @run = @app.run(run_cmds).split(delimiter) end end - it "launches blackfire CLI, but not the extension, during boot preparations, with #{script}", if: mode != "with default BLACKFIRE_LOG_LEVEL" do - retry_until retry: 3, sleep: 5 do - out = @app.run("#{script} -F conf/fpm.include.broken") # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call + + # these we check only once - it's stuff that happens in .profile.d on boot, not on each script run + it "does not log info messages about agent startup", if: mode == "with default BLACKFIRE_LOG_LEVEL" do + # without log level info, we will not see the messages we're using to test any behavior + # but we need to assert that no info is printed at all in this case + expect(@run[0].unansi).not_to match(/Reading agent configuration file/) # this message should not occur if defaults are applied correctly + end + it "logs info messages about agent startup", if: mode != "with default BLACKFIRE_LOG_LEVEL" do + out = @run[0].unansi - out_before_fpm, out_after_fpm = out.unansi.split("Starting php-fpm", 2) + out_before_fpm, out_after_fpm = out.split("Starting php-fpm", 2) - expect(out_before_fpm).to match(/Reading agent configuration file/) # that is the very first thing the agent prints - if mode == "without BLACKFIRE_SERVER_TOKEN" - expect(out_before_fpm).to match(/The server ID parameter is not set/) - else - expect(out.unansi).to match(/Waiting for new connection/) # match on whole output in case it takes a bit longer to start - end + expect(out_before_fpm).to match(/Reading agent configuration file/) # that is the very first thing the agent prints + if mode == "without BLACKFIRE_SERVER_TOKEN" + expect(out_before_fpm).to match(/The server ID parameter is not set/) + else + expect(out).to match(/Waiting for new connection/) # match on whole output in case it takes a bit longer to start + end + end + + # these others we check for each script invocation + cases.each_with_index do |script, idx| + # without log level info, we will not see the messages we're using to test any behavior + # but we need to assert that no info is printed at all in this case + it "does not output info messages with #{script}", if: mode == "with default BLACKFIRE_LOG_LEVEL" do + out = @run[idx] + expect(out).not_to match(/\[Info\]/) # this message should not occur if defaults are applied correctly + end + it "preparations launches blackfire CLI, but not the extension, with #{script}", if: mode != "with default BLACKFIRE_LOG_LEVEL" do + out = @run[idx] + + out_before_fpm, out_after_fpm = out.unansi.split("Starting php-fpm", 2) + expect(out_before_fpm).not_to match(/\[Warning\] APM: Cannot start/) # extension does not attempt to start on `php-fpm -i` during boot expect(out_before_fpm).to match(/\[Debug\] APM: disabled/) # blackfire reports itself disabled (by us) during the various boot prep PHP invocations - + expect(out_after_fpm).not_to match(/\[Debug\] APM: disabled/) expect(out_after_fpm).to match(/\[Info\] APCu extension is not loaded/) end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 6f692a8a6f..8397b94a9f 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -1,5 +1,5 @@ -test/spec/blackfire-buildpackagent_spec.rb:105 -test/spec/blackfire-herokuagent_spec.rb:130 +test/spec/blackfire-buildpackagent_spec.rb:100 +test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 test/spec/ci_frameworks_spec.rb:190 test/spec/ci_spec.rb:130 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 7089ea9c0b..60ae4983f7 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -1,5 +1,5 @@ -test/spec/blackfire-buildpackagent_spec.rb:105 -test/spec/blackfire-herokuagent_spec.rb:130 +test/spec/blackfire-buildpackagent_spec.rb:100 +test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 test/spec/ci_frameworks_spec.rb:190 test/spec/ci_spec.rb:130 From 72d37addb66986d2ce0f4fda793703d01495a77b Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 14 Feb 2024 01:14:36 +0100 Subject: [PATCH 07/17] Fewer 'heroku run' calls in newrelic_spec Speeds up tests --- test/spec/newrelic_spec.rb | 70 ++++++++++++------- .../log/parallel_runtime_rspec.heroku-20.log | 2 +- .../log/parallel_runtime_rspec.heroku-22.log | 2 +- 3 files changed, 45 insertions(+), 29 deletions(-) diff --git a/test/spec/newrelic_spec.rb b/test/spec/newrelic_spec.rb index 6712d587fc..aced649873 100644 --- a/test/spec/newrelic_spec.rb +++ b/test/spec/newrelic_spec.rb @@ -1,4 +1,5 @@ require_relative "spec_helper" +require "securerandom" describe "A PHP application using New Relic" do ["explicitly", "without NEW_RELIC_LICENSE_KEY", "with default NEW_RELIC_LOG_LEVEL", "implicitly"].each do |mode| @@ -8,29 +9,25 @@ # ext-newrelic is listed as a dependency in composer.json, and a NEW_RELIC_LICENSE_KEY is provided @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', config: { "NEW_RELIC_LOG_LEVEL" => "info", "NEW_RELIC_LICENSE_KEY" => "somethingfake" }, - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-newrelic:*'") or raise "Failed to require PHP/ext-newrelic" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-newrelic:*'") or raise "Failed to require PHP/ext-newrelic" } ) elsif mode == "without NEW_RELIC_LICENSE_KEY" # ext-newrelic is listed as a dependency in composer.json, but a NEW_RELIC_LICENSE_KEY is missing @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', config: { "NEW_RELIC_LOG_LEVEL" => "info" }, - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-newrelic:*'") or raise "Failed to require PHP/ext-newrelic" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-newrelic:*'") or raise "Failed to require PHP/ext-newrelic" } ) elsif mode == "with default NEW_RELIC_LOG_LEVEL" # ext-newrelic is listed as a dependency in composer.json, and NEW_RELIC_LOG_LEVEL is the default (warning) @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', config: { "NEW_RELIC_LICENSE_KEY" => "somethingfake" }, - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-newrelic:*'") or raise "Failed to require PHP/ext-newrelic" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*' 'ext-newrelic:*'") or raise "Failed to require PHP/ext-newrelic" } ) else # a NEW_RELIC_LICENSE_KEY triggers the automatic installation of ext-newrelic at the end of the build @app = new_app_with_stack_and_platrepo('test/fixtures/bootopts', config: { "NEW_RELIC_LOG_LEVEL" => "info", "NEW_RELIC_LICENSE_KEY" => "thiswilltriggernewrelic" }, - before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*'") or raise "Failed to require PHP version" }, - run_multi: true + before_deploy: -> { system("composer require --quiet --ignore-platform-reqs 'php:*'") or raise "Failed to require PHP version" } ) end @app.deploy @@ -59,32 +56,51 @@ expect(@app.output).not_to match(/daemon='@newrelic-daemon'.*?startup=agent/) # no extension connects during build end - ['heroku-php-apache2', 'heroku-php-nginx'].each do |script| - if mode == "with default NEW_RELIC_LOG_LEVEL" + context "during boot" do + cases = ['heroku-php-apache2', 'heroku-php-nginx'] + before(:all) do + delimiter = SecureRandom.uuid + # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call + # there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order + # if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo + # for that reason, we redirect stderr to stdout + run_cmds = cases + .map { |script| "#{script} -F conf/fpm.include.broken 2>&1"} + .join("; echo -n '#{delimiter}'; ") + retry_until retry: 3, sleep: 5 do + @run = @app.run(run_cmds).split(delimiter) + end + end + + # these we check only once - it's stuff that happens in .profile.d on boot, not on each script run + it "does not log info messages about daemon startup", if: mode == "with default NEW_RELIC_LOG_LEVEL" do # without log level info, we will not see the messages we're using to test any behavior # but we need to assert that no info is printed at all in this case - it "does not output info messages during startup with #{script}" do - retry_until retry: 3, sleep: 5 do - out = @app.run("#{script} -F conf/fpm.include.broken") # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call - - expect(out).not_to match(/New Relic PHP Agent globally disabled/) # this message should not occur if defaults are applied correctly even at build time - expect(out).not_to match(/New Relic daemon/) # this message should not occur if defaults are applied correctly even at build time - end - end - next # the other tests do not apply to this case since the log level isn't sufficient to assert anything + expect(@run[0]).not_to match(/New Relic daemon/) # this message should not occur if defaults are applied correctly end - it "launches newrelic-daemon, but not the extension, during boot preparations, with #{script}" do - retry_until retry: 3, sleep: 5 do - out = @app.run("#{script} -F conf/fpm.include.broken") # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call - + it "logs info messages about daemon startup", if: mode != "with default NEW_RELIC_LOG_LEVEL" do + out_before_fpm, out_after_fpm = @run[0].split("Starting php-fpm", 2) + expect(out_before_fpm).to match(/listen="@newrelic-daemon"[^\n]+?startup=init/) # NR daemon starts on boot + end + + # these others we check for each script invocation + cases.each_with_index do |script, idx| + # without log level info, we will not see the messages we're using to test any behavior + # but we need to assert that no info is printed at all in this case + it "does not output info messages during startup with #{script}", if: mode == "with default NEW_RELIC_LOG_LEVEL" do + # these messages should not occur if defaults are applied correctly + expect(@run[idx]).not_to match(/New Relic daemon/) + expect(@run[idx]).not_to match(/New Relic PHP Agent globally disabled/) + end + it "launches newrelic-daemon, but not the extension, during boot preparations, with #{script}", if: mode != "with default NEW_RELIC_LOG_LEVEL" do + out = @run[idx] expect(out).not_to match(/spawned daemon child/) # extension does not spawn its own daemon - + out_before_fpm, out_after_fpm = out.split("Starting php-fpm", 2) - - expect(out_before_fpm).to match(/listen="@newrelic-daemon"[^\n]+?startup=init/) # NR daemon starts on boot + expect(out_before_fpm).not_to match(/daemon='@newrelic-daemon'[^\n]+?startup=agent/) # extension does not connect to daemon before FPM starts expect(out_before_fpm).to match(/New Relic PHP Agent globally disabled/) # NR extension reports itself disabled - + expect(out_after_fpm).to match(/daemon='@newrelic-daemon'[^\n]+?startup=agent/m) # extension connects to daemon when FPM starts end end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 8397b94a9f..e04b5982e8 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -6,7 +6,7 @@ test/spec/ci_spec.rb:130 test/spec/composer_spec.rb:135 test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 -test/spec/newrelic_spec.rb:110 +test/spec/newrelic_spec.rb:115 test/spec/nginx_spec.rb:49 test/spec/php-7.3_base_spec.rb:30 test/spec/php-7.3_boot-apache2_spec.rb:65 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 60ae4983f7..5f36f8a5a6 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -6,7 +6,7 @@ test/spec/ci_spec.rb:130 test/spec/composer_spec.rb:120 test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 -test/spec/newrelic_spec.rb:110 +test/spec/newrelic_spec.rb:115 test/spec/nginx_spec.rb:49 test/spec/php-8.1_base_spec.rb:30 test/spec/php-8.1_boot-apache2_spec.rb:65 From 5e1a6a99f199b58057aa2be42acd8c4a2c0b0aa9 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 14 Feb 2024 15:45:50 +0100 Subject: [PATCH 08/17] Print output from same run's previous commands when a php_boot_spec case fails Helps with debugging in cases where a shutdown in a prior run somehow goes wrong, and web server or PHP-FPM fail to start again (since something is already/still listening on the port). --- test/spec/php_boot_shared.rb | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/test/spec/php_boot_shared.rb b/test/spec/php_boot_shared.rb index 29739cb560..5c8d889386 100644 --- a/test/spec/php_boot_shared.rb +++ b/test/spec/php_boot_shared.rb @@ -137,9 +137,16 @@ def self.gencmd(args) examples.each_with_index do |example, index| it example[:title] do output, _, code = @run[index].rstrip.rpartition("\n") + # in case this one has failed, print what the previous runs have done - maybe something unexpected (but still with correct exit code) happened that can aid debugging + previous = @run.slice(0, index).map.with_index { |run, idx| out, _, status = run.rstrip.rpartition("\n"); "Output for '#{examples[idx][:cmd]}' (exited #{status}):\n#{out}" } + if previous.empty? + previous = "" + else + previous = "\n\nFor reference, here is the output from the previous commands in this run:\n\n#{previous.join("\n\n")}" + end expect(code).method(example[:expect]).call( method(example[:operator]).call(example[:code].to_s), - "Expected exit code #{code} #{example[:expect]} be #{example[:operator]} to #{example[:code]}; output:\n#{output}" + "Expected exit code #{code} #{example[:expect]} be #{example[:operator]} to #{example[:code]}; output for '#{example[:cmd]}':\n#{output}#{previous}" ) end end From 59444e73792c1a163d007c1dbd284f10d3d94bd2 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Mon, 12 Feb 2024 21:53:27 +0100 Subject: [PATCH 09/17] Simplify waitforit.sh The purpose of this 'program' is to wait for output from a launched program, but with a timeout to prevent hanging forever. Its key feature is the ability to detect when it is part of a pipeline, and to then write something to that pipeline to signal that the expected output is there - this allows constructs like 'waitforit.sh 10 someprogram | { read; do_something_with_someprogram; }'. The previous solution for the internal pipeline signaling is, however, subject to certain race conditions, and then programs might not be terminated correctly, or the pipe signal loop may hang forever. It's simpler overall to just launch two 'timeout's, for the program and for the output grepping, and wait for either or both to terminate. --- test/utils/waitforit.sh | 87 ++++++++++++++++++++++++++--------------- 1 file changed, 55 insertions(+), 32 deletions(-) diff --git a/test/utils/waitforit.sh b/test/utils/waitforit.sh index cd1368c396..80f0987f69 100755 --- a/test/utils/waitforit.sh +++ b/test/utils/waitforit.sh @@ -14,7 +14,7 @@ print_help() { ${1:-Execute a given program and terminate after timeout or line match.} Usage: - waitforit [options] + waitforit The given COMMAND will be terminated after the given number of seconds, or the given TEXT_TO_MATCH has matched, whichever comes first. @@ -64,34 +64,57 @@ else grepargs="-q" fi -# First, we spawn a subshell that executes the desired program, wrapped in timeout (as a hard limit to prevent hanging forever if the desired text does not match). -# A trap is set up that fires on SIGPIPE (and SIGUSR1, see note below) and kills the program. -# After the program is launched, we check if it's alive in a loop, and write a dot to the following pipeline -# This writing acts as a check to see whether the following pipeline is still alive - if it is not, that's because it has terminated (see its explanation further below). -# Once the pipeline is gone, our trap fires, and shuts down the program. - -# TODO: have option to suppress output to stderr -( - # we trap SIGPIPE, but also SIGUSR1 - # there are cases where the invoking shell does not allow SIGPIPE traps to be installed - trap 'trap - PIPE USR1; kill -TERM $pid 2> /dev/null || true; wait $pid; exit 0' PIPE USR1 - - # we redirect stderr to stdout so it can be captured as well... - # ... and redirect stdout to a tee that also writes to stderr (so the output is visible) - this is done so that $! is still the pid of the timeout command - timeout $duration "$@" > >(tee >(cat 1>&2)) 2>&1 & pid=$! - - # while the program is alive, write a dot to the following pipeline - # once the following pipeline has finished, the echo will cause a SIGPIPE, which our trap above will catch - # for cases where SIGPIPE handlers are not available, we manually issue a SIGUSR1 to ourselves if the echo fails with an error (due to broken pipe) - while kill -0 $pid 2>/dev/null; do echo "." 2>/dev/null || kill -USR1 $BASHPID; sleep 0.1; done; - - wait $pid || exit $? - - exec 1>&-; -# The following pipeline blocks until grep has matched the desired text. -# Once the match has succeeded, and we're in $pipeout mode, the pipeline that follows us (outside this script), with the user test, will start running (since it is something like `{ read; curl localhost:$PORT/test | grep foo; }`, and the `read` will unblock due to our grep having output something). -# We then keep writing dots to that outer pipeline, which will start failing with SIGPIPE once the outer pipeline has finished executing. -# Once that happens, we break out of the loop, and that will cause the pipeline above (that executed the program) to also hit a SIGPIPE, and shut down the program. -) | { grep --line-buffered $grepargs -E -e "$text" && while test $pipeout; do echo "." 2>/dev/null || break; sleep 0.1; done; exec 1>&-; } - -exit ${PIPESTATUS[0]} +# a temp log file which the program writes to in one 'timeout', and a tail/grep pipeline reads from in another 'timeout' +# this way, the 'tee' that duplicates all output to both the log file and stderr lives until the very end of the program's lifetime and outputs everything +# this is much simpler than chaining the two together using a pipeline, since SIGPIPE propagates through it in a funny manner, and timeout +stdout_log=$(mktemp) +stderr_log=$(mktemp) + +# launch the program wrapped in a timeout, sending stderr to stdout to separate logs while maintaining their respective original "channels" +timeout $duration "$@" > >(tee "$stdout_log") 2> >(tee "$stderr_log" >&2) & pid=$! + +# tail the log file in a timeout, and grep for our expected output +# once the grep returns, we keep writing output to a following pipeline (if there is one), so that a program there can do some stuff - once it's done, our echo attempts will start failing (due to SIGPIPE), and we exit +timeout $duration tail -q -F "$stdout_log" "$stderr_log" > >(grep --line-buffered $grepargs -E -e "$text" && while test $pipeout; do echo "." 2>/dev/null || break; sleep 0.1; done; ) & tid=$! + +# wait for whichever returns first - could be the program "crashing" or timing out, or the tail hitting the grep expression or timing out +wait -n $pid $tid + +# we first check if the tail is still alive, not if the program is still alive +# this allows testing cases where the program exits using a particular message +if kill -0 $tid 2> /dev/null; then + wait $pid + if [[ $? != 124 ]]; then + kill -TERM $tid + fi +fi + +# record the exit status of the first part of the tail pipeline, so that we can differentiate between a timeout (status 124) and a successful match (status 141, SIGPIPE) +wait $tid +pipest=$? + +if [[ "$pipest" == 141 ]]; then + # if we have a match (pipe status 141), then let's shut down the program + # it's likely the program is still alive, as it should be - shut it down, then exit 0, so that the caller can know all was well + kill -TERM $pid 2> /dev/null + # wait and get its real exit status + wait $pid + # exit 0 in all cases + exit 0 +elif [[ "$pipest" != 124 && "$pipest" != 143 ]]; then + # if the tail did not time out, and was not killed by us... that would be weird! + echo "$(basename $0): unexpected status ${pipest} for 'timeout tail'" >&2 +fi + +# the tail/grep pipeline timed out, so we had no match +# we rely on the timeout for the "main" program to kick in +wait $pid + +progst=$? +if [[ "$pipest" != "$progst" ]]; then + # we relay that exit status - it is possible that it did not exit due to timeout, but just early with some error + exit $progst +else + # both timed out, all is well + exit $pipest +fi From a7bae1ff61a0a5c09a056715bbbb4ff0ef4f97e2 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Tue, 13 Feb 2024 22:29:07 +0100 Subject: [PATCH 10/17] Speed up platform_spec by bailing out of some builds early --- test/spec/platform_spec.rb | 10 ++++++---- test/var/log/parallel_runtime_rspec.heroku-20.log | 2 +- test/var/log/parallel_runtime_rspec.heroku-22.log | 2 +- 3 files changed, 8 insertions(+), 6 deletions(-) diff --git a/test/spec/platform_spec.rb b/test/spec/platform_spec.rb index de2539f339..bf9635ac25 100644 --- a/test/spec/platform_spec.rb +++ b/test/spec/platform_spec.rb @@ -230,8 +230,10 @@ end context "of a project that uses polyfills providing both bundled-with-PHP and third-party extensions" do + # we set an invalid COMPOSER_AUTH on all of these to stop and fail the build on userland dependency install + # we only need to check what happened during the platform install step, so that speeds things up it "treats polyfills for bundled-with-PHP and third-party extensions the same", :requires_php_on_stack => "7.4" do - new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills').deploy do |app| + new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills', config: { "COMPOSER_AUTH" => "broken" }, allow_failure: true).deploy do |app| expect(app.output).to include("detected userland polyfill packages for PHP extensions") expect(app.output).not_to include("- ext-mbstring") # ext not required by any dependency, so should not be installed or even attempted ("- ext-mbstring...") out_before_polyfills, out_after_polyfills = app.output.split("detected userland polyfill packages for PHP extensions", 2) @@ -244,7 +246,7 @@ end end it "installs native bundled extensions for legacy PHP builds for installer < 1.6 even if they are provided by a polyfill", :requires_php_on_stack => "7.3" do - new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills-legacy').deploy do |app| + new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills-legacy', config: { "COMPOSER_AUTH" => "broken" }, allow_failure: true).deploy do |app| expect(app.output).to include("detected userland polyfill packages for PHP extensions") expect(app.output).not_to include("- ext-mbstring") # ext not required by any dependency, so should not be installed or even attempted ("- ext-mbstring...") out_before_polyfills, out_after_polyfills = app.output.split("detected userland polyfill packages for PHP extensions", 2) @@ -256,7 +258,7 @@ end end it "solves using the polyfills first and does not downgrade installed packages in the later native install step" do - new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills-nodowngrade').deploy do |app| + new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills-nodowngrade', config: { "COMPOSER_AUTH" => "broken" }, allow_failure: true).deploy do |app| expect(app.output).to include("detected userland polyfill packages for PHP extensions") expect(app.output).not_to include("- ext-mbstring") # ext not required by any dependency, so should not be installed or even attempted ("- ext-mbstring...") out_before_polyfills, out_after_polyfills = app.output.split("detected userland polyfill packages for PHP extensions", 2) @@ -270,7 +272,7 @@ end end it "ignores a polyfill for an extension that another extension depends upon" do - new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills-nointernaldeps').deploy do |app| + new_app_with_stack_and_platrepo('test/fixtures/platform/installer/polyfills-nointernaldeps', config: { "COMPOSER_AUTH" => "broken" }, allow_failure: true).deploy do |app| expect(app.output).to include("detected userland polyfill packages for PHP extensions") # ext-pq got installed... expect(app.output).to include("- ext-pq (") diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index e04b5982e8..80146bdf8f 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -49,4 +49,4 @@ test/spec/php-8.3_concurrency-nginx_spec.rb:65 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 test/spec/php_default_spec.rb:55 -test/spec/platform_spec.rb:105 +test/spec/platform_spec.rb:100 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 5f36f8a5a6..422483c385 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -30,4 +30,4 @@ test/spec/php-8.3_concurrency-nginx_spec.rb:65 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 test/spec/php_default_spec.rb:55 -test/spec/platform_spec.rb:65 +test/spec/platform_spec.rb:60 From dd23fe880bcfe49b9a50b0742a4478b955ac74cc Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 14 Feb 2024 03:52:25 +0100 Subject: [PATCH 11/17] Move stack change test to php_default_spec Speeds stuff up for composer_spec on heroku-22 --- test/spec/composer_spec.rb | 13 ------------- test/spec/php_default_spec.rb | 14 +++++++++++++- test/var/log/parallel_runtime_rspec.heroku-20.log | 2 +- test/var/log/parallel_runtime_rspec.heroku-22.log | 4 ++-- 4 files changed, 16 insertions(+), 17 deletions(-) diff --git a/test/spec/composer_spec.rb b/test/spec/composer_spec.rb index bdc1ad2884..ff1c116ea9 100644 --- a/test/spec/composer_spec.rb +++ b/test/spec/composer_spec.rb @@ -1,19 +1,6 @@ require_relative "spec_helper" describe "A PHP application" do - context "that has its stack changed", :stack => "heroku-22" do - it "re-uses cached dependencies from the prior stack build" do - new_app_with_stack_and_platrepo("php-getting-started").deploy do |app| - expect(app.output).to include("Downloading") - app.update_stack("heroku-20") - # we are changing the stack to heroku-20, so we also need to adjust the platform repository accordingly, otherwise, for tests running on branches where HEROKU_PHP_PLATFORM_REPOSITORIES is set to a value, the build would use the wrong repo - app.set_config({"HEROKU_PHP_PLATFORM_REPOSITORIES" => ENV["HEROKU_PHP_PLATFORM_REPOSITORIES"].sub("heroku-22", "heroku-20")}) if ENV["HEROKU_PHP_PLATFORM_REPOSITORIES"] - app.commit! - app.push! - expect(app.output).to_not include("Downloading") - end - end - end context "with a composer.lock generated by an old version of Composer", :stack => "heroku-20" do it "builds using Composer 1.x and prints a notice" do new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_oldv1').deploy do |app| diff --git a/test/spec/php_default_spec.rb b/test/spec/php_default_spec.rb index 305c1e73d9..cfaaacd8a0 100644 --- a/test/spec/php_default_spec.rb +++ b/test/spec/php_default_spec.rb @@ -3,9 +3,21 @@ describe "A PHP application" do context "like the Heroku Getting Started guide example for PHP" do - it "deploys and works" do + it "deploys, works, and re-uses cached dependencies on stack change" do new_app_with_stack_and_platrepo("php-getting-started").deploy do |app| expect(successful_body(app)) + + # we need to test inside this deploy block for the push to work (subsequent deploy or in_directory calls start with a fresh fixture copy and repo) + + next unless "heroku-22" == ENV['STACK'] # testing one stack change is enough + + expect(app.output).to include("Downloading") + app.update_stack("heroku-20") + # we are changing the stack to heroku-20, so we also need to adjust the platform repository accordingly, otherwise, for tests running on branches where HEROKU_PHP_PLATFORM_REPOSITORIES is set to a value, the build would use the wrong repo + app.set_config({"HEROKU_PHP_PLATFORM_REPOSITORIES" => ENV["HEROKU_PHP_PLATFORM_REPOSITORIES"].sub("heroku-22", "heroku-20")}) if ENV["HEROKU_PHP_PLATFORM_REPOSITORIES"] + app.commit! + app.push! + expect(app.output).to_not include("Downloading") end end end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 80146bdf8f..19318352dc 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -48,5 +48,5 @@ test/spec/php-8.3_concurrency-apache2_spec.rb:70 test/spec/php-8.3_concurrency-nginx_spec.rb:65 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 -test/spec/php_default_spec.rb:55 +test/spec/php_default_spec.rb:50 test/spec/platform_spec.rb:100 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 422483c385..cd33ee4a77 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -3,7 +3,7 @@ test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 test/spec/ci_frameworks_spec.rb:190 test/spec/ci_spec.rb:130 -test/spec/composer_spec.rb:120 +test/spec/composer_spec.rb:100 test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:115 @@ -29,5 +29,5 @@ test/spec/php-8.3_concurrency-apache2_spec.rb:70 test/spec/php-8.3_concurrency-nginx_spec.rb:65 test/spec/php-8.3_sigterm-apache2_spec.rb:55 test/spec/php-8.3_sigterm-nginx_spec.rb:55 -test/spec/php_default_spec.rb:55 +test/spec/php_default_spec.rb:60 test/spec/platform_spec.rb:60 From c387f6efe11a96870d5515e610ac38a98c9b93f0 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 14 Feb 2024 04:21:32 +0100 Subject: [PATCH 12/17] Split composer_spec into v1 and v2 For better parallelism --- test/spec/composer-1_spec.rb | 38 +++++++++++ test/spec/composer-2_spec.rb | 53 +++++++++++++++ test/spec/composer_spec.rb | 68 ------------------- .../log/parallel_runtime_rspec.heroku-20.log | 3 +- .../log/parallel_runtime_rspec.heroku-22.log | 2 +- 5 files changed, 94 insertions(+), 70 deletions(-) create mode 100644 test/spec/composer-1_spec.rb create mode 100644 test/spec/composer-2_spec.rb delete mode 100644 test/spec/composer_spec.rb diff --git a/test/spec/composer-1_spec.rb b/test/spec/composer-1_spec.rb new file mode 100644 index 0000000000..8a97a3e189 --- /dev/null +++ b/test/spec/composer-1_spec.rb @@ -0,0 +1,38 @@ +require_relative "spec_helper" + +describe "A PHP application intended for Composer 1", :stack => "heroku-20" do + context "with a composer.lock generated by an old version of Composer" do + it "builds using Composer 1.x and prints a notice" do + new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_oldv1').deploy do |app| + expect(app.output).to match(/No Composer plugin-api-version recorded/) + expect(app.output).to match(/- composer \(1/) + expect(app.output).to match(/Composer version 1/) + end + end + end + context "with a composer.lock generated by a late version 1 of Composer" do + before(:all) do + @app = new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v1') + @app.deploy + end + + after(:all) do + @app.teardown! + end + + it "builds using Composer 1.x" do + expect(@app.output).to match(/- composer \(1/) + expect(@app.output).to match(/Composer version 1/) + end + + context "with a malformed COMPOSER_AUTH env var" do + it "still boots" do + # config test is enough, it's past any uses of composer on startup + cmds = ['heroku-php-apache2', 'heroku-php-nginx'].map { |script| "#{script} -t" } + retry_until retry: 3, sleep: 5 do + expect_exit(code: 0) { @app.run("( set -e; #{cmds.join('; ')}; )", :return_obj => true, :heroku => {:env => "COMPOSER_AUTH=malformed"}) } + end + end + end + end +end diff --git a/test/spec/composer-2_spec.rb b/test/spec/composer-2_spec.rb new file mode 100644 index 0000000000..65d32f0bed --- /dev/null +++ b/test/spec/composer-2_spec.rb @@ -0,0 +1,53 @@ +require_relative "spec_helper" + +describe "A PHP application intended for Composer 2" do + context "with a composer.lock generated by version 2.2 of Composer" do + it "builds using Composer 2.2" do + new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v2lts').deploy do |app| + expect(app.output).to match(/- composer \(2\.2\./) + expect(app.output).to match(/Composer version 2\.2\./) + end + end + end + context "with a composer.lock generated by version 2.3 of Composer" do + before(:all) do + @app = new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v2') + @app.deploy + end + + after(:all) do + @app.teardown! + end + + it "builds using Composer 2.3 or later" do + expect(@app.output).to match(/- composer \(2\.([3-9]|\d{2,})\./) + expect(@app.output).to match(/Composer version 2\.([3-9]|\d{2,}\.)/) + end + + context "with a malformed COMPOSER_AUTH env var" do + it "still boots" do + # config test is enough, it's past any uses of composer on startup + cmds = ['heroku-php-apache2', 'heroku-php-nginx'].map { |script| "#{script} -t" } + retry_until retry: 3, sleep: 5 do + expect_exit(code: 0) { @app.run("( set -e; #{cmds.join('; ')}; )", :return_obj => true, :heroku => {:env => "COMPOSER_AUTH=malformed"}) } + end + end + end + end + context "with a composer.lock generated by a future version 2 of Composer" do + it "builds using Composer 2.3 or later" do + new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v2.999').deploy do |app| + expect(app.output).to match(/- composer \(2\.([3-9]|\d{2,})\./) + expect(app.output).to match(/Composer version 2\.([3-9]|\d{2,}\.)/) + end + end + end + context "with only an index.php" do + it "builds using Composer 2.2" do + new_app_with_stack_and_platrepo('test/fixtures/default').deploy do |app| + expect(app.output).to match(/- composer \(2\.2\./) + expect(app.output).to match(/Composer version 2\.2\./) + end + end + end +end diff --git a/test/spec/composer_spec.rb b/test/spec/composer_spec.rb deleted file mode 100644 index ff1c116ea9..0000000000 --- a/test/spec/composer_spec.rb +++ /dev/null @@ -1,68 +0,0 @@ -require_relative "spec_helper" - -describe "A PHP application" do - context "with a composer.lock generated by an old version of Composer", :stack => "heroku-20" do - it "builds using Composer 1.x and prints a notice" do - new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_oldv1').deploy do |app| - expect(app.output).to match(/No Composer plugin-api-version recorded/) - expect(app.output).to match(/- composer \(1/) - expect(app.output).to match(/Composer version 1/) - end - end - end - context "with a composer.lock generated by a late version 1 of Composer", :stack => "heroku-20" do - it "builds using Composer 1.x" do - new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v1').deploy do |app| - expect(app.output).to match(/- composer \(1/) - expect(app.output).to match(/Composer version 1/) - end - end - end - context "with a composer.lock generated by version 2.2 of Composer" do - it "builds using Composer 2.2" do - new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v2lts').deploy do |app| - expect(app.output).to match(/- composer \(2\.2\./) - expect(app.output).to match(/Composer version 2\.2\./) - end - end - end - context "with a composer.lock generated by version 2.3 of Composer" do - it "builds using Composer 2.3 or later" do - new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v2').deploy do |app| - expect(app.output).to match(/- composer \(2\.([3-9]|\d{2,})\./) - expect(app.output).to match(/Composer version 2\.([3-9]|\d{2,}\.)/) - end - end - end - context "with a composer.lock generated by a future version 2 of Composer" do - it "builds using Composer 2.3 or later" do - new_app_with_stack_and_platrepo('test/fixtures/composer/basic_lock_v2.999').deploy do |app| - expect(app.output).to match(/- composer \(2\.([3-9]|\d{2,})\./) - expect(app.output).to match(/Composer version 2\.([3-9]|\d{2,}\.)/) - end - end - end - context "with only an index.php" do - it "builds using Composer 2.2" do - new_app_with_stack_and_platrepo('test/fixtures/default').deploy do |app| - expect(app.output).to match(/- composer \(2\.2\./) - expect(app.output).to match(/Composer version 2\.2\./) - end - end - end - context "with a malformed COMPOSER_AUTH env var" do - ['v1', 'v2'].each do |cv| - next unless cv == "v2" or "heroku-20" == ENV['STACK'] - it "the app still boots" do - new_app_with_stack_and_platrepo("test/fixtures/composer/basic_lock_#{cv}", run_multi: true).deploy do |app| - ['heroku-php-apache2', 'heroku-php-nginx'].each do |script| - retry_until retry: 3, sleep: 5 do - out = app.run("#{script} -F composer.lock", :heroku => {:env => "COMPOSER_AUTH=malformed"}) # prevent FPM from starting up using an invalid config, that way we don't have to wrap the server start in a `timeout` call - expect(out).to match(/FPM initialization failed/) # we got far enough (until FPM spits out an error) - end - end - end - end - end - end -end diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 19318352dc..b2ae40e233 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -3,7 +3,8 @@ test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 test/spec/ci_frameworks_spec.rb:190 test/spec/ci_spec.rb:130 -test/spec/composer_spec.rb:135 +test/spec/composer-1_spec.rb:50 +test/spec/composer-2_spec.rb:90 test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:115 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index cd33ee4a77..5ae88ad737 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -3,7 +3,7 @@ test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 test/spec/ci_frameworks_spec.rb:190 test/spec/ci_spec.rb:130 -test/spec/composer_spec.rb:100 +test/spec/composer-2_spec.rb:90 test/spec/devcenter_spec.rb:5 test/spec/httpd_spec.rb:18 test/spec/newrelic_spec.rb:115 From 9740e7554a10fcecfbecff5c411b67a497edd4d0 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Wed, 14 Feb 2024 06:04:36 +0100 Subject: [PATCH 13/17] Combine 'composer test' and zend.assertions CI tests into one Speeds things up for ci_spec --- test/fixtures/ci/composertest/composer.json | 5 ----- test/fixtures/ci/zendassert/test.php | 8 +++++++- test/spec/ci_spec.rb | 19 ++++--------------- .../log/parallel_runtime_rspec.heroku-20.log | 2 +- .../log/parallel_runtime_rspec.heroku-22.log | 2 +- 5 files changed, 13 insertions(+), 23 deletions(-) delete mode 100644 test/fixtures/ci/composertest/composer.json diff --git a/test/fixtures/ci/composertest/composer.json b/test/fixtures/ci/composertest/composer.json deleted file mode 100644 index f0670420c3..0000000000 --- a/test/fixtures/ci/composertest/composer.json +++ /dev/null @@ -1,5 +0,0 @@ -{ - "scripts": { - "test": "echo 'all tests passed'" - } -} diff --git a/test/fixtures/ci/zendassert/test.php b/test/fixtures/ci/zendassert/test.php index ae0cb2f51c..1373224335 100644 --- a/test/fixtures/ci/zendassert/test.php +++ b/test/fixtures/ci/zendassert/test.php @@ -1,4 +1,10 @@ Date: Wed, 14 Feb 2024 06:21:11 +0100 Subject: [PATCH 14/17] Split ci_frameworks_spec into two Those are the slowest tests, so it helps a lot with overall time and with parallelization --- test/spec/ci_frameworks-a_spec.rb | 20 +++++++++++++++++++ ...eworks_spec.rb => ci_frameworks-k_spec.rb} | 5 +---- .../log/parallel_runtime_rspec.heroku-20.log | 3 ++- .../log/parallel_runtime_rspec.heroku-22.log | 3 ++- 4 files changed, 25 insertions(+), 6 deletions(-) create mode 100644 test/spec/ci_frameworks-a_spec.rb rename test/spec/{ci_frameworks_spec.rb => ci_frameworks-k_spec.rb} (85%) diff --git a/test/spec/ci_frameworks-a_spec.rb b/test/spec/ci_frameworks-a_spec.rb new file mode 100644 index 0000000000..1d499fdb11 --- /dev/null +++ b/test/spec/ci_frameworks-a_spec.rb @@ -0,0 +1,20 @@ +require_relative "spec_helper" + +describe "A PHP application on Heroku CI" do + { + "atoum": "atoum", + "Behat": "behat", + "Codeception": "codecept run", + }.each do |name, command| + context "using the #{name} CI framework" do + let(:app) { + new_app_with_stack_and_platrepo("test/fixtures/ci/#{name.downcase}") + } + it "automatically executes '#{command}'" do + app.run_ci do |test_run| + expect(test_run.output).to match("#{name} found, executing '#{command}'...") + end + end + end + end +end diff --git a/test/spec/ci_frameworks_spec.rb b/test/spec/ci_frameworks-k_spec.rb similarity index 85% rename from test/spec/ci_frameworks_spec.rb rename to test/spec/ci_frameworks-k_spec.rb index fc79bb0ee3..8568b2d1c1 100644 --- a/test/spec/ci_frameworks_spec.rb +++ b/test/spec/ci_frameworks-k_spec.rb @@ -2,11 +2,8 @@ describe "A PHP application on Heroku CI" do { - "Codeception": "codecept run", - "Behat": "behat", - "PHPSpec": "phpspec run", - "atoum": "atoum", "Kahlan": "kahlan", + "PHPSpec": "phpspec run", "PHPUnit": "phpunit", }.each do |name, command| context "using the #{name} CI framework" do diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 2456c8f189..561c4a11bf 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -1,7 +1,8 @@ test/spec/blackfire-buildpackagent_spec.rb:100 test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 -test/spec/ci_frameworks_spec.rb:190 +test/spec/ci_frameworks-a_spec.rb:120 +test/spec/ci_frameworks-k_spec.rb:120 test/spec/ci_spec.rb:125 test/spec/composer-1_spec.rb:50 test/spec/composer-2_spec.rb:90 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index 2ed0092836..bac088fb8c 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -1,7 +1,8 @@ test/spec/blackfire-buildpackagent_spec.rb:100 test/spec/blackfire-herokuagent_spec.rb:120 test/spec/bugs_spec.rb:30 -test/spec/ci_frameworks_spec.rb:190 +test/spec/ci_frameworks-a_spec.rb:120 +test/spec/ci_frameworks-k_spec.rb:120 test/spec/ci_spec.rb:125 test/spec/composer-2_spec.rb:90 test/spec/devcenter_spec.rb:5 From 79b416eaff2d9d04611315d3a61f1b7656986389 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Mon, 4 Mar 2024 23:55:00 +0100 Subject: [PATCH 15/17] Slightly adjust test runtimes for better balancing --- .../log/parallel_runtime_rspec.heroku-20.log | 22 +++++++++---------- .../log/parallel_runtime_rspec.heroku-22.log | 14 ++++++------ 2 files changed, 18 insertions(+), 18 deletions(-) diff --git a/test/var/log/parallel_runtime_rspec.heroku-20.log b/test/var/log/parallel_runtime_rspec.heroku-20.log index 561c4a11bf..117db5ecdf 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-20.log +++ b/test/var/log/parallel_runtime_rspec.heroku-20.log @@ -1,6 +1,6 @@ test/spec/blackfire-buildpackagent_spec.rb:100 test/spec/blackfire-herokuagent_spec.rb:120 -test/spec/bugs_spec.rb:30 +test/spec/bugs_spec.rb:40 test/spec/ci_frameworks-a_spec.rb:120 test/spec/ci_frameworks-k_spec.rb:120 test/spec/ci_spec.rb:125 @@ -20,35 +20,35 @@ test/spec/php-7.4_boot-apache2_spec.rb:65 test/spec/php-7.4_boot-nginx_spec.rb:55 test/spec/php-7.4_concurrency-apache2_spec.rb:70 test/spec/php-7.4_concurrency-nginx_spec.rb:65 -test/spec/php-7.4_sigterm-apache2_spec.rb:55 -test/spec/php-7.4_sigterm-nginx_spec.rb:55 +test/spec/php-7.4_sigterm-apache2_spec.rb:70 +test/spec/php-7.4_sigterm-nginx_spec.rb:70 test/spec/php-8.0_base_spec.rb:30 test/spec/php-8.0_boot-apache2_spec.rb:65 test/spec/php-8.0_boot-nginx_spec.rb:55 test/spec/php-8.0_concurrency-apache2_spec.rb:70 test/spec/php-8.0_concurrency-nginx_spec.rb:65 -test/spec/php-8.0_sigterm-apache2_spec.rb:55 -test/spec/php-8.0_sigterm-nginx_spec.rb:55 +test/spec/php-8.0_sigterm-apache2_spec.rb:70 +test/spec/php-8.0_sigterm-nginx_spec.rb:70 test/spec/php-8.1_base_spec.rb:30 test/spec/php-8.1_boot-apache2_spec.rb:65 test/spec/php-8.1_boot-nginx_spec.rb:55 test/spec/php-8.1_concurrency-apache2_spec.rb:70 test/spec/php-8.1_concurrency-nginx_spec.rb:65 -test/spec/php-8.1_sigterm-apache2_spec.rb:55 -test/spec/php-8.1_sigterm-nginx_spec.rb:55 +test/spec/php-8.1_sigterm-apache2_spec.rb:70 +test/spec/php-8.1_sigterm-nginx_spec.rb:70 test/spec/php-8.2_base_spec.rb:30 test/spec/php-8.2_boot-apache2_spec.rb:65 test/spec/php-8.2_boot-nginx_spec.rb:55 test/spec/php-8.2_concurrency-apache2_spec.rb:70 test/spec/php-8.2_concurrency-nginx_spec.rb:65 -test/spec/php-8.2_sigterm-apache2_spec.rb:55 -test/spec/php-8.2_sigterm-nginx_spec.rb:55 +test/spec/php-8.2_sigterm-apache2_spec.rb:70 +test/spec/php-8.2_sigterm-nginx_spec.rb:70 test/spec/php-8.3_base_spec.rb:30 test/spec/php-8.3_boot-apache2_spec.rb:65 test/spec/php-8.3_boot-nginx_spec.rb:55 test/spec/php-8.3_concurrency-apache2_spec.rb:70 test/spec/php-8.3_concurrency-nginx_spec.rb:65 -test/spec/php-8.3_sigterm-apache2_spec.rb:55 -test/spec/php-8.3_sigterm-nginx_spec.rb:55 +test/spec/php-8.3_sigterm-apache2_spec.rb:70 +test/spec/php-8.3_sigterm-nginx_spec.rb:70 test/spec/php_default_spec.rb:50 test/spec/platform_spec.rb:100 diff --git a/test/var/log/parallel_runtime_rspec.heroku-22.log b/test/var/log/parallel_runtime_rspec.heroku-22.log index bac088fb8c..46f94f5f1d 100644 --- a/test/var/log/parallel_runtime_rspec.heroku-22.log +++ b/test/var/log/parallel_runtime_rspec.heroku-22.log @@ -1,6 +1,6 @@ test/spec/blackfire-buildpackagent_spec.rb:100 test/spec/blackfire-herokuagent_spec.rb:120 -test/spec/bugs_spec.rb:30 +test/spec/bugs_spec.rb:40 test/spec/ci_frameworks-a_spec.rb:120 test/spec/ci_frameworks-k_spec.rb:120 test/spec/ci_spec.rb:125 @@ -14,21 +14,21 @@ test/spec/php-8.1_boot-apache2_spec.rb:65 test/spec/php-8.1_boot-nginx_spec.rb:55 test/spec/php-8.1_concurrency-apache2_spec.rb:70 test/spec/php-8.1_concurrency-nginx_spec.rb:65 -test/spec/php-8.1_sigterm-apache2_spec.rb:55 -test/spec/php-8.1_sigterm-nginx_spec.rb:55 +test/spec/php-8.1_sigterm-apache2_spec.rb:70 +test/spec/php-8.1_sigterm-nginx_spec.rb:70 test/spec/php-8.2_base_spec.rb:30 test/spec/php-8.2_boot-apache2_spec.rb:65 test/spec/php-8.2_boot-nginx_spec.rb:55 test/spec/php-8.2_concurrency-apache2_spec.rb:70 test/spec/php-8.2_concurrency-nginx_spec.rb:65 -test/spec/php-8.2_sigterm-apache2_spec.rb:55 -test/spec/php-8.2_sigterm-nginx_spec.rb:55 +test/spec/php-8.2_sigterm-apache2_spec.rb:70 +test/spec/php-8.2_sigterm-nginx_spec.rb:70 test/spec/php-8.3_base_spec.rb:30 test/spec/php-8.3_boot-apache2_spec.rb:65 test/spec/php-8.3_boot-nginx_spec.rb:55 test/spec/php-8.3_concurrency-apache2_spec.rb:70 test/spec/php-8.3_concurrency-nginx_spec.rb:65 -test/spec/php-8.3_sigterm-apache2_spec.rb:55 -test/spec/php-8.3_sigterm-nginx_spec.rb:55 +test/spec/php-8.3_sigterm-apache2_spec.rb:70 +test/spec/php-8.3_sigterm-nginx_spec.rb:70 test/spec/php_default_spec.rb:60 test/spec/platform_spec.rb:60 From 4ab70d2cef217e847c657c578cd845d74f226ba2 Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Thu, 7 Mar 2024 17:01:50 +0100 Subject: [PATCH 16/17] Write runtime log to test/var/log/ It's where it belongs really (gets .gitignore-d there, too). --- .github/workflows/ci.yml | 2 +- .rspec_parallel | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 3e68edde02..eea3e7921f 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -60,4 +60,4 @@ jobs: - name: Print list of executed examples run: cat test/var/log/group.*.json | jq -r --slurp '[.[].examples[]] | sort_by(.id) | flatten[] | .full_description' - name: Print parallel_runtime_rspec.log - run: cat parallel_runtime_rspec.log | grep -E '^test/spec/[a-z0-9_/\.-]+\.rb:[0-9]+\.[0-9]+$' | sort + run: cat test/var/log/parallel_runtime_rspec.log | grep -E '^test/spec/[a-z0-9_/\.-]+\.rb:[0-9]+\.[0-9]+$' | sort diff --git a/.rspec_parallel b/.rspec_parallel index 3694d423c3..75bd2164e1 100644 --- a/.rspec_parallel +++ b/.rspec_parallel @@ -1,3 +1,3 @@ --format progress --format json --out test/var/log/group.<%= "%02d" % ENV["TEST_ENV_NUMBER"] %>.json ---format ParallelTests::RSpec::RuntimeLogger --out parallel_runtime_rspec.log +--format ParallelTests::RSpec::RuntimeLogger --out test/var/log/parallel_runtime_rspec.log From f30760279286f96e290ccf2f36e8befd0fb4a00e Mon Sep 17 00:00:00 2001 From: David Zuelke Date: Fri, 8 Mar 2024 01:58:17 +0100 Subject: [PATCH 17/17] drop outdated comment obsolete since fb2858563390c33863465a46fca6a7e0c04449a2 --- test/var/log/README.md | 2 -- 1 file changed, 2 deletions(-) diff --git a/test/var/log/README.md b/test/var/log/README.md index 76c9982ece..4bee4f9f98 100644 --- a/test/var/log/README.md +++ b/test/var/log/README.md @@ -3,5 +3,3 @@ The `parallel_runtime_rspec.*.log` files in this directory are here on purpose. They're test runtime logs generated by `parallel_tests`, and they are output at the end of a run. They should, for each stack, periodically be copied from the test run logs and updated here in the repository, so that balanced grouping of test runs works well for minimal execution time. - -It's important to include all spec files from the code in the list. You must fake entries if needed for files that are skipped completely (like the PHP series tests, which don't all run on every stack). Otherwise, parallel_tests will not balance things correctly - the --unknown-runtime=1 flag does not work.