thoughtbot / json_matchers

Validate your JSON APIs
MIT License
385 stars 40 forks source link

Slowdown of specs with release 0.11.1 #101

Open jovanmaric opened 5 years ago

jovanmaric commented 5 years ago

After updating from 0.10.0 to 0.11.1 I noticed my specs slowing down from 1 minute to 1.5 minutes. I've done some profiling to verify this:

0.10.0 - rubyprof

Measure Mode: wall_time
Thread ID: 47026346392080
Fiber ID: 47026383823100
Total: 87.553599
Sort by: self_time

 %self      total      self      wait     child     calls  name                           location
 24.81     22.188    21.722     0.467     0.000       42   IO#eof?                        
  7.56      8.087     6.618     0.000     1.469  1561068   JsonSchema::Parser#validate_type /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/parser.rb:364
  3.50      4.236     3.066     0.000     1.170      558   ValidEmail2::Address#domain_is_in? /usr/local/bundle/gems/valid_email2-3.0.3/lib/valid_email2/address.rb:71
  3.40      2.974     2.974     0.000     0.000     9651   PG::Connection#exec_params     
  1.95     14.138     1.707     0.000    12.430    43363  *JsonSchema::Parser#parse_schema /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/parser.rb:270
  1.90      1.662     1.662     0.000     0.000    10121   PG::Connection#async_exec      
  1.33      1.165     1.165     0.000     0.000  8594852   String#end_with?               
  1.07      1.325     0.938     0.000     0.386    49560   JsonSchema::Attributes#initialize_attrs /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:111
  1.01      0.890     0.882     0.000     0.008  1573202   Array#join                     

0.11.1 - rubyprof

Measure Mode: wall_time
Thread ID: 47380564785680
Fiber ID: 47380601697300
Total: 128.424518
Sort by: self_time

 %self      total      self      wait     child     calls  name                           location
 17.00     21.833    21.833     0.000     0.000       42   IO#eof?                        
  9.04     41.953    11.616     0.000    30.337  1548031  *JsonSchema::ReferenceExpander#schema_children /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/reference_expander.rb:284
  4.97      7.839     6.385     0.000     1.454  1561068   JsonSchema::Parser#validate_type /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/parser.rb:364
  3.58      5.061     4.599     0.000     0.462  4440878  *JsonSchema::Schema#pointer     /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/schema.rb:265
  2.55     38.187     3.269     0.000    34.917  1657881  *JsonSchema::ReferenceExpander#build_schema_paths /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/reference_expander.rb:68
  2.40      4.098     3.088     0.000     1.010  3182788   JsonSchema::Schema#links       /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  2.36      4.232     3.031     0.000     1.202      558   ValidEmail2::Address#domain_is_in? /usr/local/bundle/gems/valid_email2-3.0.3/lib/valid_email2/address.rb:71
  2.32      2.979     2.979     0.000     0.000 17033822   Kernel#instance_variable_get   
  2.28      2.933     2.933     0.000     0.000     9651   PG::Connection#exec_params     
  1.44      1.846     1.846     0.000     0.000 12433267   Kernel#nil?                    
  1.38      2.376     1.770     0.000     0.606  1635324   JsonSchema::Schema#all_of      /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.30      2.175     1.675     0.000     0.500  1634983   JsonSchema::Schema#dependencies /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.30      1.675     1.675     0.000     0.000    10129   PG::Connection#async_exec      
  1.29      2.161     1.654     0.000     0.507  1646378   JsonSchema::Schema#definitions /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.28      2.180     1.647     0.000     0.533  1624970   JsonSchema::Schema#additional_properties /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.26      2.128     1.615     0.000     0.513  1735069   JsonSchema::Schema#properties  /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.21      2.071     1.557     0.000     0.514  1635324   JsonSchema::Schema#any_of      /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.20      2.110     1.546     0.000     0.565  1635639   JsonSchema::Schema#pattern_properties /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40
  1.20     13.612     1.545     0.000    12.068    43363  *JsonSchema::Parser#parse_schema /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/parser.rb:270
  1.19      2.039     1.530     0.000     0.509  1635324   JsonSchema::Schema#one_of      /usr/local/bundle/gems/json_schema-0.20.7/lib/json_schema/attributes.rb:40

I do not have any other projects with over 1000 examples to test this on unfortunately. I've looked at the changes from 0.10.0 and i'm not entirely sure what is causing this.

Has anyone noticed any slowdown as well?

Volosh1n commented 4 years ago

Faced this issue too. At first glance, I think this changes probably cause this slowdown (since there were no other global changes in slower version).

maschiner commented 3 years ago

Ran into the same issue today, specs slowing down from 5 to 13 minutes.

I managed to resolve it with a little patch, might be useful for somebody else:

module JsonMatchers
  class Matcher
    def initialize(schema_path)
      @schema_path = schema_path
      # prevent reloading document_store for every instance, ref: https://github.com/thoughtbot/json_matchers/issues/101
      @@document_store ||= build_and_populate_document_store
      @document_store = @@document_store
    end
  end
end