Skip to content

Instantly share code, notes, and snippets.

@jcxplorer

jcxplorer/First run (Unicorn)

Created June 26, 2010 22:01
Show Gist options
  • Save jcxplorer/454374 to your computer and use it in GitHub Desktop.
Save jcxplorer/454374 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
First run (Unicorn)
Total running time: 351.65212240200003s
% cumulative self self total
time seconds seconds calls ms/call ms/call name
------------------------------------------------------------
99.40 349.53 349.53 352 992.98 992.99 IO.select_primitive
0.09 0.31 0.31 56 5.55 5.55 Rubinius::CodeLoader#load_compiled_file
0.06 0.22 0.22 410 0.54 0.54 IO::Buffer#fill
0.03 0.10 0.10 14 7.20 7.20 GC.collect_young
0.02 0.20 0.07 322 0.22 0.63 Rubinius::Melbourne#string_to_ast
0.02 0.05 0.05 3270 0.02 0.02 Rubinius::VM.reset_method_cache
0.01 0.05 0.04 10975 0.00 0.00 String#[]
0.01 0.04 0.04 5659 0.01 0.01 FFI::Platform::POSIX.stat
0.01 0.03 0.03 15 2.19 2.19 GC.collect_mature
0.01 0.06 0.03 16675 0.00 0.00 Hash#find_entry
0.01 0.10 0.03 11458 0.00 0.01 Hash#[]=
0.01 0.04 0.03 69229 0.00 0.00 Array#<<
0.01 0.03 0.03 36848 0.00 0.00 Hash::Entry#match?
0.01 0.03 0.02 19269 0.00 0.00 Kernel#instance_of?
0.01 1.32 0.02 10321 0.00 0.13 Array#each
0.01 0.02 0.02 5679 0.00 0.00 Hash::Iterator#next
0.01 0.04 0.02 11871 0.00 0.00 Hash#new_entry
0.00 0.03 0.02 5027 0.00 0.01 FFI::MemoryPointer.new
0.00 0.02 0.02 32789 0.00 0.00 Type.coerce_to
0.00 0.02 0.01 2 7.49 9.10 Rubinius::Melbourne#file_to_ast
0.00 0.01 0.01 4890 0.00 0.00 Dir#read
0.00 0.01 0.01 8189 0.00 0.00 Regexp#search_region
0.00 0.02 0.01 203 0.06 0.10 Hash#redistribute
0.00 0.06 0.01 5007 0.00 0.01 FFI::Struct#initialize
0.00 0.18 0.01 15947 0.00 0.01 Hash#[]
0.00 0.01 0.01 2 6.15 6.15 Rubinius::NativeMethod.load_entry_point
0.00 0.04 0.01 10354 0.00 0.00 Rubinius::Melbourne#process_transforms {}
0.00 0.10 0.01 11386 0.00 0.01 Hash#default
0.00 0.06 0.01 2022 0.01 0.03 Rubinius.add_method
0.00 0.02 0.01 21634 0.00 0.00 Kernel#StringValue
0.00 0.01 0.01 25853 0.00 0.00 Hash#key_index
0.00 0.09 0.01 8202 0.00 0.01 Rubinius::Generator#initialize {}
0.00 349.71 0.01 350 0.03 999.17 Unicorn::HttpServer#join {}
0.00 0.01 0.01 69230 0.00 0.00 Array#set_index
0.00 0.01 0.01 5563 0.00 0.00 FFI::Struct#[]
0.00 0.32 0.01 632 0.01 0.50 Dir::Glob.brace_glob
0.00 349.55 0.01 352 0.03 993.05 IO.select
0.00 0.06 0.01 4516 0.00 0.01 File::Stat.create
0.00 0.10 0.01 4516 0.00 0.02 File::Stat.stat
0.00 0.02 0.01 860 0.01 0.02 Thread.detect_recursion
0.00 0.03 0.01 5008 0.00 0.01 Dir::Glob#compile {}
0.00 0.01 0.01 60611 0.00 0.00 Class#allocate
0.00 0.03 0.01 4505 0.00 0.01 Dir::Glob::Node#path_join
0.00 0.03 0.01 16923 0.00 0.00 String#to_s
0.00 0.01 0.01 84189 0.00 0.00 Rubinius::Tuple#[]
1,670 methods omitted
1,715 methods called a total of 1,845,485 times
Raw
Second run (Unicorn)
Total running time: 131.760095369s
% cumulative self self total
time seconds seconds calls ms/call ms/call name
------------------------------------------------------------
98.34 129.57 129.57 130 996.72 996.72 IO.select_primitive
0.52 0.68 0.68 7 97.70 97.71 Rubinius::Channel#receive_timeout
0.07 0.09 0.09 56 1.66 1.66 Rubinius::CodeLoader#load_compiled_file
0.07 0.09 0.09 13 7.07 7.07 GC.collect_young
0.05 0.19 0.06 322 0.19 0.60 Rubinius::Melbourne#string_to_ast
0.03 0.04 0.04 3270 0.01 0.01 Rubinius::VM.reset_method_cache
0.03 0.03 0.03 14 2.38 2.38 GC.collect_mature
0.02 0.03 0.03 5657 0.01 0.01 FFI::Platform::POSIX.stat
0.02 0.06 0.03 16491 0.00 0.00 Hash#find_entry
0.02 0.04 0.03 69227 0.00 0.00 Array#<<
0.02 0.10 0.03 11262 0.00 0.01 Hash#[]=
0.02 0.04 0.03 10878 0.00 0.00 String#[]
0.02 0.03 0.03 36054 0.00 0.00 Hash::Entry#match?
0.02 0.03 0.02 19171 0.00 0.00 Kernel#instance_of?
0.02 1.11 0.02 10324 0.00 0.11 Array#each
0.01 0.04 0.02 11504 0.00 0.00 Hash#new_entry
0.01 0.02 0.01 31644 0.00 0.00 Type.coerce_to
0.01 0.01 0.01 4890 0.00 0.00 Dir#read
0.01 0.02 0.01 203 0.07 0.10 Hash#redistribute
0.01 0.02 0.01 4806 0.00 0.00 FFI::MemoryPointer.new
0.01 0.01 0.01 8048 0.00 0.00 Regexp#search_region
0.01 0.01 0.01 4814 0.00 0.00 Hash::Iterator#next
0.01 0.04 0.01 10354 0.00 0.00 Rubinius::Melbourne#process_transforms {}
0.01 0.18 0.01 15763 0.00 0.01 Hash#[]
0.01 0.09 0.01 8202 0.00 0.01 Rubinius::Generator#initialize {}
0.01 0.05 0.01 4786 0.00 0.01 FFI::Struct#initialize
0.01 0.05 0.01 2022 0.01 0.02 Rubinius.add_method
0.01 0.02 0.01 21592 0.00 0.00 Kernel#StringValue
0.01 0.01 0.01 69228 0.00 0.00 Array#set_index
0.01 0.01 0.01 25668 0.00 0.00 Hash#key_index
0.01 0.10 0.01 11166 0.00 0.01 Hash#default
0.01 0.03 0.01 4505 0.00 0.01 Dir::Glob::Node#path_join
0.01 0.31 0.01 632 0.01 0.49 Dir::Glob.brace_glob
0.01 0.06 0.01 4514 0.00 0.01 File::Stat.create
0.01 0.01 0.01 5144 0.00 0.00 FFI::Struct#[]
0.01 0.03 0.01 5008 0.00 0.01 Dir::Glob#compile {}
0.01 0.01 0.01 39198 0.00 0.00 Kernel#kind_of?
0.01 0.02 0.01 5951 0.00 0.00 Rubinius::GeneratorMethods#emit_push_literal
0.01 0.03 0.01 16841 0.00 0.00 String#to_s
0.01 0.01 0.01 17309 0.00 0.00 Rubinius::Generator::BasicBlock#add_stack
0.01 0.01 0.01 46884 0.00 0.00 Module#===
0.01 0.01 0.01 59088 0.00 0.00 Class#allocate
0.01 0.01 0.01 466 0.02 0.02 Dir#initialize
0.01 0.02 0.01 5037 0.00 0.00 Regexp#match
0.01 0.40 0.01 618 0.01 0.64 Array#reverse_each
1,672 methods omitted
1,717 methods called a total of 1,792,021 times
Raw
Second run - Exception
Cannot serialize an object of class Time into BSON.
bson (1.0.3) lib/./lib/bson/bson_c.rb:24:in `serialize'
mongo (1.0.3) lib/./lib/mongo/collection.rb:327:in `update'
mongoid (2.0.0.beta7) lib/mongoid/collections/master.rb:15:in `Master {}'
mongoid (2.0.0.beta7) lib/mongoid/collection.rb:19:in `Collection {}'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert_embedded.rb:35:in `persist {}'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:417:in `_run_save_callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:88:in `run_callbacks'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert_embedded.rb:30:in `persist {}'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:417:in `_run_create_callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:88:in `run_callbacks'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert_embedded.rb:29:in `persist'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert.rb:40:in `insert'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert.rb:28:in `persist {}'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:417:in `_run_save_callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:88:in `run_callbacks'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert.rb:27:in `persist {}'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:417:in `_run_create_callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:88:in `run_callbacks'
mongoid (2.0.0.beta7) lib/mongoid/persistence/insert.rb:26:in `persist'
mongoid (2.0.0.beta7) lib/mongoid/persistence.rb:40:in `insert'
mongoid (2.0.0.beta7) lib/mongoid/persistence.rb:122:in `save (upsert)'
kernel/common/symbol.rb:43:in `to_proc {}'
kernel/common/kernel.rb:348:in `tap'
mongoid (2.0.0.beta7) lib/mongoid/associations/embeds_many.rb:58:in `create'
app/controllers/comments_controller.rb:6:in `create'
actionpack (3.0.0.beta4) lib/action_controller/metal/implicit_render.rb:4:in `send_action'
actionpack (3.0.0.beta4) lib/abstract_controller/base.rb:145:in `process_action'
actionpack (3.0.0.beta4) lib/action_controller/metal/rendering.rb:11:in `process_action'
actionpack (3.0.0.beta4) lib/abstract_controller/callbacks.rb:18:in `process_action {}'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:433:in `_run__3221164532195705195__process_action__3985228182631969790__callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:408:in `_run_process_action_callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:88:in `run_callbacks'
actionpack (3.0.0.beta4) lib/abstract_controller/callbacks.rb:17:in `process_action'
actionpack (3.0.0.beta4) lib/action_controller/metal/instrumentation.rb:29:in `process_action {}'
activesupport (3.0.0.beta4) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
activesupport (3.0.0.beta4) lib/active_support/notifications.rb:48:in `instrument'
actionpack (3.0.0.beta4) lib/action_controller/metal/instrumentation.rb:28:in `process_action'
actionpack (3.0.0.beta4) lib/action_controller/metal/rescue.rb:8:in `process_action'
actionpack (3.0.0.beta4) lib/abstract_controller/base.rb:114:in `process'
actionpack (3.0.0.beta4) lib/abstract_controller/rendering.rb:40:in `process'
actionpack (3.0.0.beta4) lib/action_controller/metal.rb:126:in `dispatch'
actionpack (3.0.0.beta4) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
actionpack (3.0.0.beta4) lib/action_controller/metal.rb:166:in `action {}'
actionpack (3.0.0.beta4) lib/action_dispatch/routing/route_set.rb:27:in `call'
rack-mount (0.6.6) lib/rack/mount/route_set.rb:148:in `call {}'
rack-mount (0.6.6) lib/rack/mount/code_generation.rb:89:in `recognize {}'
rack-mount (0.6.6) lib/rack/mount/code_generation.rb:66:in `optimized_each'
rack-mount (0.6.6) lib/rack/mount/code_generation.rb:88:in `recognize'
rack-mount (0.6.6) lib/rack/mount/route_set.rb:139:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/routing/route_set.rb:457:in `call'
warden (0.10.7) lib/warden/manager.rb:35:in `call {}'
kernel/common/throw_catch.rb:34:in `catch {}'
kernel/common/throw_catch.rb:13:in `register'
kernel/common/throw_catch.rb:33:in `catch'
warden (0.10.7) lib/warden/manager.rb:34:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/head.rb:14:in `call'
rack (1.1.0) lib/rack/methodoverride.rb:24:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/params_parser.rb:21:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/flash.rb:177:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/session/abstract_store.rb:106:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/cookies.rb:235:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/callbacks.rb:46:in `call {}'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:414:in `_run_call_callbacks'
activesupport (3.0.0.beta4) lib/active_support/callbacks.rb:88:in `run_callbacks'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/callbacks.rb:44:in `call'
rack (1.1.0) lib/rack/sendfile.rb:105:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/remote_ip.rb:48:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/show_exceptions.rb:48:in `call'
railties (3.0.0.beta4) lib/rails/rack/logger.rb:14:in `call'
rack (1.1.0) lib/rack/runtime.rb:17:in `call'
activesupport (3.0.0.beta4) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
rack (1.1.0) lib/rack/lock.rb:11:in `call {}'
/usr/local/rubinius/1.0.1/lib/thread.rb:106:in `synchronize'
rack (1.1.0) lib/rack/lock.rb:11:in `call'
actionpack (3.0.0.beta4) lib/action_dispatch/middleware/static.rb:30:in `call'
railties (3.0.0.beta4) lib/rails/application.rb:145:in `call'
railties (3.0.0.beta4) lib/rails/application.rb:81:in `call (method_missing)'
rack (1.1.0) lib/rack/lint.rb:47:in `_call'
rack (1.1.0) lib/rack/lint.rb:35:in `call'
rack (1.1.0) lib/rack/showexceptions.rb:24:in `call'
rack (1.1.0) lib/rack/commonlogger.rb:18:in `call'
unicorn (1.0.0) lib/unicorn.rb:636:in `process_client'
unicorn (1.0.0) lib/unicorn.rb:709:in `worker_loop {}'
kernel/bootstrap/array.rb:163:in `each'
unicorn (1.0.0) lib/unicorn.rb:707:in `worker_loop'
unicorn (1.0.0) lib/unicorn.rb:598:in `spawn_missing_workers {}'
kernel/common/process.rb:62:in `fork'
kernel/common/process.rb:616:in `fork'
unicorn (1.0.0) lib/unicorn.rb:595:in `spawn_missing_workers {}'
kernel/common/range.rb:162:in `each'
unicorn (1.0.0) lib/unicorn.rb:591:in `spawn_missing_workers'
unicorn (1.0.0) lib/unicorn.rb:605:in `maintain_worker_count'
unicorn (1.0.0) lib/unicorn.rb:269:in `start'
unicorn (1.0.0) lib/unicorn.rb:28:in `run'
unicorn (1.0.0) bin/unicorn:123:in `__script__'
kernel/common/kernel.rb:642:in `load'
/usr/local/rubinius/1.0.1/gems/bin/unicorn:19:in `__script__'
kernel/delta/codeloader.rb:67:in `load_script'
kernel/delta/codeloader.rb:91:in `load_script'
kernel/loader.rb:435:in `script'
kernel/loader.rb:527:in `main'
kernel/loader.rb:553:in `main'
kernel/loader.rb:565:in `__script__'
Raw
Third run (Thin)
Total running time: 134.489655502s
% cumulative self self total
time seconds seconds calls ms/call ms/call name
------------------------------------------------------------
17.62 23.69 23.69 114 207.82 207.82 Array#fast_pack
16.32 117.28 21.95 1 21951.84 117278.85 EventMachine.run_machine
4.60 7.74 6.18 10071800 0.00 0.00 Hash::Entry#match?
3.10 4.16 4.16 825 5.05 5.05 GC.collect_mature
3.04 4.09 4.09 748 5.46 5.46 GC.collect_young
2.92 9.50 3.93 1939621 0.00 0.00 Hash#find_entry
2.86 15.53 3.84 1249908 0.00 0.01 Hash#[]=
1.97 4.30 2.64 18765 0.14 0.23 Hash#redistribute
1.67 3.04 2.25 2020605 0.00 0.00 Kernel#instance_of?
1.52 24.80 2.04 2216817 0.00 0.01 Module#filter_methods {}
1.37 2.73 1.84 775180 0.00 0.00 String#[]
1.26 2.31 1.70 637588 0.00 0.00 Array::IdentityMap#insert
1.23 8.70 1.65 21763 0.08 0.40 Array#map
1.20 25.84 1.61 100297 0.02 0.26 Rubinius::MethodTable#each
1.13 3.50 1.52 1267599 0.00 0.00 Hash#new_entry
1.08 1.67 1.45 1159183 0.00 0.00 Hash::Iterator#next
1.04 1.68 1.40 3824867 0.00 0.00 Hash#key_index
1.02 1.37 1.37 298310 0.00 0.00 FFI::Platform::POSIX.stat
0.90 0.98 1.21 13898711 0.00 0.00 Rubinius::Tuple#[]
0.75 1.71 1.01 2561014 0.00 0.00 Array#<<
0.75 3.21 1.01 6758 0.15 0.48 Rubinius::Melbourne#string_to_ast
0.74 0.82 1.00 11705399 0.00 0.00 Kernel#equal?
0.73 0.98 0.98 551256 0.00 0.00 Regexp#search_region
0.67 82.32 0.89 248502 0.00 0.33 Array#each
0.66 0.74 0.89 10725737 0.00 0.00 Symbol.===
0.65 4.79 0.87 398874 0.00 0.01 String::Unpacker#number {}
0.63 4.72 0.84 5902 0.14 0.80 Hash#each
0.58 0.77 0.78 49856 0.02 0.02 Rubinius::VM.reset_method_cache
0.56 1.00 0.75 1890 0.40 0.53 Array::IdentityMap#to_array
0.55 8.98 0.75 1617925 0.00 0.01 Hash#key?
0.52 3.41 0.70 1671555 0.00 0.00 String#to_s
0.44 0.79 0.60 1232525 0.00 0.00 Type.coerce_to
0.42 0.46 0.57 6366070 0.00 0.00 Fixnum#&
0.40 0.50 0.54 2580575 0.00 0.00 Module#===
0.40 0.47 0.54 4558106 0.00 0.00 Kernel#__class__
0.40 0.53 0.53 1153 0.46 0.46 Rubinius::CodeLoader#load_compiled_file
0.35 1.01 0.47 898493 0.00 0.00 Kernel#StringValue
0.34 1.57 0.46 1267599 0.00 0.00 Hash::Entry#initialize
0.34 3.23 0.46 7892 0.06 0.41 Array::IdentityMap#load
0.33 0.38 0.45 4327127 0.00 0.00 Kernel#hash
0.31 0.34 0.42 4765596 0.00 0.00 Rubinius::Tuple#at
0.31 0.38 0.42 2532820 0.00 0.00 Kernel#kind_of?
0.31 0.89 0.42 241433 0.00 0.00 Array::IdentityMap#include?
0.31 1.76 0.41 199103 0.00 0.01 Range#each
0.28 0.36 0.38 1017630 0.00 0.00 Symbol#to_s
6,120 methods omitted
6,165 methods called a total of 162,158,766 times
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment