Skip to content
Rails 5.2 version of headius/pgrailsbench
Branch: master
Clone or download
Fetching latest commit…
Cannot retrieve the latest commit at this time.
Permalink
Type Name Latest commit message Commit time
Failed to load latest commit information.
app rails g scaffold post title:string body:text published:boolean Mar 16, 2019
bin Reset debug counter Apr 14, 2019
config Use secrets rather than credentials Mar 27, 2019
db Use fixed id to always make /posts/1 functional Mar 16, 2019
lib rails new railsbench --database=postgresql Mar 16, 2019
log 50k measure JIT, and JRuby again Mar 17, 2019
public rails new railsbench --database=postgresql Mar 16, 2019
storage rails new railsbench --database=postgresql Mar 16, 2019
test rails g scaffold post title:string body:text published:boolean Mar 16, 2019
tmp
vendor rails new railsbench --database=postgresql Mar 16, 2019
.gitignore Add profiling results Mar 17, 2019
Gemfile
Gemfile.lock Disable bootsnap Mar 19, 2019
MIT-LICENSE
README.md Note createdb for macOS Mar 26, 2019
Rakefile rails new railsbench --database=postgresql Mar 16, 2019
config.ru rails new railsbench --database=postgresql Mar 16, 2019
package.json rails new railsbench --database=postgresql Mar 16, 2019
yarn.lock Describe how to run server Mar 16, 2019

README.md

railsbench

Based on headius/pgrailsbench, but on Rails 5.2 and with database seeds.

What's this?

This application is generated by following commands:

rails new railsbench --database=postgresql
rails g scaffold post title:string body:text published:boolean

Setup

Make sure config/database.yml works for your local PostgreSQL. Replace "k0kubun" with your $USER in the following instructions.

# Linux
sudo apt install postgresql
sudo -u postgres psql
postgres=$ create role k0kubun superuser;
sudo vi /etc/postgresql/10/main/pg_hba.conf # Add `local all k0kubun trust`
sudo systemctl restart postgresql

# macOS
brew install postgresql
createdb railsbench_production

Populate database and assets for RAILS_ENV=production.

gem install bundler -v 2.0.1
bundle install
bundle exec rake db:create db:migrate db:seed RAILS_ENV=production
bundle exec rake assets:precompile RAILS_ENV=production

Run

# MRI
bundle exec puma -e production --workers=4 --threads=1 --preload

# JRuby, TruffleRuby
bundle exec puma -e production --threads=4

You can see posts on localhost:3000/posts.

Assets are not shown properly with -e production but it's intentional because Rails assumes we delegate assets distribution to a reverse proxy on production by default.

If you want to see the actual apprecation behavior, do the setup with RAILS_ENV=development and try puma -e development.

Benchmark

Install Apache Bench with sudo apt install apache2-utils. Then:

# HTML posts#index
ab -c 4 -n 10000 localhost:3000/posts

# JSON posts#index
ab -c 4 -n 10000 localhost:3000/posts.json

# HTML posts#show
ab -c 4 -n 10000 localhost:3000/posts/1

# JSON posts#show
ab -c 4 -n 10000 localhost:3000/posts/1.json

50k Benchmark Results

Here is the benchmark result on: Intel 4.0GHz i7-4790K, 16GB memory, x86-64 Ubuntu 8 Cores

JRuby claims to be faster than MRI when after 50k requests with a single post read. This part measures results with following steps:

  • Restart puma
  • Run ab -n 50000 as warmup
  • Run ab -n 10000 as benchmark

See log/benchmark_50k for details.

GET /posts/1

The following table is showing response time milliseconds for each %ile in the last 10,000 requests.

Ruby 2.6.2 Ruby 2.6.2 JIT JRuby 9.2.6.0 indy
50% 2 4 3
66% 2 5 3
75% 3 5 3
80% 3 6 3
90% 3 8 3
95% 3 10 4
98% 6 15 5
99% 10 17 6
100% 54 37 15

The following table is showing # of requests per second (mean).

Ruby 2.6.2 Ruby 2.6.2 JIT JRuby 9.2.6.0 indy
#/s 1653.11 744.18 1335.05

10k Benchmark Results

Here is the benchmark result on: Intel 4.0GHz i7-4790K, 16GB memory, x86-64 Ubuntu 8 Cores

For each result, I measured results with following steps:

  • Restart puma
  • Run ab -n 10000 as warmup
  • Run ab -n 1000 as benchmark

Following tables are showing response time milliseconds for each %ile in the last 1,000 requests. See log/benchmark for details.

GET /posts

Ruby 2.6.2 Ruby 2.6.2 JIT JRuby 9.2.6.0 JRuby 9.2.6.0 indy JRuby 9.2.6.0 indy Graal
50% 11 23 18 13 22
66% 15 27 21 18 22
75% 16 30 26 19 22
80% 17 31 26 19 24
90% 18 41 28 20 28
95% 24 51 29 22 35
98% 28 61 32 26 36
99% 34 70 34 28 38
100% 44 101 41 35 44

GET /posts.json

Ruby 2.6.2 Ruby 2.6.2 JIT JRuby 9.2.6.0 JRuby 9.2.6.0 indy JRuby 9.2.6.0 indy Graal
50% 27 61 31 21 53
66% 29 69 32 23 58
75% 30 76 34 26 61
80% 31 81 35 28 62
90% 40 106 40 31 68
95% 54 117 45 32 78
98% 56 131 47 35 85
99% 62 144 50 38 92
100% 78 203 56 45 101

GET /posts/1

Ruby 2.6.2 Ruby 2.6.2 JIT JRuby 9.2.6.0 JRuby 9.2.6.0 indy JRuby 9.2.6.0 indy Graal
50% 3 5 8 7 8
66% 4 6 9 8 9
75% 4 7 9 9 12
80% 5 8 10 10 13
90% 5 10 13 12 16
95% 6 12 15 14 19
98% 9 17 19 18 22
99% 14 22 22 19 26
100% 28 31 28 46 28

GET /posts/1.json

Ruby 2.6.2 Ruby 2.6.2 JIT JRuby 9.2.6.0 JRuby 9.2.6.0 indy JRuby 9.2.6.0 indy Graal
50% 3 4 8 7 6
66% 3 6 9 7 7
75% 4 7 9 8 8
80% 4 7 10 9 8
90% 5 9 13 11 9
95% 5 13 16 11 10
98% 6 17 19 13 10
99% 11 21 19 16 12
100% 29 29 28 20 15

Profile

perf

$ WARMUP=1 BENCHMARK=10000 DATABASE_URL="postgresql://k0kubun@localhost/railsbench_production" sudo -E perf record -c 10000 ~/.rbenv/versions/2.6.2/bin/ruby bin/bench
Warmup: 1 requests
Benchmark: 10000 requests

Request per second: 843.8 [#/s] (mean)

Percentage of the requests served within a certain time (ms)
  50%    1.02
  66%    1.14
  75%    1.26
  80%    1.30
  90%    1.35
  95%    1.48
  98%    1.79
  99%    5.96
 100%   13.65
[ perf record: Woken up 106 times to write data ]
[ perf record: Captured and wrote 26.491 MB perf.data (857163 samples) ]

$ sudo perf report
Samples: 857K of event 'cycles:ppp', Event count (approx.): 8571630000
Overhead  Command          Shared Object       Symbol
  20.21%  ruby             ruby                [.] vm_exec_core
   3.71%  ruby             ruby                [.] st_lookup
   3.24%  ruby             ruby                [.] vm_call_cfunc
   2.63%  ruby             ruby                [.] rb_wb_protected_newobj_of
   2.51%  ruby             ruby                [.] vm_call_iseq_setup
   2.34%  ruby             ruby                [.] rb_id_table_lookup
   2.26%  ruby             ruby                [.] method_entry_get
   2.16%  ruby             ruby                [.] vm_call_iseq_setup_normal_0start_0params_0locals
   1.55%  ruby             ruby                [.] find_entry
   1.55%  ruby             ruby                [.] gc_sweep_step
   1.41%  ruby             libc-2.27.so        [.] _int_malloc
   1.38%  ruby             ruby                [.] rb_class_of
   1.35%  ruby             ruby                [.] vm_call_iseq_setup_normal_0start_1params_1locals
   1.13%  ruby             ruby                [.] setup_parameters_complex
   1.10%  ruby             ruby                [.] rb_memhash
   1.00%  ruby             libc-2.27.so        [.] __malloc_usable_size
   0.94%  ruby             libc-2.27.so        [.] malloc
   0.79%  ruby             ruby                [.] vm_call0_body.constprop.402
   0.75%  ruby             ruby                [.] match_at
   0.75%  ruby             ruby                [.] rb_obj_is_kind_of
   0.72%  ruby             libc-2.27.so        [.] malloc_consolidate
   0.72%  ruby             ruby                [.] rb_enc_get
   0.71%  ruby             libc-2.27.so        [.] cfree@GLIBC_2.2.5
   0.61%  ruby             ruby                [.] vm_call_method_each_type
   0.57%  ruby             ruby                [.] rb_get_alloc_func
   0.56%  ruby             ruby                [.] st_update
   0.55%  ruby             libc-2.27.so        [.] __memmove_avx_unaligned_erms
   0.54%  ruby             ruby                [.] str_buf_cat
   0.53%  ruby             ruby                [.] rb_callable_method_entry
   0.49%  ruby             ruby                [.] rb_call0.constprop.401
   0.49%  ruby             ruby                [.] vm_call_method
Samples: 2M of event 'cycles:ppp', Event count (approx.): 20509820000
Overhead  Command          Shared Object              Symbol
   8.70%  ruby             ruby                       [.] vm_exec_core
   1.65%  ruby             ruby                       [.] st_lookup
   1.45%  ruby             ruby                       [.] vm_call_cfunc
   1.28%  ruby             ruby                       [.] rb_wb_protected_newobj_of
   1.21%  ruby             ruby                       [.] vm_call_iseq_setup
   1.07%  ruby             ruby                       [.] method_entry_get
   1.07%  ruby             ruby                       [.] vm_call_iseq_setup_normal_0start_0params_0locals
   1.04%  ruby             libc-2.27.so               [.] _int_malloc
   1.03%  ruby             ruby                       [.] rb_id_table_lookup
   1.01%  cc1              cc1                        [.] _Z14bitmap_set_bitP11bitmap_headi
   0.85%  ruby             ruby                       [.] gc_sweep_step
   0.71%  ruby             ruby                       [.] vm_call_iseq_setup_normal_0start_1params_1locals
   0.71%  ruby             libc-2.27.so               [.] __malloc_usable_size
   0.68%  ruby             ruby                       [.] find_entry
   0.62%  ruby             ruby                       [.] rb_class_of
   0.55%  cc1              libc-2.27.so               [.] cfree@GLIBC_2.2.5
   0.54%  cc1              libc-2.27.so               [.] _int_malloc
   0.54%  ruby             ruby                       [.] setup_parameters_complex
   0.46%  ruby             libc-2.27.so               [.] malloc_consolidate
   0.45%  ruby             ruby                       [.] rb_memhash
   0.43%  cc1              cc1                        [.] _Z12bitmap_bit_pP11bitmap_headi
   0.41%  ruby             libc-2.27.so               [.] malloc
   0.41%  cc1              cc1                        [.] _Z18ggc_internal_allocmPFvPvEmm
   0.39%  ruby             libc-2.27.so               [.] cfree@GLIBC_2.2.5
   0.37%  ruby             ruby                       [.] mjit_exec.part.335
   0.34%  ruby             ruby                       [.] rb_obj_is_kind_of
   0.33%  ruby             ruby                       [.] match_at
   0.32%  cc1              cc1                        [.] _Z16bitmap_clear_bitP11bitmap_headi
   0.32%  ruby             ruby                       [.] vm_call0_body.constprop.402
   0.31%  ruby             ruby                       [.] rb_enc_get
   0.29%  ruby             ruby                       [.] gc_mark_children

stackprof

$ PROFILE=wall INTERVAL=100 WARMUP=1 BENCHMARK=10000 bin/bench
Warmup: 1 requests
Benchmarking 10000 requests...

Request per second: 860.5 [#/s] (mean)

$ stackprof stackprof-2019-03-17_12:17:46_+0900.dump
==================================
  Mode: wall(100)
  Samples: 114881 (0.81% miss rate)
  GC: 4907 (4.27%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
      6363   (5.5%)        6363   (5.5%)     Concurrent::Collection::NonConcurrentMapBackend#[]
      4907   (4.3%)        4907   (4.3%)     (garbage collection)
      3843   (3.3%)        3843   (3.3%)     Logger::Formatter#format_datetime
      4774   (4.2%)        3418   (3.0%)     Logger::LogDevice#write
      2878   (2.5%)        2878   (2.5%)     Rack::Request::Env#get_header
      2116   (1.8%)        2116   (1.8%)     ActiveSupport::SafeBuffer#initialize
      6212   (5.4%)        1773   (1.5%)     Logger::Formatter#call
      2374   (2.1%)        1454   (1.3%)     ActionView::Helpers::TagHelper::TagBuilder#tag_option
      2105   (1.8%)        1436   (1.2%)     block (2 levels) in class_attribute
      1399   (1.2%)        1399   (1.2%)     block (4 levels) in class_attribute
      1347   (1.2%)        1347   (1.2%)     ActiveSupport::InheritableOptions#initialize
      1218   (1.1%)        1218   (1.1%)     ActiveSupport::PerThreadRegistry#instance
      1178   (1.0%)        1178   (1.0%)     ActionDispatch::Http::FilterParameters#initialize
      1076   (0.9%)        1076   (0.9%)     ActiveSupport::Configurable::ClassMethods#config
      1051   (0.9%)        1051   (0.9%)     Rack::Request::Env#fetch_header
      1029   (0.9%)        1029   (0.9%)     Rack::Utils::HeaderHash#[]=
      1025   (0.9%)        1025   (0.9%)     ActiveModel::Attribute#initialize
       982   (0.9%)         982   (0.9%)     ActiveSupport::TaggedLogging::Formatter#current_tags
       963   (0.8%)         963   (0.8%)     MonitorMixin#mon_enter
       960   (0.8%)         960   (0.8%)     Set#include?
       929   (0.8%)         929   (0.8%)     ActiveRecord::Base.logger
       921   (0.8%)         921   (0.8%)     #<Module:0x000055e69f38da70>.encode_www_form_component
      1493   (1.3%)         870   (0.8%)     ActiveModel::Attribute#hash
      1551   (1.4%)         858   (0.7%)     ActiveSupport::TaggedLogging::Formatter#tags_text
      1607   (1.4%)         811   (0.7%)     Rails::Rack::Logger#started_request_message
       786   (0.7%)         786   (0.7%)     ActiveSupport::SafeBuffer#html_safe?
     18279  (15.9%)         779   (0.7%)     Logger#add
       779   (0.7%)         779   (0.7%)     ActiveSupport::ToJsonWithActiveSupportEncoder#to_json
       763   (0.7%)         763   (0.7%)     String#blank?
       757   (0.7%)         757   (0.7%)     ActionDispatch::Response#parse_content_type
$ RUBYOPT="--jit-verbose=1 -v" PROFILE=wall INTERVAL=100 WARMUP=50000 BENCHMARK=10000 bin/bench
ruby 2.7.0dev (2019-03-17 trunk 67281) +JIT [x86_64-linux]
JIT success (41.6ms): block in remove_unresolved_default_spec@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/rubygems.rb:1292 -> /tmp/_ruby_mjit_p5340u0.c
/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.1/lib/bootsnap/compile_cache/yaml.rb:48: warning: method redefined; discarding old load_file
/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/psych.rb:576: warning: previous definition of load_file was here
JIT success (111.1ms): canonical_segments@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/rubygems/version.rb:370 -> /tmp/_ruby_mjit_p5340u1.c
JIT success (109.1ms): _segments@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/rubygems/version.rb:383 -> /tmp/_ruby_mjit_p5340u5.c
JIT success (83.3ms): block (2 levels) in initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.1/lib/bootsnap/load_path_cache/loaded_features_index.rb:36 -> /tmp/_ruby_mjit_p5340u6.c
JIT success (87.1ms): block in tsort_each_child@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/railties-5.2.2.1/lib/rails/initializable.rb:50 -> /tmp/_ruby_mjit_p5340u7.c
JIT success (28.1ms): before@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/railties-5.2.2.1/lib/rails/initializable.rb:19 -> /tmp/_ruby_mjit_p5340u8.c
/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activerecord-5.2.2.1/lib/active_record/statement_cache.rb:90: warning: tried to create Proc object without a block
JIT success (33.1ms): after@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/railties-5.2.2.1/lib/rails/initializable.rb:23 -> /tmp/_ruby_mjit_p5340u9.c
Warmup: 120/50000JIT success (146.3ms): ==@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/rubygems/dependency.rb:173 -> /tmp/_ruby_mjit_p5340u2.c
Warmup: 214/50000JIT success (109.4ms): ==@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/bundler/dep_proxy.rb:16 -> /tmp/_ruby_mjit_p5340u3.c
Warmup: 240/50000JIT success (32.1ms): get_header@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:52 -> /tmp/_ruby_mjit_p5340u10.c
Warmup: 266/50000JIT success (32.5ms): []@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/concurrent-ruby-1.1.5/lib/concurrent/collection/map/non_concurrent_map_backend.rb:19 -> /tmp/_ruby_mjit_p5340u11.c
Warmup: 1027/50000JIT success (888.4ms): []@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/concurrent-ruby-1.1.5/lib/concurrent/map.rb:132 -> /tmp/_ruby_mjit_p5340u12.c
Warmup: 1049/50000JIT success (32.0ms): include?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/set.rb:253 -> /tmp/_ruby_mjit_p5340u13.c
Warmup: 1144/50000JIT success (108.0ms): instance@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/per_thread_registry.rb:46 -> /tmp/_ruby_mjit_p5340u14.c
Warmup: 1176/50000JIT success (50.5ms): block in initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/ordered_options.rb:73 -> /tmp/_ruby_mjit_p5340u15.c
Warmup: 1213/50000JIT success (54.0ms): block in xor_byte_strings@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_controller/metal/request_forgery_protection.rb:405 -> /tmp/_ruby_mjit_p5340u17.c
Warmup: 1228/50000JIT success (29.3ms): block (4 levels) in class_attribute@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/class/attribute.rb:106 -> /tmp/_ruby_mjit_p5340u16.c
Warmup: 1271/50000JIT success (70.4ms): html_safe?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:210 -> /tmp/_ruby_mjit_p5340u18.c
Warmup: 1380/50000JIT success (141.3ms): mon_check_owner@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/monitor.rb:267 -> /tmp/_ruby_mjit_p5340u19.c
Warmup: 1443/50000JIT success (95.2ms): mon_exit@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/monitor.rb:199 -> /tmp/_ruby_mjit_p5340u20.c
Warmup: 1692/50000JIT success (320.0ms): mon_synchronize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/monitor.rb:227 -> /tmp/_ruby_mjit_p5340u21.c
Warmup: 1816/50000JIT success (152.4ms): mon_enter@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/monitor.rb:187 -> /tmp/_ruby_mjit_p5340u22.c
Warmup: 1882/50000JIT success (86.3ms): convert_key@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/hash_with_indifferent_access.rb:349 -> /tmp/_ruby_mjit_p5340u23.c
Warmup: 1901/50000JIT success (25.6ms): html_safe?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:123 -> /tmp/_ruby_mjit_p5340u24.c
Warmup: 1939/50000JIT success (80.4ms): block (2 levels) in class_attribute@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/class/attribute.rb:124 -> /tmp/_ruby_mjit_p5340u25.c
Warmup: 1974/50000JIT success (43.5ms): block in symbolize_keys!@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/hash/keys.rb:64 -> /tmp/_ruby_mjit_p5340u26.c
Warmup: 2049/50000JIT success (115.5ms): block in forwarded_scheme@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:489 -> /tmp/_ruby_mjit_p5340u27.c
Warmup: 2173/50000JIT success (192.7ms): unwrapped_html_escape@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:34 -> /tmp/_ruby_mjit_p5340u28.c
Warmup: 2261/50000JIT success (115.1ms): tidy_bytes@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/multibyte/unicode.rb:226 -> /tmp/_ruby_mjit_p5340u29.c
Warmup: 2907/50000JIT success (785.2ms): initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:172 -> /tmp/_ruby_mjit_p5340u30.c
Warmup: 3036/50000JIT success (151.1ms): connection_specification_name@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activerecord-5.2.2.1/lib/active_record/connection_handling.rb:96 -> /tmp/_ruby_mjit_p5340u31.c
Warmup: 3063/50000JIT success (40.4ms): block in view_assigns@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/abstract_controller/rendering.rb:68 -> /tmp/_ruby_mjit_p5340u32.c
Warmup: 3097/50000JIT success (45.2ms): present?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/object/blank.rb:26 -> /tmp/_ruby_mjit_p5340u33.c
MJIT warning: Skipped to compile unsupported instruction: getblockparamproxy
JIT failure (0.0ms): fetch_header@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:58 -> /tmp/_ruby_mjit_p5340u34.c
Warmup: 3130/50000JIT success (48.8ms): logger@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/configurable.rb:23 -> /tmp/_ruby_mjit_p5340u35.c
Warmup: 3197/50000JIT success (104.3ms): safe_concat@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:167 -> /tmp/_ruby_mjit_p5340u36.c
Warmup: 3334/50000JIT success (190.7ms): config@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/configurable.rb:30 -> /tmp/_ruby_mjit_p5340u37.c
Warmup: 3394/50000JIT success (91.6ms): event_stack@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/subscriber.rb:106 -> /tmp/_ruby_mjit_p5340u38.c
Warmup: 3425/50000JIT success (65.6ms): get_queue@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/subscriber.rb:126 -> /tmp/_ruby_mjit_p5340u39.c
Warmup: 3509/50000JIT success (141.1ms): listeners_for@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/notifications/fanout.rb:55 -> /tmp/_ruby_mjit_p5340u40.c
Warmup: 3678/50000JIT success (231.4ms): convert_value@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/hash_with_indifferent_access.rb:353 -> /tmp/_ruby_mjit_p5340u41.c
Warmup: 3894/50000JIT success (260.6ms): block in tag_options@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionview-5.2.2.1/lib/action_view/helpers/tag_helper.rb:63 -> /tmp/_ruby_mjit_p5340u42.c
Warmup: 4025/50000JIT success (172.9ms): tag_option@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionview-5.2.2.1/lib/action_view/helpers/tag_helper.rb:87 -> /tmp/_ruby_mjit_p5340u43.c
Warmup: 4085/50000JIT success (86.2ms): html_safe@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:255 -> /tmp/_ruby_mjit_p5340u44.c
Warmup: 4784/50000JIT success (859.4ms): []=@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/utils.rb:468 -> /tmp/_ruby_mjit_p5340u45.c
Warmup: 4854/50000JIT success (87.1ms): path_info@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:132 -> /tmp/_ruby_mjit_p5340u47.c
Warmup: 4931/50000JIT success (93.1ms): logger@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_controller/log_subscriber.rb:72 -> /tmp/_ruby_mjit_p5340u49.c
Warmup: 5581/50000JIT success (793.2ms): <<@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionview-5.2.2.1/lib/action_view/buffers.rb:12 -> /tmp/_ruby_mjit_p5340u51.c
Warmup: 5620/50000JIT success (48.8ms): logger@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/configurable.rb:115 -> /tmp/_ruby_mjit_p5340u50.c
Warmup: 5881/50000JIT success (348.2ms): __getobj__@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/delegate.rb:392 -> /tmp/_ruby_mjit_p5340u46.c
Warmup: 5900/50000JIT success (24.1ms): loaded?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/request/session.rb:192 -> /tmp/_ruby_mjit_p5340u48.c
Warmup: 5921/50000JIT success (31.5ms): set_header@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:68 -> /tmp/_ruby_mjit_p5340u52.c
Warmup: 6564/50000JIT success (795.3ms): level@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/logger_thread_safe_level.rb:29 -> /tmp/_ruby_mjit_p5340u53.c
Warmup: 6607/50000JIT success (49.9ms): local_level@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/logger_thread_safe_level.rb:17 -> /tmp/_ruby_mjit_p5340u54.c
Warmup: 6668/50000JIT success (81.7ms): local_log_id@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/logger_thread_safe_level.rb:13 -> /tmp/_ruby_mjit_p5340u55.c
Warmup: 7264/50000JIT success (779.6ms): initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/request.rb:59 -> /tmp/_ruby_mjit_p5340u56.c
Warmup: 7885/50000JIT success (759.4ms): initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:40 -> /tmp/_ruby_mjit_p5340u57.c
Warmup: 8513/50000JIT success (769.3ms): initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/url.rb:186 -> /tmp/_ruby_mjit_p5340u58.c
Warmup: 9139/50000JIT success (759.2ms): initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/filter_parameters.rb:34 -> /tmp/_ruby_mjit_p5340u59.c
Warmup: 9238/50000JIT success (123.6ms): current_tags@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/tagged_logging.rb:47 -> /tmp/_ruby_mjit_p5340u60.c
Warmup: 9899/50000JIT success (813.0ms): request_method@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/request.rb:134 -> /tmp/_ruby_mjit_p5340u62.c
Warmup: 9987/50000JIT success (113.7ms): block in delegating_block@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/delegate.rb:347 -> /tmp/_ruby_mjit_p5340u61.c
Warmup: 10617/50000JIT success (770.6ms): concat@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:186 -> /tmp/_ruby_mjit_p5340u63.c
Warmup: 10704/50000JIT success (109.5ms): html_escape_interpolated_argument@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:243 -> /tmp/_ruby_mjit_p5340u64.c
Warmup: 10726/50000JIT success (29.4ms): block in initialize@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/utils.rb:443 -> /tmp/_ruby_mjit_p5340u65.c
Warmup: 10810/50000JIT success (133.6ms): now@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/subscriber.rb:110 -> /tmp/_ruby_mjit_p5340u66.c
Warmup: 10838/50000JIT success (46.8ms): presence@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/object/blank.rb:46 -> /tmp/_ruby_mjit_p5340u67.c
Warmup: 11464/50000JIT success (795.7ms): default@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/hash_with_indifferent_access.rb:206 -> /tmp/_ruby_mjit_p5340u69.c
Warmup: 11529/50000JIT success (88.3ms): script_name@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:129 -> /tmp/_ruby_mjit_p5340u68.c
Warmup: 11545/50000JIT success (27.9ms): to_s@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/string/output_safety.rb:214 -> /tmp/_ruby_mjit_p5340u70.c
Warmup: 11694/50000JIT success (240.8ms): scheme@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:188 -> /tmp/_ruby_mjit_p5340u71.c
Warmup: 11838/50000JIT success (207.4ms): forwarded_scheme@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/rack-2.0.6/lib/rack/request.rb:483 -> /tmp/_ruby_mjit_p5340u72.c
Warmup: 12735/50000JIT success (1092.5ms): to_s@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/numeric/conversions.rb:104 -> /tmp/_ruby_mjit_p5340u73.c
Warmup: 12790/50000JIT success (75.4ms): value@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activemodel-5.2.2.1/lib/active_model/attribute.rb:40 -> /tmp/_ruby_mjit_p5340u74.c
Warmup: 13479/50000JIT success (861.8ms): add@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/logger.rb:87 -> /tmp/_ruby_mjit_p5340u75.c
Warmup: 13848/50000JIT success (455.4ms): add@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:455 -> /tmp/_ruby_mjit_p5340u76.c
Warmup: 13913/50000JIT success (84.2ms): config@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/configurable.rb:146 -> /tmp/_ruby_mjit_p5340u90.c
Warmup: 13965/50000JIT success (71.3ms): format_severity@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:577 -> /tmp/_ruby_mjit_p5340u77.c
Warmup: 14059/50000JIT success (132.1ms): lookup_context@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionview-5.2.2.1/lib/action_view/view_paths.rb:40 -> /tmp/_ruby_mjit_p5340u89.c
Warmup: 14098/50000JIT success (62.5ms): format_message@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:581 -> /tmp/_ruby_mjit_p5340u78.c
Warmup: 14753/50000JIT success (827.8ms): call@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/tagged_logging.rb:22 -> /tmp/_ruby_mjit_p5340u79.c
Warmup: 14849/50000JIT success (125.3ms): tags_text@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/tagged_logging.rb:53 -> /tmp/_ruby_mjit_p5340u80.c
Warmup: 14879/50000JIT success (42.3ms): block in tags_text@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/tagged_logging.rb:56 -> /tmp/_ruby_mjit_p5340u81.c
Warmup: 14965/50000JIT success (135.2ms): call@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:596 -> /tmp/_ruby_mjit_p5340u82.c
Warmup: 14994/50000JIT success (53.7ms): format_datetime@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:603 -> /tmp/_ruby_mjit_p5340u83.c
Warmup: 15067/50000JIT success (120.6ms): msg2str@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:607 -> /tmp/_ruby_mjit_p5340u84.c
Warmup: 15124/50000JIT success (105.0ms): write@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:684 -> /tmp/_ruby_mjit_p5340u85.c
Warmup: 15164/50000JIT success (61.1ms): block in write@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/2.7.0/logger.rb:686 -> /tmp/_ruby_mjit_p5340u86.c
Warmup: 15221/50000JIT success (95.7ms): committed?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/response.rb:219 -> /tmp/_ruby_mjit_p5340u87.c
Warmup: 15240/50000JIT success (29.2ms): block in committed?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/response.rb:219 -> /tmp/_ruby_mjit_p5340u88.c
Warmup: 15286/50000JIT success (90.2ms): load_for_read!@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/request/session.rb:212 -> /tmp/_ruby_mjit_p5340u91.c
Warmup: 15323/50000JIT success (54.3ms): get_header@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/http/response.rb:181 -> /tmp/_ruby_mjit_p5340u93.c
Warmup: 15357/50000JIT success (69.3ms): block in extract!@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/hash/slice.rb:46 -> /tmp/_ruby_mjit_p5340u92.c
Warmup: 15386/50000JIT success (44.4ms): []@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/actionpack-5.2.2.1/lib/action_dispatch/request/session.rb:48 -> /tmp/_ruby_mjit_p5340u94.c
Warmup: 15420/50000JIT success (53.0ms): get_or_default@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/concurrent-ruby-1.1.5/lib/concurrent/collection/map/non_concurrent_map_backend.rb:108 -> /tmp/_ruby_mjit_p5340u95.c
Warmup: 15768/50000JIT success (484.5ms): fetch@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/concurrent-ruby-1.1.5/lib/concurrent/map.rb:168 -> /tmp/_ruby_mjit_p5340u96.c
Warmup: 15825/50000JIT success (82.2ms): blank?@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/core_ext/object/blank.rb:122 -> /tmp/_ruby_mjit_p5340u97.c
Warmup: 15895/50000JIT success (98.1ms): owner_to_pool@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activerecord-5.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:1054 -> /tmp/_ruby_mjit_p5340u98.c
Warmup: 15969/50000JIT success (109.8ms): connection_handler@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activerecord-5.2.2.1/lib/active_record/core.rb:130 -> /tmp/_ruby_mjit_p5340u99.c
Warmup: 16008/50000JIT success (53.1ms): connection_handler@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activerecord-5.2.2.1/lib/active_record/runtime_registry.rb:20 -> /tmp/_ruby_mjit_p5340u100.c
Warmup: 16037/50000JIT success (55.0ms): start@/home/k0kubun/.rbenv/versions/ruby-svn/lib/ruby/gems/2.7.0/gems/activesupport-5.2.2.1/lib/active_support/notifications/instrumenter.rb:34 -> /tmp/_ruby_mjit_p5340u101.c
Warmup: 16051/50000JIT compaction (23.7ms): Compacted 100 methods -> /tmp/_ruby_mjit_p5340u990.so
Warmup: 50000 requests
Benchmarking 10000 requests...

Request per second: 818.3 [#/s] (mean)
Successful MJIT finish
/home/k0kubun/src/github.com/k0kubun/railsbench † bionic status: 0                                                            (git)-[master]-
$ stackprof stackprof-2019-03-17_17:51:33_+0900.dump
==================================
  Mode: wall(100)
  Samples: 121143 (0.61% miss rate)
  GC: 5436 (4.49%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
      5890   (4.9%)        5890   (4.9%)     Concurrent::Collection::NonConcurrentMapBackend#[]
      5436   (4.5%)        5436   (4.5%)     (garbage collection)
      3903   (3.2%)        3903   (3.2%)     Logger::Formatter#format_datetime
      4990   (4.1%)        3556   (2.9%)     Logger::LogDevice#write
      3307   (2.7%)        3307   (2.7%)     Rack::Request::Env#get_header
      2384   (2.0%)        2384   (2.0%)     ActiveSupport::SafeBuffer#initialize
      6335   (5.2%)        1773   (1.5%)     Logger::Formatter#call
      2330   (1.9%)        1619   (1.3%)     block (2 levels) in class_attribute
      1444   (1.2%)        1444   (1.2%)     block (4 levels) in class_attribute
      1949   (1.6%)        1261   (1.0%)     ActionView::Helpers::TagHelper::TagBuilder#tag_option
      1254   (1.0%)        1254   (1.0%)     ActiveSupport::PerThreadRegistry#instance
      1231   (1.0%)        1231   (1.0%)     ActionDispatch::Http::FilterParameters#initialize
      1226   (1.0%)        1226   (1.0%)     Rack::Utils::HeaderHash#[]=
      1219   (1.0%)        1219   (1.0%)     Rack::Request::Env#fetch_header
      1188   (1.0%)        1188   (1.0%)     ActiveSupport::InheritableOptions#initialize
      1187   (1.0%)        1187   (1.0%)     ActiveSupport::Configurable::ClassMethods#config
      1131   (0.9%)        1131   (0.9%)     MonitorMixin#mon_enter
      1264   (1.0%)         984   (0.8%)     ActionView::LogSubscriber#from_rails_root
       953   (0.8%)         953   (0.8%)     ActionDispatch::Response#parse_content_type
       944   (0.8%)         944   (0.8%)     #<Module:0x0000561544a19168>.encode_www_form_component
     18841  (15.6%)         933   (0.8%)     Logger#add
       908   (0.7%)         908   (0.7%)     ActiveSupport::TaggedLogging::Formatter#current_tags
       900   (0.7%)         900   (0.7%)     Set#include?
       889   (0.7%)         889   (0.7%)     ActiveModel::Attribute#initialize
      1503   (1.2%)         865   (0.7%)     ActiveSupport::TaggedLogging::Formatter#tags_text
       840   (0.7%)         840   (0.7%)     ActiveSupport::HashWithIndifferentAccess#convert_key
      1471   (1.2%)         832   (0.7%)     ActiveModel::Attribute#hash
       830   (0.7%)         830   (0.7%)     #<Class:0x0000561545c7a578>#__getobj__
       828   (0.7%)         828   (0.7%)     ActiveRecord::Base.logger
       781   (0.6%)         781   (0.6%)     MonitorMixin#mon_enter

License

MIT License

You can’t perform that action at this time.