Test timing analysis

[BuonOmo]

Step 1, stackprof analysis

Analysing with stackprof, we get the confirmation that test slowness comes from sql requests:

==================================
  Mode: wall(1000)
  Samples: 86133 (0.01% miss rate)
  GC: 38 (0.04%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
     66436  (77.1%)       66436  (77.1%)     PG::Connection#exec_params
     18559  (21.5%)       18559  (21.5%)     PG::Connection#exec

Looking up the callers of #exec_params we can see

$ stackprof --method 'ActiveRecord::ConnectionAdapters::AbstractAdapter#exec_query'
  samples:     1 self (0.0%)  /   67165 total (78.0%)
  callers:
    67040  (   99.8%)  ActiveRecord::ConnectionAdapters::CockroachDB::SchemaStatements#foreign_keys
      77  (    0.1%)  block in <class:AdapterTestWithoutTransaction>
      48  (    0.1%)  CockroachDB::AdapterTestWithoutTransaction#test_reset_empty_table_with_custom_pk_sequence

the #foreign_keys method seems to be the outlier by far. And the foreign key method is itself mostly called by #disable_referential_integrity:

  samples:     9 self (0.0%)  /   67150 total (78.0%)
  callers:
    57264  (   85.3%)  ActiveRecord::ConnectionAdapters::CockroachDB::ReferentialIntegrity#disable_referential_integrity
    9886  (   14.7%)  ActiveRecord::ConnectionAdapters::SchemaStatements#foreign_key_for

And the method that seems to make most extensive calls for this is #reset_fixtures. Indeed, #reset_fixtures is looping over an array of features, and for each calling #create_fixtures, which itself calls #disable_referential_integrity. Hence we call #disable_referential_integrity once per feature. This is very costly. We could already try to refactor this out of the loop. By looking further in the codebase, this is at most a 3 items array, there might be a better option.

Step 2, stackprof analysis without #disable_referential_integrity

If we change #disable_referential_integrity to be a noop, we have a new interesting stackprof result. First, the test time is divided by 4. So there is something to do here. And then, the SchemaTest#setup method is now taking 9.5% of the test time:

https://github.com/cockroachdb/activerecord-cockroachdb-adapter/blob/0fe24278c1512253459729cf50b5a1e917c2cd40/test/excludes/SchemaTest.rb#L17

Hence this could be the next thing to tackle.

Besides that it seems like there is no specific local code to optimize:

 `bundle exec stackprof --files stack.dump`.
  split("\n").
  map { _1[%r(/\s+(\d+).*(/home/runner.*))]; [$1.to_i, $2] }.
  group_by { |count, file| file ?
file["vendor"] ? :vendor : file[".rubies"] ? :ruby : file : :c }.
  transform_values { |ary| ary.sum{|count,file|count} }.then { jj _1 }
# {
#   "vendor": 7866,
#   "c": 0,
#   ".../test/cases/helper_cockroachdb.rb": 191,
#   "ruby": 157,
#   ".../lib/active_record/connection_adapters/cockroachdb/schema_statements.rb": 148
# }

This means that 94% of the samples are coming from the activerecord stack. With that said, most of these samples actually are happening while waiting for a sql query. If we isolate the only file sampled within the adapter lib:

 260738  ( 22.9%) /   148  (  0.0%)   /home/runner/work/activerecord-cockroachdb-adapter/activerecord-cockroachdb-adapter/lib/active_record/connection_adapters/cockroachdb/schema_statements.rb

We see that it still takes an active part of the samples (23%) are of its callees. Also there might be some inefficient queries in our codebase. However, within this file, the only homemade query that hits some sampling is the query in #foreign_keys. We should look at optimizing it as it is a frequently used method.

On trying to reduce calls to disable_referential_integrity

when do we #disable_referential_integrity?

• ActiveRecord::ConnectionAdapters::CockroachDB::DatabaseStatements#insert_fixtures_set
• CockroachDB::FixturesTest#before_setup
• CockroachDB::FixturesResetPkSequenceTest#teardown
• CockroachDB::AdapterTestWithoutTransaction#reset_fixtures
• In the generic schema creation in activerecord (might not be needed)
• DatabaseStatements#truncate_tables
• referential_integrity_test.rb
• AdapterForeignKeyTest#test_disable_referential_integrity

Ideas

Analysis:

• review logs https://www.cockroachlabs.com/docs/v23.2/local-testing#log-test-output-to-a-file
• review query times (already in test artifacts due to this PR)