Skip to content

Commit 96a5a87

Browse files
authored
speed up unit tests (#5137)
1 parent 0e8d3b7 commit 96a5a87

13 files changed

Lines changed: 247 additions & 130 deletions

.github/workflows/unit_tests.yml

Lines changed: 46 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,11 @@ concurrency:
44
cancel-in-progress: true
55
on:
66
workflow_dispatch:
7+
inputs:
8+
rspec_profile:
9+
description: 'Top N slowest examples to print (rspec --profile), e.g. 20. Leave blank to disable.'
10+
required: false
11+
default: ''
712
pull_request:
813
branches: [ main ]
914
paths-ignore:
@@ -49,6 +54,12 @@ jobs:
4954
image: ${{ matrix.image }}
5055
env:
5156
POSTGRES_PASSWORD: rootpassword
57+
# Test-only durability tuning: skip the work that backs durability.
58+
command: >-
59+
postgres
60+
-c fsync=off
61+
-c synchronous_commit=off
62+
-c full_page_writes=off
5263
options: >-
5364
--tmpfs /var/lib/postgresql/data:rw,size=2g
5465
--health-cmd pg_isready
@@ -61,8 +72,22 @@ jobs:
6172
- uses: hmarr/debug-action@v3
6273
- uses: actions/checkout@v6
6374
- uses: ./.github/workflows/composite/setup
75+
- name: Restore parallel_rspec runtime logs
76+
uses: actions/cache/restore@v4
77+
with:
78+
path: tmp/parallel_runtime_rspec_*.log
79+
key: parallel-runtime-postgres-${{ matrix.image }}-${{ github.run_id }}
80+
restore-keys: |
81+
parallel-runtime-postgres-${{ matrix.image }}-
82+
parallel-runtime-postgres-
6483
- name: Run tests
65-
run: DB=postgres POSTGRES_CONNECTION_PREFIX="postgres://postgres:rootpassword@localhost:5432" bundle exec rake spec
84+
run: DB=postgres POSTGRES_CONNECTION_PREFIX="postgres://postgres:rootpassword@localhost:5432" RSPEC_PROFILE="${{ inputs.rspec_profile }}" bundle exec rake spec
85+
- name: Save parallel_rspec runtime logs
86+
if: always()
87+
uses: actions/cache/save@v4
88+
with:
89+
path: tmp/parallel_runtime_rspec_*.log
90+
key: parallel-runtime-postgres-${{ matrix.image }}-${{ github.run_id }}
6691
- uses: ravsamhq/notify-slack-action@v2
6792
if: github.event_name == 'push'
6893
with:
@@ -84,6 +109,11 @@ jobs:
84109
env:
85110
MYSQL_DATABASE: cc_test
86111
MYSQL_ROOT_PASSWORD: password
112+
# Test-only durability tuning: skip the redo/binlog/doublewrite work.
113+
command: >-
114+
--innodb-flush-log-at-trx-commit=0
115+
--sync-binlog=0
116+
--innodb-doublewrite=OFF
87117
options: >-
88118
--tmpfs /var/lib/mysql:rw,size=2g
89119
--health-cmd="mysqladmin ping"
@@ -96,8 +126,22 @@ jobs:
96126
- uses: hmarr/debug-action@v3
97127
- uses: actions/checkout@v6
98128
- uses: ./.github/workflows/composite/setup
129+
- name: Restore parallel_rspec runtime logs
130+
uses: actions/cache/restore@v4
131+
with:
132+
path: tmp/parallel_runtime_rspec_*.log
133+
key: parallel-runtime-mysql-${{ matrix.image }}-${{ github.run_id }}
134+
restore-keys: |
135+
parallel-runtime-mysql-${{ matrix.image }}-
136+
parallel-runtime-mysql-
99137
- name: Run tests
100-
run: DB=mysql MYSQL_CONNECTION_PREFIX="mysql2://root:password@127.0.0.1:3306" bundle exec rake spec
138+
run: DB=mysql MYSQL_CONNECTION_PREFIX="mysql2://root:password@127.0.0.1:3306" RSPEC_PROFILE="${{ inputs.rspec_profile }}" bundle exec rake spec
139+
- name: Save parallel_rspec runtime logs
140+
if: always()
141+
uses: actions/cache/save@v4
142+
with:
143+
path: tmp/parallel_runtime_rspec_*.log
144+
key: parallel-runtime-mysql-${{ matrix.image }}-${{ github.run_id }}
101145
- uses: ravsamhq/notify-slack-action@v2
102146
if: github.event_name == 'push'
103147
with:

.rspec_parallel

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,5 +2,4 @@
22
--format RSpec::Instafail
33
--format progress
44
--format ParallelTests::RSpec::SummaryLogger --out tmp/spec_summary.log
5-
--format ParallelTests::RSpec::RuntimeLogger --out tmp/parallel_runtime_rspec.log
65
--order rand

.rubocop_cc.yml

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,7 @@ Metrics/BlockLength:
4747
- config/routes.rb
4848
- lib/tasks/db.rake
4949
- lib/tasks/jobs.rake
50+
- lib/tasks/spec.rake
5051
Max: 50
5152
Metrics/CyclomaticComplexity:
5253
Max: 12

lib/tasks/spec.rake

Lines changed: 20 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ namespace :spec do
77
run_specs(ARGV[1])
88
else
99
run_specs_parallel('spec')
10-
# Run isolated specs separately since they might affect other tests
10+
run_migration_specs_parallel
1111
run_specs('spec/isolated_specs')
1212
end
1313
end
@@ -32,6 +32,7 @@ namespace :spec do
3232
run_specs(ARGV[1], 'NO_DB_MIGRATION=true')
3333
else
3434
run_specs_parallel('spec', 'NO_DB_MIGRATION=true')
35+
run_migration_specs_parallel('NO_DB_MIGRATION=true')
3536
# Run isolated specs separately since they might affect other tests
3637
run_specs('spec/isolated_specs', 'NO_DB_MIGRATION=true')
3738
end
@@ -44,17 +45,33 @@ namespace :spec do
4445
def run_specs_parallel(path, env_vars='')
4546
command = <<~CMD
4647
#{env_vars} bundle exec parallel_rspec \
47-
--test-options '--order rand' \
48+
--test-options '--order rand #{rspec_profile_option} --format ParallelTests::RSpec::RuntimeLogger --out tmp/parallel_runtime_rspec_main.log' \
49+
--runtime-log tmp/parallel_runtime_rspec_main.log \
4850
--single spec/integration/ \
4951
--single spec/acceptance/ \
5052
--isolate \
51-
--exclude-pattern 'spec/isolated_specs/' \
53+
--exclude-pattern '(spec/isolated_specs/|spec/migrations/)' \
5254
-- #{path}
5355
CMD
5456

5557
sh command
5658
end
5759

60+
def run_migration_specs_parallel(env_vars='')
61+
command = <<~CMD
62+
#{env_vars} bundle exec parallel_rspec \
63+
--test-options '--order rand #{rspec_profile_option} --format ParallelTests::RSpec::RuntimeLogger --out tmp/parallel_runtime_rspec_migrations.log' \
64+
--runtime-log tmp/parallel_runtime_rspec_migrations.log \
65+
-- spec/migrations
66+
CMD
67+
68+
sh command
69+
end
70+
71+
def rspec_profile_option
72+
ENV['RSPEC_PROFILE'].to_s.empty? ? '' : "--profile #{ENV.fetch('RSPEC_PROFILE', nil)}"
73+
end
74+
5875
def run_failed_specs
5976
sh 'bundle exec rspec --only-failures --color --tty spec --require rspec/instafail --format RSpec::Instafail'
6077
end

spec/migrations/helpers/bigint_migration_step1_shared_context.rb

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3,13 +3,13 @@
33
require 'database/bigint_migration'
44

55
RSpec.shared_context 'bigint migration step1' do
6+
before(:all) { skip unless Sequel::Model.db.database_type == :postgres } # rubocop:disable RSpec/BeforeAfterAll
7+
68
include_context 'migration'
79

810
let(:skip_bigint_id_migration) { nil }
911

1012
before do
11-
skip unless db.database_type == :postgres
12-
1313
allow_any_instance_of(VCAP::CloudController::Config).to receive(:get).with(:skip_bigint_id_migration).and_return(skip_bigint_id_migration)
1414
allow_any_instance_of(VCAP::CloudController::Config).to receive(:get).with(:migration_psql_concurrent_statement_timeout_in_seconds).and_return(300)
1515
end

spec/migrations/helpers/bigint_migration_step3_shared_context.rb

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,8 @@
33
require 'database/bigint_migration'
44

55
RSpec.shared_context 'bigint migration step3a' do
6+
before(:all) { skip unless Sequel::Model.db.database_type == :postgres } # rubocop:disable RSpec/BeforeAfterAll
7+
68
let(:migration_filename) { migration_filename_step1 }
79
let(:current_migration_index_step3a) { migration_filename_step3a.match(/\A\d+/)[0].to_i }
810

@@ -12,8 +14,6 @@
1214
let(:logger) { double(:logger, info: nil) }
1315

1416
before do
15-
skip unless db.database_type == :postgres
16-
1717
allow_any_instance_of(VCAP::CloudController::Config).to receive(:get).with(:skip_bigint_id_migration).and_return(skip_bigint_id_migration)
1818
allow_any_instance_of(VCAP::CloudController::Config).to receive(:get).with(:migration_psql_concurrent_statement_timeout_in_seconds).and_return(300)
1919
end
@@ -107,6 +107,8 @@
107107
end
108108

109109
RSpec.shared_context 'bigint migration step3b' do
110+
before(:all) { skip unless Sequel::Model.db.database_type == :postgres } # rubocop:disable RSpec/BeforeAfterAll
111+
110112
let(:migration_filename) { migration_filename_step1 }
111113
let(:current_migration_index_step3a) { migration_filename_step3a.match(/\A\d+/)[0].to_i }
112114
let(:current_migration_index_step3b) { migration_filename_step3b.match(/\A\d+/)[0].to_i }
@@ -117,8 +119,6 @@
117119
let(:logger) { double(:logger, info: nil) }
118120

119121
before do
120-
skip unless db.database_type == :postgres
121-
122122
allow_any_instance_of(VCAP::CloudController::Config).to receive(:get).with(:skip_bigint_id_migration).and_return(skip_bigint_id_migration)
123123
allow_any_instance_of(VCAP::CloudController::Config).to receive(:get).with(:migration_psql_concurrent_statement_timeout_in_seconds).and_return(300)
124124
end

spec/support/database_isolation.rb

Lines changed: 47 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -8,20 +8,61 @@ def self.choose(isolation, db)
88
end
99
end
1010

11+
# Sequel logger that records which tables an example wrote to, so we can truncate only those.
12+
# Schema-qualified writes (e.g. INSERT INTO public.users) trigger a full truncate as a safe fallback.
13+
class WrittenTablesLogger
14+
WRITE_REGEX = /\b(?:INSERT INTO|UPDATE|DELETE FROM|TRUNCATE TABLE|TRUNCATE)\s+(\S+)/i
15+
16+
attr_reader :tables
17+
18+
def initialize
19+
@tables = Set.new
20+
@full_reset = false
21+
end
22+
23+
def full_reset?
24+
@full_reset
25+
end
26+
27+
def capture(msg)
28+
return unless msg =~ WRITE_REGEX
29+
30+
target = ::Regexp.last_match(1).delete('`"')
31+
if target.include?('.')
32+
@full_reset = true
33+
else
34+
@tables << target.to_sym
35+
end
36+
end
37+
38+
alias_method :info, :capture
39+
alias_method :warn, :capture
40+
alias_method :debug, :capture
41+
alias_method :error, :capture
42+
alias_method :fatal, :capture
43+
end
44+
1145
class TruncateTables
1246
def initialize(db)
1347
@db = db
1448
end
1549

1650
def cleanly
17-
yield
18-
ensure
19-
reset_tables
51+
logger = WrittenTablesLogger.new
52+
db.loggers << logger
53+
begin
54+
yield
55+
ensure
56+
db.loggers.delete(logger)
57+
tables = logger.full_reset? ? TableTruncator.isolated_tables(db) : logger.tables.to_a & TableTruncator.isolated_tables(db)
58+
reset_tables(tables)
59+
end
2060
end
2161

22-
def reset_tables
23-
table_truncator = TableTruncator.new(db)
24-
table_truncator.truncate_tables
62+
def reset_tables(tables)
63+
return if tables.empty?
64+
65+
TableTruncator.new(db, tables).truncate_tables
2566

2667
# VCAP::CloudController::Seeds requires the :api config
2768
TestConfig.context = :api

spec/unit/jobs/runtime/prune_completed_builds_spec.rb

Lines changed: 27 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
module VCAP::CloudController
44
module Jobs::Runtime
55
RSpec.describe PruneCompletedBuilds, job_context: :worker do
6-
let(:max_retained_builds_per_app) { 15 }
6+
let(:max_retained_builds_per_app) { 3 }
77

88
subject(:job) { PruneCompletedBuilds.new(max_retained_builds_per_app) }
99

@@ -19,67 +19,67 @@ module Jobs::Runtime
1919
it 'deletes all the staged builds over the limit' do
2020
expect(BuildModel.count).to eq(0)
2121

22-
total = 50
23-
(1..50).each do |i|
22+
total = 8
23+
(1..total).each do |i|
2424
BuildModel.make(id: i, state: BuildModel::STAGED_STATE, app: app, created_at: Time.now - total + i)
2525
end
2626

2727
job.perform
2828

29-
expect(BuildModel.count).to eq(15)
30-
expect(BuildModel.map(&:id)).to match_array((36..50).to_a)
29+
expect(BuildModel.count).to eq(3)
30+
expect(BuildModel.map(&:id)).to match_array((6..8).to_a)
3131
end
3232

3333
it 'deletes all failed builds over the limit' do
3434
expect(BuildModel.count).to eq(0)
3535

36-
total = 50
37-
(1..50).each do |i|
36+
total = 8
37+
(1..total).each do |i|
3838
BuildModel.make(id: i, state: BuildModel::FAILED_STATE, app: app, created_at: Time.now - total + i)
3939
end
4040

4141
job.perform
4242

43-
expect(BuildModel.count).to eq(15)
44-
expect(BuildModel.map(&:id)).to match_array((36..50).to_a)
43+
expect(BuildModel.count).to eq(3)
44+
expect(BuildModel.map(&:id)).to match_array((6..8).to_a)
4545
end
4646

4747
it 'does NOT delete any staging builds over the limit' do
4848
expect(BuildModel.count).to eq(0)
4949

50-
total = 50
51-
(1..50).each do |i|
50+
total = 8
51+
(1..total).each do |i|
5252
BuildModel.make(id: i, state: BuildModel::STAGING_STATE, app: app, created_at: Time.now - total + i)
5353
end
5454

5555
job.perform
5656

57-
expect(BuildModel.count).to eq(50)
58-
expect(BuildModel.map(&:id)).to match_array((1..50).to_a)
57+
expect(BuildModel.count).to eq(8)
58+
expect(BuildModel.map(&:id)).to match_array((1..8).to_a)
5959
end
6060

6161
it 'does not delete in-flight builds over the limit' do
62-
total = 60
63-
(1..20).each do |i|
62+
total = 12
63+
(1..4).each do |i|
6464
BuildModel.make(id: i, state: BuildModel::STAGED_STATE, app: app, created_at: Time.now - total + i)
6565
end
66-
(21..40).each do |i|
66+
(5..8).each do |i|
6767
BuildModel.make(id: i, state: BuildModel::STAGING_STATE, app: app, created_at: Time.now - total + i)
6868
end
69-
(41..60).each do |i|
69+
(9..12).each do |i|
7070
BuildModel.make(id: i, state: BuildModel::STAGED_STATE, app: app, created_at: Time.now - total + i)
7171
end
7272

7373
job.perform
7474

75-
expect(BuildModel.count).to be(35)
76-
expect(BuildModel.order(Sequel.asc(:created_at), Sequel.asc(:id)).map(&:id)).to eq((21..40).to_a + (46..60).to_a)
75+
expect(BuildModel.count).to be(7)
76+
expect(BuildModel.order(Sequel.asc(:created_at), Sequel.asc(:id)).map(&:id)).to eq((5..8).to_a + (10..12).to_a)
7777
end
7878

7979
it 'calls destroy on the BuildModel so association dependencies are respected' do
8080
expect(BuildModel.count).to eq(0)
8181

82-
50.times do
82+
8.times do
8383
b = BuildModel.make(state: BuildModel::STAGED_STATE, app: app)
8484
BuildpackLifecycleDataModel.make(build: b)
8585
end
@@ -97,22 +97,22 @@ module Jobs::Runtime
9797
expect(BuildModel.count).to eq(0)
9898

9999
[app, app_the_second, app_the_third].each_with_index do |current_app, app_index|
100-
total = 50
100+
total = 8
101101
(1..total).each do |i|
102102
BuildModel.make(id: i + (1000 * app_index), state: BuildModel::STAGED_STATE, app: current_app, created_at: Time.now - total + i)
103103
end
104104
end
105105

106106
job.perform
107107

108-
expect(BuildModel.where(app:).count).to eq(15)
109-
expect(BuildModel.where(app:).map(&:id)).to match_array((36..50).to_a)
108+
expect(BuildModel.where(app:).count).to eq(3)
109+
expect(BuildModel.where(app:).map(&:id)).to match_array((6..8).to_a)
110110

111-
expect(BuildModel.where(app: app_the_second).count).to eq(15)
112-
expect(BuildModel.where(app: app_the_second).map(&:id)).to match_array((1036..1050).to_a)
111+
expect(BuildModel.where(app: app_the_second).count).to eq(3)
112+
expect(BuildModel.where(app: app_the_second).map(&:id)).to match_array((1006..1008).to_a)
113113

114-
expect(BuildModel.where(app: app_the_third).count).to eq(15)
115-
expect(BuildModel.where(app: app_the_third).map(&:id)).to match_array((2036..2050).to_a)
114+
expect(BuildModel.where(app: app_the_third).count).to eq(3)
115+
expect(BuildModel.where(app: app_the_third).map(&:id)).to match_array((2006..2008).to_a)
116116
end
117117
end
118118

0 commit comments

Comments
 (0)