Merge pull request #706 from heroku/ci-herokurun-speedups

CI speed-ups

GUS-W-15212157

.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
+        run: cat test/var/log/parallel_runtime_rspec.log | grep -E '^test/spec/[a-z0-9_/\.-]+\.rb:[0-9]+\.[0-9]+$' | sort

.rspec_parallel

@@ -1,2 +1,3 @@
 --format progress
---format ParallelTests::RSpec::RuntimeLogger --out parallel_runtime_rspec.log
+--format json --out test/var/log/group.<%= "%02d" % ENV["TEST_ENV_NUMBER"] %>.json
+--format ParallelTests::RSpec::RuntimeLogger --out test/var/log/parallel_runtime_rspec.log

test/fixtures/ci/zendassert/test.php

@@ -1,4 +1,10 @@
 <?php
 
 ini_set("assert.exception", 1);
-assert(true == false, "Expected true to be false");
+
+try {
+	assert(true == false, "Expected true to be false");
+	exit(1);
+} catch(AssertionError $e) {
+	fputs(STDERR, "Caught expected AssertionError");
+}

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 <up></up>
-							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 <up></up>
+						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

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

test/spec/ci_frameworks_spec.rb → 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

test/spec/ci_spec.rb

@@ -11,11 +11,11 @@
 		end
 	end
 
-	it "has zend.assertions enabled" do
-		app = new_app_with_stack_and_platrepo('test/fixtures/ci/zendassert', allow_failure: true)
+	it "has zend.assertions enabled and auto-runs a composer.json 'test' script entry" do
+		app = new_app_with_stack_and_platrepo('test/fixtures/ci/zendassert')
 		app.run_ci do |test_run|
-			expect(test_run.status).to eq :failed
-			expect(test_run.output).to match("AssertionError")
+			expect(test_run.output).to match("Script 'composer test' found, executing...")
+			expect(test_run.output).to match("Caught expected AssertionError")
 		end
 	end
 
@@ -26,15 +26,4 @@
 			expect(test_run.output).to match("No tests found.")
 		end
 	end
-
-	context "specifying a composer.json 'test' script entry" do
-		let(:app) {
-			new_app_with_stack_and_platrepo('test/fixtures/ci/composertest')
-		}
-		it "executes 'composer test'" do
-			app.run_ci do |test_run|
-				expect(test_run.output).to match("Script 'composer test' found, executing...")
-			end
-		end
-	end
 end

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

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