Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Massive performance degragation 3.0 -> 3.0.2 #140

Closed
mscrivo opened this issue Aug 12, 2024 · 9 comments · Fixed by #142
Closed

Massive performance degragation 3.0 -> 3.0.2 #140

mscrivo opened this issue Aug 12, 2024 · 9 comments · Fixed by #142

Comments

@mscrivo
Copy link

mscrivo commented Aug 12, 2024

After upgrading from 3.0 to 3.0.2, we notice crashes during startup in our test environment. The pods were using an order of magnitude more CPU on startup than before. Upon profiling, we saw this:

Time since start: 13s. Press Ctrl+C to stop.
Summary of profiling data so far:
% self  % total  name
 90.78    90.78  initialize [c function] - (unknown)
  1.55     1.55  initialize_pattern - /usr/local/lib/ruby/3.3.0/uri/rfc2396_parser.rb:493
  1.38    93.02  initialize_regexp - /usr/local/lib/ruby/3.3.0/uri/rfc2396_parser.rb:525
  1.03    99.31  new [c function] - (unknown)
  0.69     0.69  split [c function] - (unknown)
  0.60     0.86  each_value [c function] - (unknown)
  0.34    99.48  each [c function] - (unknown)
  0.34     0.34  freeze [c function] - (unknown)
  0.34     0.34  compile_file [c function] - (unknown)
  0.26    97.93  translate - /home/app/vendor/bundle/ruby/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:117
  0.26    95.78  initialize - /usr/local/lib/ruby/3.3.0/uri/rfc2396_parser.rb:107
  0.17    97.93  t - /home/app/vendor/bundle/ruby/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:43
  0.17    97.16  map [c function] - (unknown)
  0.17     0.17  sysread_nonblock [c function] - (unknown)
  0.17     0.17  select [c function] - (unknown)
  0.17     0.17  count_objects [c function] - (unknown)
  0.09    99.31  inject [c function] - (unknown)
  0.09    96.21  escape - /home/app/vendor/bundle/ruby/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:124
  0.09     0.43  fetch [c function] - (unknown)
  0.09     0.17  each_byte [c function] - (unknown)

and this is what our CPU usage looked like before, after upgrade, and after reverting:
image

We don't use mustermann explicitly, just implicitly via usage of sinatra.

Some notes about our env:

Ruby 3.3.3 with YJIT enabled running in x64 docker image
latest Sinatra + Puma versions

@dentarg
Copy link
Member

dentarg commented Aug 12, 2024

@hsbt any idea?

@hsbt
Copy link
Contributor

hsbt commented Aug 13, 2024

I will look at next week.

@dentarg
Copy link
Member

dentarg commented Aug 13, 2024

@mscrivo do you see the same without YJIT? How does 3.3.4 behave?

@mscrivo
Copy link
Author

mscrivo commented Aug 13, 2024

Ah I misspoke, we're already using 3.3.4. I'll have to put together a test with the new version and YJIT disabled, or try and see if I can repro on my dev machine. Will let you know if I have anything interesting to share on that front.

@travisbell
Copy link

Just chiming in that we also have this problem with 3.0.2, so I've locked things to 3.0.1 until 3.0.3 is released.

@ericproulx
Copy link
Contributor

ericproulx commented Sep 1, 2024

I've noticed the same issue within Grape which depends on mustermann-grape. While profiling some code, I found that the memory allocation skyrocketed from 2.0.2 to 3.0.2

mustermann 2.0.2
Total allocated: 13844660 bytes (151009 objects)
Total retained:  478500 bytes (1419 objects)

mustermann 3.0.0
Total allocated: 13844660 bytes (151009 objects)
Total retained:  478500 bytes (1419 objects)

mustermann 3.0.1
Total allocated: 112875956 bytes (312625 objects)
Total retained:  478500 bytes (1419 objects)

mustermann 3.0.2
Total allocated: 310938548 bytes (635857 objects)
Total retained:  478500 bytes (1419 objects)


allocated memory by location
-----------------------------------
46772544  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:504
36381072  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:500
33332208  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:501
22451520  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:505
21656544  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:506
12544896  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:515
10015824  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:520
9832368  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:451
8290464  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:519
6473376  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:453
5346432  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:473
5263440  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:517
5136768  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:448
4599504  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:521
4599504  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:522
4590768  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:446
4333056  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:339
4333056  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:497
4018560  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:441
3922464  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:518
3900624  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:514
3524976  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:513
3468192  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:510
2891616  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:516
2856672  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:509
2795520  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:419
2795520  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:424
2795520  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:438
2321000  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:106
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:388
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:394
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:398
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:402
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:416
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:434
1397760  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:436
990720  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/parser.rb:129
931840  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:292
731240  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:42
698880  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:386
698880  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:414
698880  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:443
698880  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:99
582400  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/compiler.rb:17
570752  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:123
511489  /Users/eproulx/code/grape/lib/grape/router/base_route.rb:26
467344  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:108
432840  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/compiler.rb:129
411480  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/mustermann-3.0.2/lib/mustermann/ast/translator.rb:114
349440  /Users/eproulx/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/uri-0.13.1/lib/uri/rfc2396_parser.rb:296

You can execute a complete memory profiler from this script

require 'grape'
require 'memory_profiler'

class API < Grape::API
  default_format :json

  params do
    requires :name, allow_blank: false
  end
  get '/disallow_blank'

  params do
    optional :name, type: String, allow_blank: false
  end
  get '/opt_disallow_string_blank'

  params do
    optional :name, allow_blank: false
  end
  get '/disallow_blank_optional_param'

  params do
    requires :name, allow_blank: true
  end
  get '/allow_blank'

  params do
    requires :val, type: DateTime, allow_blank: true
  end
  get '/allow_datetime_blank'

  params do
    requires :val, type: DateTime, allow_blank: false
  end
  get '/disallow_datetime_blank'

  params do
    requires :val, type: DateTime
  end
  get '/default_allow_datetime_blank'

  params do
    requires :val, type: Date, allow_blank: true
  end
  get '/allow_date_blank'

  params do
    requires :val, type: Integer, allow_blank: true
  end
  get '/allow_integer_blank'

  params do
    requires :val, type: Float, allow_blank: true
  end
  get '/allow_float_blank'

  params do
    requires :val, type: Integer, allow_blank: true
  end
  get '/allow_integer_blank'

  params do
    requires :val, type: Symbol, allow_blank: true
  end
  get '/allow_symbol_blank'

  params do
    requires :val, type: Grape::API::Boolean, allow_blank: true
  end
  get '/allow_boolean_blank'

  params do
    requires :val, type: Grape::API::Boolean, allow_blank: false
  end
  get '/disallow_boolean_blank'

  params do
    optional :user, type: Hash do
      requires :name, allow_blank: false
    end
  end
  get '/disallow_blank_required_param_in_an_optional_group'

  params do
    optional :user, type: Hash do
      requires :name, type: Date, allow_blank: true
    end
  end
  get '/allow_blank_date_param_in_an_optional_group'

  params do
    optional :user, type: Hash do
      optional :name, allow_blank: false
      requires :age
    end
  end
  get '/disallow_blank_optional_param_in_an_optional_group'

  params do
    requires :user, type: Hash do
      requires :name, allow_blank: false
    end
  end
  get '/disallow_blank_required_param_in_a_required_group'

  params do
    requires :user, type: Hash do
      requires :name, allow_blank: false
    end
  end
  get '/disallow_string_value_in_a_required_hash_group'

  params do
    requires :user, type: Hash do
      optional :name, allow_blank: false
    end
  end
  get '/disallow_blank_optional_param_in_a_required_group'

  params do
    optional :user, type: Hash do
      optional :name, allow_blank: false
    end
  end
  get '/disallow_string_value_in_an_optional_hash_group'

  resources :custom_message do
    params do
      requires :name, allow_blank: { value: false, message: 'has no value' }
    end
    get

    params do
      optional :name, allow_blank: { value: false, message: 'has no value' }
    end
    get '/disallow_blank_optional_param'

    params do
      requires :name, allow_blank: true
    end
    get '/allow_blank'

    params do
      requires :val, type: DateTime, allow_blank: true
    end
    get '/allow_datetime_blank'

    params do
      requires :val, type: DateTime, allow_blank: { value: false, message: 'has no value' }
    end
    get '/disallow_datetime_blank'

    params do
      requires :val, type: DateTime
    end
    get '/default_allow_datetime_blank'

    params do
      requires :val, type: Date, allow_blank: true
    end
    get '/allow_date_blank'

    params do
      requires :val, type: Integer, allow_blank: true
    end
    get '/allow_integer_blank'

    params do
      requires :val, type: Float, allow_blank: true
    end
    get '/allow_float_blank'

    params do
      requires :val, type: Integer, allow_blank: true
    end
    get '/allow_integer_blank'

    params do
      requires :val, type: Symbol, allow_blank: true
    end
    get '/allow_symbol_blank'

    params do
      requires :val, type: Grape::API::Boolean, allow_blank: true
    end
    get '/allow_boolean_blank'

    params do
      requires :val, type: Grape::API::Boolean, allow_blank: { value: false, message: 'has no value' }
    end
    get '/disallow_boolean_blank'

    params do
      optional :user, type: Hash do
        requires :name, allow_blank: { value: false, message: 'has no value' }
      end
    end
    get '/disallow_blank_required_param_in_an_optional_group'

    params do
      optional :user, type: Hash do
        requires :name, type: Date, allow_blank: true
      end
    end
    get '/allow_blank_date_param_in_an_optional_group'

    params do
      optional :user, type: Hash do
        optional :name, allow_blank: { value: false, message: 'has no value' }
        requires :age
      end
    end
    get '/disallow_blank_optional_param_in_an_optional_group'

    params do
      requires :user, type: Hash do
        requires :name, allow_blank: { value: false, message: 'has no value' }
      end
    end
    get '/disallow_blank_required_param_in_a_required_group'

    params do
      requires :user, type: Hash do
        requires :name, allow_blank: { value: false, message: 'has no value' }
      end
    end
    get '/disallow_string_value_in_a_required_hash_group'

    params do
      requires :user, type: Hash do
        optional :name, allow_blank: { value: false, message: 'has no value' }
      end
    end
    get '/disallow_blank_optional_param_in_a_required_group'

    params do
      optional :user, type: Hash do
        optional :name, allow_blank: { value: false, message: 'has no value' }
      end
    end
    get '/disallow_string_value_in_an_optional_hash_group'
  end
end

report = MemoryProfiler.report do
  API.compile!
end

report.pretty_print

@dentarg
Copy link
Member

dentarg commented Sep 1, 2024

Anyone in this thread that want this fixed please help at #141 (comment)

@dentarg
Copy link
Member

dentarg commented Sep 3, 2024

v3.0.3 released with fix, please report back if it has resolved your issues!

@ericproulx
Copy link
Contributor

It resolved our issue :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
5 participants