JRuby profile

flat.log

Profiling enabled; ^C shutdown will now dump profile info

main thread profile results:
Total time: 54.43

     total        self    children       calls  method
----------------------------------------------------------------
     50.17        0.00       50.17           1  RSpec::Core::Runner.run
     50.13        0.00       50.13           1  RSpec::Core::Runner.run_in_process
     50.13        0.00       50.13           1  RSpec::Core::CommandLine#run
     50.08        0.03       50.05       29243  Array#collect
     39.27        0.23       39.03       96551  Array#each
     29.11        0.15       28.95        4545  BasicObject#instance_eval
     28.86        0.00       28.86           1  RSpec::Core::Reporter#report
     28.77        0.00       28.77         158  RSpec::Core::ExampleGroup.run
     28.67        0.00       28.67         158  RSpec::Core::ExampleGroup.run_examples
     28.65        0.01       28.64         220  RSpec::Core::Example#run
     28.53        0.01       28.52         219  RSpec::Core::Example#with_around_hooks
     26.36        0.05       26.31        9342  Kernel#require
     24.45        0.06       24.39      156383  Kernel#send
     21.34        0.05       21.29          41  Kernel#load
     21.20        0.00       21.20           1  RSpec::Core::Configuration#load_spec_files
     20.23        0.00       20.23           1  Spork.prefork
     19.38        0.00       19.38        2339  ActiveSupport::Dependencies::Loadable#load_dependency
     17.40        0.00       17.40        2301  ActiveSupport::Dependencies::Loadable#require
     15.03        0.11       14.92       23460  Proc#call
     13.96        0.03       13.93       32139  Kernel#catch
     13.90        0.02       13.87        2686  <unknown>
     13.45        0.02       13.44        1867  ActiveSupport::Callbacks#run_callbacks
     11.31        0.00       11.31          56  <unknown>
     11.31        0.00       11.31          56  <unknown>
     11.29        0.00       11.29          56  <unknown>
     11.29        0.01       11.28          56  <unknown>
     10.91        0.00       10.91          56  <unknown>
     10.89        0.00       10.89          56  AbstractController::Rendering#process
     10.89        0.00       10.89          58  AbstractController::Base#process
     10.73        0.00       10.72          56  ActiveRecord::Railties::ControllerRuntime#process_action
     10.72        0.00       10.72          56  ActionController::ParamsWrapper#process_action
     10.72        0.01       10.71          56  ActionController::Instrumentation#process_action
     10.67        0.00       10.66         277  ActiveSupport::Notifications.instrument
     10.59        0.00       10.59          56  ActionController::Rescue#process_action
     10.59        0.00       10.59          56  AbstractController::Callbacks#process_action
     10.20        0.01       10.20        1482  ActiveSupport::Dependencies#new_constants_in
     10.07        0.00       10.07           1  Bundler.require
     10.07        0.00       10.07           1  Bundler::Runtime#require
      9.22        0.00        9.22          53  ActionController::Rendering#process_action
      9.22        0.00        9.22          55  AbstractController::Base#process_action
      9.21        0.00        9.21          53  ActionController::ImplicitRender#send_action
      8.96        0.00        8.96         219  RSpec::Core::Example#run_before_each
      8.62        0.00        8.62          38  ActionController::Instrumentation#render
      8.62        0.00        8.62          38  ActiveRecord::Railties::ControllerRuntime#cleanup_view_runtime
      8.62        0.00        8.62          38  ActionController::Instrumentation#cleanup_view_runtime
      8.62        0.00        8.62          38  Benchmark.ms
      8.62        0.00        8.62          76  Benchmark#realtime
      8.61        0.00        8.61          38  ActionController::Rendering#render
      8.61        0.00        8.61          38  AbstractController::Rendering#render
      8.53        0.00        8.53          38  ActionController::Compatibility#render_to_body

It looks like requiring neo4j gem takes most of the time.
But I'm very much in doubt that 1.7 sec (is it in secs?) time is an issue here.

Relatively small gem (draper) takes 1.2 secs to load. Also at the rails gem seems to take the least amont of time.
The results don't seem to be representative unfortunately.

> sort --reverse require.log 
(1.709000) for require neo4j: 1.709000
(1.188000) for require draper: 1.189000
(0.683000) for require sass-rails: 0.683000
(0.651000) for require inherited_resources: 0.651000
(0.543000) for require pry: 0.542000
(0.527000) for require capybara-webkit: 0.527000
(0.520000) for require capybara: 0.520000
(0.474000) for require compass: 0.474000
(0.444000) for require haml-rails: 0.444000
(0.355000) for require devise-neo4j: 0.355000
(0.305000) for require shoulda-matchers: 0.305000
(0.214000) for require launchy: 0.214000
(0.171000) for require factory_girl: 0.171000
(0.150000) for require coffee-rails: 0.150000
(0.082000) for require dragonfly: 0.082000
(0.079000) for require jasmine: 0.079000
(0.036000) for require paper_trail: 0.037000
(0.025000) for require allowy: 0.025000
(0.019000) for require no_peeping_toms: 0.019000
(0.018000) for require database_cleaner: 0.018000
(0.016000) for require ruby_gntp: 0.016000
(0.015000) for require jquery-rails: 0.014000
(0.015000) for require factory_girl_rails: 0.015000
(0.012000) for require rb-fsevent: 0.012000
(0.011000) for require uglifier: 0.011000
(0.010000) for require formtastic: 0.010000
(0.008000) for require rack/cache: 0.008000
(0.007000) for require guard: 0.007000
(0.003000) for require rspec-rails: 0.003000
(0.002000) for require spork: 0.002000
(0.001000) for require rails: 0.001000